Bug 877538

Summary: [abrt]: WARNING: at arch/x86/kvm/svm.c:997 svm_set_tsc_khz+0xd2/0xe0 [kvm_amd]()
Product: [Fedora] Fedora Reporter: Heiko Meyer <h.meyer>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED CURRENTRELEASE QA Contact: Marcelo Tosatti <mtosatti>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 17CC: gansalmon, itamar, jonathan, kernel-maint, madhu.chinakonda, mtosatti, opensource, z_ero0
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
Whiteboard: abrt_hash:742d7744923d772a6f88956519608f51c8c0c85f
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-03-11 22:30:55 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
dmesg printouts and messages file
none
New logs (messages and dmesg)
none
dmesg printouts after booting the 3.7.6-102.bz877538 kernel (not debug)
none
dmesg printouts after booting the 3.7.6-102.bz877538.debug kernel none

Description Heiko Meyer 2012-11-16 20:06:19 UTC 
Additional info:
libreport version: 2.0.18
abrt_version:   2.0.18
cmdline:        BOOT_IMAGE=/vmlinuz-3.6.6-1.fc17.x86_64 root=/dev/mapper/vg_tower-lv_root ro rd.lvm.lv=vg_tower/lv_swap rd.md=0 rd.dm=0 SYSFONT=True rd.lvm.lv=vg_tower/lv_root KEYTABLE=sv-latin1 rd.luks=0 LANG=en_US.UTF-8 rhgb quiet
kernel:         3.6.6-1.fc17.x86_64

backtrace:
:WARNING: at arch/x86/kvm/svm.c:997 svm_set_tsc_khz+0xd2/0xe0 [kvm_amd]()
:Hardware name: GB334AA-B1U d4895.se
:user requested TSC rate below hardware speed
:Modules linked in: nls_utf8 cifs dns_resolver fscache fuse ip6table_filter ip6_tables ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack xt_CHECKSUM iptable_mangle bridge stp llc lockd sunrpc rfcomm bnep be2iscsi iscsi_boot_sysfs bnx2i cnic uio cxgb4i cxgb4 cxgb3i cxgb3 mdio libcxgbi ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi saa7134_alsa tda1004x saa7134_dvb arc4 videobuf_dvb dvb_core snd_usb_audio tda827x snd_usbmidi_lib snd_rawmidi snd_hda_codec_realtek gspca_zc3xx snd_hda_intel ath5k snd_hda_codec tda8290 gspca_main ath snd_hwdep tuner mac80211 saa7134 tveeprom videobuf_dma_sg videobuf_core v4l2_common snd_seq snd_seq_device snd_pcm cfg80211 btusb snd_page_alloc snd_timer snd soundcore videodev media rc_core nv_tco forcedeth bluetooth rfkill edac_core edac_mce_amd i2c_nforce2 k8temp vhost_net tun macvtap macvlan kvm_amd kvm uinput binfmt_m
:isc ata_generic usb_storage pata_acpi firewire_ohci firewire_core crc_itu_t sata_nv pata_amd nouveau mxm_wmi wmi video i2c_algo_bit drm_kms_helper ttm drm i2c_core
:Pid: 2268, comm: qemu-kvm Not tainted 3.6.6-1.fc17.x86_64 #1
:Call Trace:
: [<ffffffff8105b8ef>] warn_slowpath_common+0x7f/0xc0
: [<ffffffff8105b9e6>] warn_slowpath_fmt+0x46/0x50
: [<ffffffffa024c872>] svm_set_tsc_khz+0xd2/0xe0 [kvm_amd]
: [<ffffffffa01d7778>] kvm_set_tsc_khz+0xa8/0xe0 [kvm]
: [<ffffffffa01e4aeb>] kvm_arch_vcpu_init+0xab/0x1c0 [kvm]
: [<ffffffffa01c9db6>] kvm_vcpu_init+0xb6/0xf0 [kvm]
: [<ffffffffa025060d>] svm_create_vcpu+0x6d/0x310 [kvm_amd]
: [<ffffffffa01e34c7>] kvm_arch_vcpu_create+0x47/0x70 [kvm]
: [<ffffffffa01cdc42>] kvm_vm_ioctl+0x1b2/0x510 [kvm]
: [<ffffffff811a1029>] do_vfs_ioctl+0x99/0x580
: [<ffffffff81282d57>] ? file_has_perm+0x97/0xb0
: [<ffffffff811a15a9>] sys_ioctl+0x99/0xa0
: [<ffffffff81625929>] system_call_fastpath+0x16/0x1b
Comment 1 Josh Boyer 2013-01-07 21:16:41 UTC 
This seems to be qemu-kvm requesting a TSC speed below what your machine can do from what I can tell.  Marcelo?
Comment 2 Marcelo Tosatti 2013-01-17 18:13:12 UTC 
Please share the output of 

