kvm-88: KVM_APIC_READ: read reserved register b0

kvm-88: KVM_APIC_READ: read reserved register b0

[Christoph Lechner]

Hi all,

running kvm-88 on a 2.6.26-1-amd64 kernel (stock Debian 5.0 kernel), I
get the syslog on the host system flooded with the message:

Aug 28 11:49:40 reactor kernel: [124035.611782] KVM_APIC_READ: read
reserved register b0

The guest is running Debian 5.0 as well. Kernel 2.6.26-2-486. qemu is
started with the command line:
/opt/kvm-88/bin/qemu-system-x86_64 -hda web-int.img -m 512 -net
nic,vlan=0,macaddr=52:54:12:34:02:01 -net tap,vlan=0 -k de -vnc :4


The message is always the same, only the timestamp differs. The log msg
is generated quite often, at least 10000 times per minute. The guest
system has 100% CPU usage, so has the qemu process on the host. I was
doing a search engine crawler run -- lots of network I/O -- , when the
log was filled. See the impressive growth rate of the syslog (crawler
running)

reactor:/virt# ls -l /var/log/syslog; sleep 60; ls -l /var/log/syslog
-rw-r----- 1 root adm 17765119 2009-08-28 11:47 /var/log/syslog
-rw-r----- 1 root adm 19124492 2009-08-28 11:48 /var/log/syslog
(at least 99.9% of the new log entries are of the same kind as the one
above ...)


I seems to me that the message is related to network I/O because when I
run a netpipe-tcp TCP performance benchmark between the guest and some
real machine on the network the growth rate is even higher:
reactor:/virt# ls -l /var/log/syslog; sleep 60; ls -l /var/log/syslog
-rw-r----- 1 root adm 32404400 2009-08-28 11:59 /var/log/syslog
-rw-r----- 1 root adm 73271420 2009-08-28 12:00 /var/log/syslog
(throughput max: 240 MBit/s)


When the guest system is idle (only shell prompt), the syslog growth
rate is some magnitudes smaller:
reactor:/virt# ls -l /var/log/syslog; sleep 60; ls -l /var/log/syslog
-rw-r----- 1 root adm 29649924 2009-08-28 11:56 /var/log/syslog
-rw-r----- 1 root adm 29708722 2009-08-28 11:57 /var/log/syslog

How can I fix it?

CU
- cl

reactor:/virt# cat /proc/cpuinfo
processor       : 0
vendor_id       : AuthenticAMD
cpu family      : 16
model           : 4
model name      : AMD Phenom(tm) II X4 920 Processor
stepping        : 2
cpu MHz         : 2807.120
cache size      : 512 KB
physical id     : 0
siblings        : 4
core id         : 0
cpu cores       : 4
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 5
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge
mca cmovpat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext
fxsr_opt pdpe1gb rdtscp lm 3dnowext 3dnow constant_tsc rep_good pni
monitor cx16 popcnt lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a
misalignsse 3dnowprefetch osvw ibs skinit wdt
bogomips        : 5618.34
TLB size        : 1024 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 48 bits physical, 48 bits virtual
power management: ts ttp tm stc 100mhzsteps hwpstate

(the host system has a quad-core CPU)

Re: kvm-88: KVM_APIC_READ: read reserved register b0

[Christoph Lechner]

Hi,

just a quick status update.

After switching to virtio networking, the problem disappeared. So far I
transferred about 200GB from and to the virtual machine and no problem
occurred.
After the original posting, I discovered that the rtl8139 emulation
suffers from loss of connection, too. 100% probability to lose network
connectivity while moving around the first gigabyte of data or so.

- cl

Re: kvm-88: KVM_APIC_READ: read reserved register b0

[Daniel Bareiro]

[-- Attachment #1: Type: text/plain, Size: 2083 bytes --]

On Friday, 28 August 2009 12:04:02 +0200,
Christoph Lechner wrote:

> Hi all,

Hi Christoph.
 
> running kvm-88 on a 2.6.26-1-amd64 kernel (stock Debian 5.0 kernel), I
> get the syslog on the host system flooded with the message:
> 
> Aug 28 11:49:40 reactor kernel: [124035.611782] KVM_APIC_READ: read
> reserved register b0
> 
> The guest is running Debian 5.0 as well. Kernel 2.6.26-2-486. qemu is
> started with the command line:
> /opt/kvm-88/bin/qemu-system-x86_64 -hda web-int.img -m 512 -net
> nic,vlan=0,macaddr=52:54:12:34:02:01 -net tap,vlan=0 -k de -vnc :4
> 
> 
> The message is always the same, only the timestamp differs. The log msg
> is generated quite often, at least 10000 times per minute. The guest
> system has 100% CPU usage, so has the qemu process on the host. I was
> doing a search engine crawler run -- lots of network I/O -- , when the
> log was filled. See the impressive growth rate of the syslog (crawler
> running)
> 
> reactor:/virt# ls -l /var/log/syslog; sleep 60; ls -l /var/log/syslog
> -rw-r----- 1 root adm 17765119 2009-08-28 11:47 /var/log/syslog
> -rw-r----- 1 root adm 19124492 2009-08-28 11:48 /var/log/syslog
> (at least 99.9% of the new log entries are of the same kind as the one
> above ...)

Also I am observing this behavior in one of my hosts with KVM-88 and
Linux 2.6.30 compiled both by myself on Ubuntu GNU/Linux Hardy Heron
server amd64, as I've mentioned in a previous [1] mail. Guests has
Debian GNU/Linux Lenny with stock kernel 2.6.26.

I was trying if with model=virtio the problem were solved, but was not
successful. It would seem that the cause is due to something related to
hardware of the host (is it possible?), since I have other hosts in
which I use both the same version of KVM and kernel, also both compiled
by myself, and I'm not having this problem.

Regards,
Daniel

[1] http://thread.gmane.org/gmane.comp.emulators.kvm.devel/39324
-- 
Fingerprint: BFB3 08D6 B4D1 31B2 72B9  29CE 6696 BF1B 14E6 1D37
Powered by Debian GNU/Linux Squeeze - Linux user #188.598

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 197 bytes --]

Re: kvm-88: KVM_APIC_READ: read reserved register b0

[Christoph Lechner]

Daniel Bareiro wrote:
> On Friday, 28 August 2009 12:04:02 +0200,
> Christoph Lechner wrote:
> 
>> Hi all,
> 
> Hi Christoph.
Hi.
>  
>> running kvm-88 on a 2.6.26-1-amd64 kernel (stock Debian 5.0 kernel), I
>> get the syslog on the host system flooded with the message:
>>
>> Aug 28 11:49:40 reactor kernel: [124035.611782] KVM_APIC_READ: read
>> reserved register b0
>>
>> [...]
> 
> Also I am observing this behavior in one of my hosts with KVM-88 and
> Linux 2.6.30 compiled both by myself on Ubuntu GNU/Linux Hardy Heron
> server amd64, as I've mentioned in a previous [1] mail. Guests has
> Debian GNU/Linux Lenny with stock kernel 2.6.26.
> 
> I was trying if with model=virtio the problem were solved, but was not
> successful. It would seem that the cause is due to something related to
> hardware of the host (is it possible?), since I have other hosts in
> which I use both the same version of KVM and kernel, also both compiled
> by myself, and I'm not having this problem.

don't know if this is caused by the host hardware. But what I forgot to
mention: I commented out the printk call in lapic.c. This stopped the
flooding, but I know it's only a work around.

- cl

Re: kvm-88: KVM_APIC_READ: read reserved register b0

[Gleb Natapov]