$ cat /proc/cpuinfo
Comment 3 z_ero0 2013-01-17 22:49:47 UTC 
(In reply to comment #2)
> Please share the output of 
> 
> $ cat /proc/cpuinfo

processor	: 0
vendor_id	: AuthenticAMD
cpu family	: 15
model		: 107
model name	: AMD Athlon(tm) 64 X2 Dual Core Processor 5000+
stepping	: 2
cpu MHz		: 1000.000
cache size	: 512 KB
physical id	: 0
siblings	: 2
core id		: 0
cpu cores	: 2
apicid		: 0
initial apicid	: 0
fpu		: yes
fpu_exception	: yes
cpuid level	: 1
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl extd_apicid pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy 3dnowprefetch lbrv
bogomips	: 2009.10
TLB size	: 1024 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc 100mhzsteps

processor	: 1
vendor_id	: AuthenticAMD
cpu family	: 15
model		: 107
model name	: AMD Athlon(tm) 64 X2 Dual Core Processor 5000+
stepping	: 2
cpu MHz		: 1000.000
cache size	: 512 KB
physical id	: 0
siblings	: 2
core id		: 1
cpu cores	: 2
apicid		: 1
initial apicid	: 1
fpu		: yes
fpu_exception	: yes
cpuid level	: 1
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl extd_apicid pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy 3dnowprefetch lbrv
bogomips	: 2009.10
TLB size	: 1024 4K pages
clflush size	: 64
cache_alignment	: 64
address sizes	: 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc 100mhzsteps
Comment 4 Marcelo Tosatti 2013-01-18 16:44:16 UTC 
Thanks... can you now please grab output of

/sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq 
and cpuinfo_cur_freq (same directory).
Comment 6 z_ero0 2013-01-18 17:48:29 UTC 
(In reply to comment #4)
> Thanks... can you now please grab output of
> 
> /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq 
> and cpuinfo_cur_freq (same directory).

[t@Tarek-s-DeskTop ~]$ cat /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq
2600000
[t@Tarek-s-DeskTop ~]$ cat /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq
cat: /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq: Permission denied
[t@Tarek-s-DeskTop ~]$ su -
Password: 
[root@Tarek-s-DeskTop ~]# cat /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq
1000000
[root@Tarek-s-DeskTop ~]#
Comment 7 Heiko Meyer 2013-01-18 19:33:18 UTC 
(In reply to comment #4)
> Thanks... can you now please grab output of
> 
> /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq 
> and cpuinfo_cur_freq (same directory).

[root@tower ~]# cat /proc/cpuinfo
processor       : 0
vendor_id       : AuthenticAMD
cpu family      : 15
model           : 67
model name      : AMD Athlon(tm) 64 X2 Dual Core Processor 5600+
stepping        : 3
cpu MHz         : 1000.000
cache size      : 1024 KB
physical id     : 0
siblings        : 2
core id         : 0
cpu cores       : 2
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 1
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy
bogomips        : 2004.19
TLB size        : 1024 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc

processor       : 1
vendor_id       : AuthenticAMD
cpu family      : 15
model           : 67
model name      : AMD Athlon(tm) 64 X2 Dual Core Processor 5600+
stepping        : 3
cpu MHz         : 1000.000
cache size      : 1024 KB
physical id     : 0
siblings        : 2
core id         : 1
cpu cores       : 2
apicid          : 1
initial apicid  : 1
fpu             : yes
fpu_exception   : yes
cpuid level     : 1
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy
bogomips        : 2004.19
TLB size        : 1024 4K pages
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc

[root@tower ~]# cat /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq
2800000
[root@tower ~]# cat /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq
1000000
Comment 8 Marcelo Tosatti 2013-01-19 22:35:44 UTC 
# debuginfo-install kernel
(reboot into the proper kernel, if necessary)

# cat /proc/kallsyms | grep max_tsc_khz 
(save the hexadecimal address, lets call it $maxtsckhzaddr)

# gdb `rpm -ql kernel-debuginfo | grep vmlinux` /proc/kcore

gdb> p *(0x$maxtsckhzaddr)
(note $maxtsckhzaddr is the hexadecimal address from the 
second step above)

gdb> p tsc_khz

And then repord the output of these two gdb commands.

Sorry for all this steps, have no hardware to reproduce. This is the last request, hopefully.
Comment 9 Heiko Meyer 2013-01-20 08:50:07 UTC 
(In reply to comment #8)
> # debuginfo-install kernel
> (reboot into the proper kernel, if necessary)
> 
> # cat /proc/kallsyms | grep max_tsc_khz 
> (save the hexadecimal address, lets call it $maxtsckhzaddr)
> 
> # gdb `rpm -ql kernel-debuginfo | grep vmlinux` /proc/kcore
> 
> gdb> p *(0x$maxtsckhzaddr)
> (note $maxtsckhzaddr is the hexadecimal address from the 
> second step above)
> 
> gdb> p tsc_khz
> 
> And then repord the output of these two gdb commands.
> 
> Sorry for all this steps, have no hardware to reproduce. This is the last
> request, hopefully.

[root@tower ~]# cat /proc/kallsyms | grep max_tsc_khz
ffffffffa021baa0 b max_tsc_khz  [kvm]
[root@tower ~]# gdb `rpm -ql kernel-debuginfo | grep vmlinux` /proc/kcore
GNU gdb (GDB) Fedora (7.4.50.20120120-52.fc17)
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/lib/debug/lib/modules/3.6.11-5.fc17.x86_64/vmlinux...done.
[New process 1]
Core was generated by `BOOT_IMAGE=/vmlinuz-3.6.11-5.fc17.x86_64 root=/dev/mapper/vg_tower-lv_root ro rd'.
#0  0x0000000000000000 in irq_stack_union ()
(gdb) p *(0xffffffffa021baa0)
$1 = 2800000
(gdb) p tsc_khz
$2 = 1002137
(gdb)
Comment 10 z_ero0 2013-01-20 17:19:24 UTC 
(In reply to comment #9)
> (In reply to comment #8)
> > # debuginfo-install kernel
> > (reboot into the proper kernel, if necessary)
> > 
> > # cat /proc/kallsyms | grep max_tsc_khz 
> > (save the hexadecimal address, lets call it $maxtsckhzaddr)
> > 
> > # gdb `rpm -ql kernel-debuginfo | grep vmlinux` /proc/kcore
> > 
> > gdb> p *(0x$maxtsckhzaddr)
> > (note $maxtsckhzaddr is the hexadecimal address from the 
> > second step above)
> > 
> > gdb> p tsc_khz
> > 
> > And then repord the output of these two gdb commands.
> > 
> > Sorry for all this steps, have no hardware to reproduce. This is the last
> > request, hopefully.
> 
> [root@tower ~]# cat /proc/kallsyms | grep max_tsc_khz
> ffffffffa021baa0 b max_tsc_khz  [kvm]
> [root@tower ~]# gdb `rpm -ql kernel-debuginfo | grep vmlinux` /proc/kcore
> GNU gdb (GDB) Fedora (7.4.50.20120120-52.fc17)
> Copyright (C) 2012 Free Software Foundation, Inc.
> License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
> This is free software: you are free to change and redistribute it.
> There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
> and "show warranty" for details.
> This GDB was configured as "x86_64-redhat-linux-gnu".
> For bug reporting instructions, please see:
> <http://www.gnu.org/software/gdb/bugs/>...
> Reading symbols from
> /usr/lib/debug/lib/modules/3.6.11-5.fc17.x86_64/vmlinux...done.
> [New process 1]
> Core was generated by `BOOT_IMAGE=/vmlinuz-3.6.11-5.fc17.x86_64
> root=/dev/mapper/vg_tower-lv_root ro rd'.
> #0  0x0000000000000000 in irq_stack_union ()
> (gdb) p *(0xffffffffa021baa0)
> $1 = 2800000
> (gdb) p tsc_khz
> $2 = 1002137
> (gdb)


 Sorry couldn't get you the second value, says no symbol table is loaded! see log below:

[root@Tarek-s-DeskTop ~]# cat /proc/kallsyms | grep max_tsc_khz
ffffffffa01edaa0 b max_tsc_khz	[kvm]
[root@Tarek-s-DeskTop ~]# gdb `rpm -ql kernel-debuginfo | grep vmlinux` /proc/kcore
GNU gdb (GDB) Fedora (7.4.50.20120120-52.fc17)
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
[New process 1]
Core was generated by `BOOT_IMAGE=/vmlinuz-3.6.11-1.fc17.x86_64 root=/dev/mapper/vg_tarek--s--desktop-l'.
#0  0x0000000000000000 in ?? ()
"/proc/kcore" is a core file.
Please specify an executable to debug.
(gdb) p *(0xffffffffa01edaa0)
$1 = 2600000
(gdb) p tsc_khz
No symbol table is loaded.  Use the "file" command.
(gdb)
Comment 11 Till Maas 2013-01-29 20:18:04 UTC 
I started qemu-kvm:
qemu-kvm -hda /dev/sdd -cdrom Fedora-18-x86_64-Live-Desktop.iso -boot d -k de -m 1024  -usb -usbdevice tablet


Package: kernel
OS Release: Fedora release 17 (Beefy Miracle)
Comment 12 Marcelo Tosatti 2013-02-05 01:32:28 UTC 
I've built a custom kernel to collect debug information at the location. Can you please install it and reproduce the problem


http://koji.fedoraproject.org/koji/taskinfo?taskID=4928758

Thanks in advance
Comment 13 Heiko Meyer 2013-02-06 21:01:42 UTC 
(In reply to comment #12)
> I've built a custom kernel to collect debug information at the location. Can
> you please install it and reproduce the problem
> 
> 
> http://koji.fedoraproject.org/koji/taskinfo?taskID=4928758
> 
> Thanks in advance

Unfortunately the noveau graphics driver does not seem to work with 3.7.x kernels. At least it hangs the gdm login screen each time I try. If there is something I can provide from the tty, please let me know.
Comment 14 Marcelo Tosatti 2013-02-06 23:00:30 UTC 
Can you start the guest from the command line? Just so that we get the WARNING

# qemu-system-x86_64 --nographic -enable-kvm

Should be enough (press ctrl+a c to reach the monitor, then q to quit).

The warning should be in /var/log/messages or /var/log/dmesg.
Comment 15 Heiko Meyer 2013-02-09 08:01:32 UTC 
Created attachment 695369 [details]
dmesg printouts and messages file

Hi,

here is the requested information (I hope).

The command you sent resulted in:
<snip>
[root@tower ~]# qemu-system-x86_64 --nographic -enable-kvm
KVM not supported for this target
No accelerator found!
[root@tower ~]# 
</snip>

So I started one of my images using virsh. Hope that gave the desired printouts.

Attached are the dmesg printouts and the messages file which I took after the virsh execution.
Comment 16 Marcelo Tosatti 2013-02-11 23:27:39 UTC 
Heiko,

Unfortunately these are not useful, _please_ boot with the debug kernel from comment 12 and run, in the console:

# qemu-kvm -nographic

After that, press ctrl+a c to reach the monitor, then q to quit.

Now attached both /var/log/messages and /var/log/dmesg.

Thats it!
Comment 17 Heiko Meyer 2013-02-12 20:34:48 UTC 
Created attachment 696615 [details]
New logs (messages and dmesg)

Sorry for that, I used the wrong kernel. Have re-run the test now with the indicated kernel. New logs are attached.

/Heiko
Comment 18 Marcelo Tosatti 2013-02-19 22:05:51 UTC 
Heiko,

The report from comment 17 is not problematic (as you can see there is no warning).

What kernel are you using? Should prepare a debug kernel with exact same version.
Comment 19 Heiko Meyer 2013-02-21 20:51:28 UTC 
I didn't check the logs, so I di not see that there was no warning.
Currently I'm running 3.7.6-102-fc17.x86_64 (the latest released).
Comment 20 Marcelo Tosatti 2013-02-27 10:32:11 UTC 
Heiko, please try the 3.7.6-102 kernel package at
http://koji.fedoraproject.org/koji/taskinfo?taskID=5059642, 
which prints additional information.

Thanks
Comment 21 Marcelo Tosatti 2013-03-08 17:13:37 UTC 
Ping?
Comment 22 Heiko Meyer 2013-03-08 18:46:21 UTC 
Hi Marcelo,

I downloaded and installed the kernel, unfortunately I can't seem to recreate the problem right now.

/Heiko
Comment 23 Marcelo Tosatti 2013-03-08 21:37:46 UTC 
Heiko,

Can you attach dmesg of boot with the new kernel ? (even without a failure).
Comment 24 Heiko Meyer 2013-03-09 21:19:58 UTC 
(In reply to comment #23)
> Heiko,
> 
> Can you attach dmesg of boot with the new kernel ? (even without a failure).

Hi Marcelo, I will attach the dmesg printouts. To make the debug kernel work I had to ditch the graphical login target in favour for the multi-user. Hope it gave the needed printouts anyway.
Comment 25 Heiko Meyer 2013-03-09 21:21:55 UTC 
Created attachment 707568 [details]
dmesg printouts after booting the 3.7.6-102.bz877538 kernel (not debug)
Comment 26 Heiko Meyer 2013-03-09 21:22:58 UTC 
Created attachment 707569 [details]
dmesg printouts after booting the 3.7.6-102.bz877538.debug kernel
Comment 27 Marcelo Tosatti 2013-03-11 22:30:55 UTC 
There have been a number of fixes around KVM TSC code from v3.6 to v3.7, including fixes in the initialization order code.

Since problem cant be reproduced with a v3.7 kernel, marking this bug as FIXED.

Please reopen if you see this again with v3.7.

Thanks