On Sun, Aug 30, 2009 at 11:59:27AM +0200, Christoph Lechner wrote:
> Daniel Bareiro wrote:
> > On Friday, 28 August 2009 12:04:02 +0200,
> > Christoph Lechner wrote:
> > 
> >> Hi all,
> > 
> > Hi Christoph.
> Hi.
> >  
> >> running kvm-88 on a 2.6.26-1-amd64 kernel (stock Debian 5.0 kernel), I
> >> get the syslog on the host system flooded with the message:
> >>
> >> Aug 28 11:49:40 reactor kernel: [124035.611782] KVM_APIC_READ: read
> >> reserved register b0
> >>
> >> [...]
> > 
> > Also I am observing this behavior in one of my hosts with KVM-88 and
> > Linux 2.6.30 compiled both by myself on Ubuntu GNU/Linux Hardy Heron
> > server amd64, as I've mentioned in a previous [1] mail. Guests has
> > Debian GNU/Linux Lenny with stock kernel 2.6.26.
> > 
> > I was trying if with model=virtio the problem were solved, but was not
> > successful. It would seem that the cause is due to something related to
> > hardware of the host (is it possible?), since I have other hosts in
> > which I use both the same version of KVM and kernel, also both compiled
> > by myself, and I'm not having this problem.
> 
> don't know if this is caused by the host hardware. But what I forgot to
> mention: I commented out the printk call in lapic.c. This stopped the
> flooding, but I know it's only a work around.
> 
This printk no longer exists in upstream kvm.

--
			Gleb.

Re: kvm-88: KVM_APIC_READ: read reserved register b0

[Christoph Lechner]

Gleb Natapov wrote:
> This printk no longer exists in upstream kvm.
> 

just to be curious: What was the reason to add that debugging message?

I don't know much about the background of the message, but I assume that
it is useful. So wouldn't it be a idea to keep the code for the message
where it is and just throttle the rate it is reported?

- cl

Re: kvm-88: KVM_APIC_READ: read reserved register b0

[Gleb Natapov]

On Sun, Aug 30, 2009 at 01:42:14PM +0200, Christoph Lechner wrote:
> Gleb Natapov wrote:
> > This printk no longer exists in upstream kvm.
> > 
> 
> just to be curious: What was the reason to add that debugging message?
> 
Because well behaved OS shouldn't read write only register. Unfortunately
older Linux kernels sometimes uses xchg to access eoi(b0) apic register
which will generate read/write.

> I don't know much about the background of the message, but I assume that
> it is useful. So wouldn't it be a idea to keep the code for the message
> where it is and just throttle the rate it is reported?
> 
It's not too much useful unless you are debugging a guest.

--
			Gleb.

Re: kvm-88: KVM_APIC_READ: read reserved register b0

[Daniel Bareiro]

[-- Attachment #1: Type: text/plain, Size: 1169 bytes --]

On Sunday, 30 August 2009 14:49:59 +0300,
Gleb Natapov wrote:

> > > This printk no longer exists in upstream kvm.

Between emails of the list, I found the suggestion to apply this [1]
patch, but I suppose that not yet it must be applied in the download
version.

> > just to be curious: What was the reason to add that debugging
> > message?

> Because well behaved OS shouldn't read write only register.
> Unfortunately older Linux kernels sometimes uses xchg to access
> eoi(b0) apic register which will generate read/write.

According to I see, guest kernel is 2.6.26-2-486. Apparently, after a
reboot, the OS boots with it instead of amd64 kernel. After boot with
amd64 kernel, no longer flooding in syslog takes place.

I didn't test yet, but I think that with a 686 kernel also the problem
had been solved from the moment that the kernel is nearer the hardware
architecture which I'm using.

Thanks to both for your replies.

Regards,
Daniel

[1] http://thread.gmane.org/gmane.comp.emulators.qemu/24029
-- 
Fingerprint: BFB3 08D6 B4D1 31B2 72B9  29CE 6696 BF1B 14E6 1D37
Powered by Debian GNU/Linux Squeeze - Linux user #188.598

[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 197 bytes --]