Le 01/03/2011 08:03, Michael S. Tsirkin a écrit :
On Mon, Feb 28, 2011 at 11:34:16PM +0100, Jean-Philippe Menil wrote:Hi,here is another trace with kvm.ko compiled with debug flags. the bug: [12099.503414] BUG: unable to handle kernel paging request at 000000000b6635e9 [12099.503462] IP: [<ffffffffa03ee877>] kvm_set_irq+0x37/0x140 [kvm] [12099.503521] PGD 45d8d2067 PUD 45d58e067 PMD 0 [12099.503560] Oops: 0000 [#1] SMP [12099.503591] last sysfs file: /sys/devices/system/cpu/cpu11/cache/index2/shared_cpu_map [12099.503641] CPU 0 [12099.503648] Modules linked in: netconsole configfs vhost_net macvtap macvlan tun veth powernow_k8 mperf cpufreq_userspace cpufreq_stats cpufreq_powersave cpufreq_ondemand freq_table cpufreq_conservative fuse xt_physdev ip6t_LOG ip6table_filter ip6_tables ipt_LOG xt_multiport xt_limit xt_tcpudp xt_state iptable_filter ip_tables x_tables nf_conntrack_tftp nf_conntrack_ftp nf_conntrack_ipv4 nf_defrag_ipv4 8021q bridge stp ext2 mbcache dm_round_robin dm_multipath nf_conntrack_ipv6 nf_conntrack nf_defrag_ipv6 kvm_amd kvm ipv6 snd_pcm snd_timer snd soundcore snd_page_alloc shpchp pci_hotplug tpm_tis i2c_nforce2 tpm i2c_core pcspkr evdev psmouse joydev tpm_bios processor ghes dcdbas hed button serio_raw thermal_sys xfs exportfs dm_mod sg sr_mod cdrom usbhid hid usb_storage ses sd_mod enclosure megaraid_sas ohci_hcd lpfc scsi_transport_fc bnx2 scsi_tgt scsi_mod ehci_hcd [last unloaded: scsi_wait_scan] [12099.504277] [12099.504302] Pid: 1742, comm: kworker/0:2 Not tainted 2.6.37.2-dsiun-110105+ #2 Dell Inc. PowerEdge M605/0K543T [12099.504373] RIP: 0010:[<ffffffffa03ee877>] [<ffffffffa03ee877>] kvm_set_irq+0x37/0x140 [kvm] [12099.504444] RSP: 0018:ffff88045e013d00 EFLAGS: 00010246 [12099.504474] RAX: 000000000b6634c1 RBX: 0000000000000018 RCX: 0000000000000001 [12099.504508] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff880419b600c0 [12099.504541] RBP: ffff88045e013dd0 R08: ffff88045e012000 R09: 0000000000000000 [12099.504575] R10: 0000000000000000 R11: 00000000ffffffff R12: ffff880419b600c0 [12099.504609] R13: ffff880419b600c0 R14: ffffffffa03efaa0 R15: 0000000000000001 [12099.504643] FS: 00007f3abaa05710(0000) GS:ffff88007f800000(0000) knlGS:0000000000000000 [12099.504693] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [12099.504724] CR2: 000000000b6635e9 CR3: 000000045e2bc000 CR4: 00000000000006f0 [12099.504757] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [12099.504791] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 [12099.504825] Process kworker/0:2 (pid: 1742, threadinfo ffkvm_set_irqff88045e012000, task ffff88045ffb0d60) [12099.504874] Stack: [12099.504897] 00000000000119c0 00000000000119c0 00000000000119c0 ffff88045ffb0d60 [12099.504953] ffff88045ffb1010 ffff88045e013fd8 ffff88045ffb1018 ffff88045e012010 [12099.505009] 00000000000119c0 ffff88045e013fd8 00000000000119c0 00000000000119c0 [12099.505065] Call Trace: [12099.505099] [<ffffffff813818ce>] ? common_interrupt+0xe/0x13 [12099.505145] [<ffffffffa03efaa0>] ? irqfd_inject+0x0/0x50 [kvm] [12099.505145] [<ffffffffa03efaca>] irqfd_inject+0x2a/0x50 [kvm] [12099.505145] [<ffffffff8106b7bb>] process_one_work+0x11b/0x450 [12099.505145] [<ffffffff8106bf37>] worker_thread+0x157/0x410 [12099.505145] [<ffffffff8103a569>] ? __wake_up_common+0x59/0x90 [12099.505145] [<ffffffff8106bde0>] ? worker_thread+0x0/0x410 [12099.505145] [<ffffffff8106f996>] kthread+0x96/0xa0 [12099.505145] [<ffffffff81003c64>] kernel_thread_helper+0x4/0x10 [12099.505145] [<ffffffff8106f900>] ? kthread+0x0/0xa0 [12099.505145] [<ffffffff81003c60>] ? kernel_thread_helper+0x0/0x10 [12099.505145] Code: 55 49 89 fd 41 54 53 89 d3 48 81 ec a8 00 00 00 8b 15 a6 75 03 00 89 b5 3c ff ff ff 85 d2 0f 85 d5 00 00 00 49 8b 85 58 24 00 00<3b> 98 28 01 00 00 73 61 89 db 48 8b 84 d8 30 01 00 00 48 85 c0 [12099.505145] RIP [<ffffffffa03ee877>] kvm_set_irq+0x37/0x140 [kvm] [12099.505145] RSP<ffff88045e013d00> [12099.505145] CR2: 000000000b6635e9 markup_oops result: root@ayrshire:~# cat bug.txt | perl markup_oops.pl -m /lib/modules/2.6.37.2-dsiun-110105+/kernel/arch/x86/kvm/kvm.ko /boot/vmlinuz-2.6.37.2-dsiun-110105+ vmaoffset = 18446744072103034880 ffffffffa03ee841: 48 89 e5 mov %rsp,%rbp ffffffffa03ee844: 41 57 push %r15 ffffffffa03ee846: 41 89 cf mov %ecx,%r15d | %r15 => 1 %ecx = 1 ffffffffa03ee849: 41 56 push %r14 | %r14 => ffffffffa03efaa0 ffffffffa03ee84b: 41 55 push %r13 ffffffffa03ee84d: 49 89 fd mov %rdi,%r13 | %edi = ffff880419b600c0 %r13 => ffff880419b600c0 ffffffffa03ee850: 41 54 push %r12 | %r12 => ffff880419b600c0 ffffffffa03ee852: 53 push %rbx ffffffffa03ee853: 89 d3 mov %edx,%ebx | %ebx => 18 ffffffffa03ee855: 48 81 ec a8 00 00 00 sub $0xa8,%rsp ffffffffa03ee85c: 8b 15 00 00 00 00 mov 0x0(%rip),%edx # ffffffffa03ee862<kvm_set_irq+0x22> ffffffffa03ee862: 89 b5 3c ff ff ff mov %esi,-0xc4(%rbp) | %esi = 0 ffffffffa03ee868: 85 d2 test %edx,%edx | %edx => 0 ffffffffa03ee86a: 0f 85 d5 00 00 00 jne ffffffffa03ee945 <kvm_set_irq+0x105> ffffffffa03ee870: 49 8b 85 58 24 00 00 mov 0x2458(%r13),%rax | %eax => b6634c1 %r13 = ffff880419b600c0 *ffffffffa03ee877: 3b 98 28 01 00 00 cmp 0x128(%rax),%ebx | %eax = b6634c1 %ebx = 18<--- faulting instruction ffffffffa03ee87d: 73 61 jae ffffffffa03ee8e0 <kvm_set_irq+0xa0> ffffffffa03ee87f: 89 db mov %ebx,%ebx ffffffffa03ee881: 48 8b 84 d8 30 01 00 mov 0x130(%rax,%rbx,8),%rax ffffffffa03ee888: 00 ffffffffa03ee889: 48 85 c0 test %rax,%rax ffffffffa03ee88c: 74 52 je ffffffffa03ee8e0 <kvm_set_irq+0xa0> ffffffffa03ee88e: 48 8d 95 40 ff ff ff lea -0xc0(%rbp),%rdx ffffffffa03ee895: 31 db xor %ebx,%ebx ffffffffa03ee897: 48 8b 08 mov (%rax),%rcx ffffffffa03ee89a: 83 c3 01 add $0x1,%ebx ffffffffa03ee89d: 0f 18 09 prefetcht0 (%rcx) ffffffffa03ee8a0: 48 8b 48 e0 mov -0x20(%rax),%rcx ffffffffa03ee8a4: 48 89 0a mov %rcx,(%rdx) ffffffffa03ee8a7: 48 8b 48 e8 mov -0x18(%rax),%rcx ffffffffa03ee8ab: 48 89 4a 08 mov %rcx,0x8(%rdx) ffffffffa03ee8af: 48 8b 48 f0 mov -0x10(%rax),%rcx ffffffffa03ee8b3: 48 89 4a 10 mov %rcx,0x10(%rdx) ffffffffa03ee8b7: 48 8b 48 f8 mov -0x8(%rax),%rcx ffffffffa03ee8bb: 48 89 4a 18 mov %rcx,0x18(%rdx) ffffffffa03ee8bf: 48 8b 08 mov (%rax),%rcx The relvant part of objdump for kvm_set_irq: root@ayrshire:~# objdump -ldS /lib/modules/2.6.37.2-dsiun-110105+/kernel/arch/x86/kvm/kvm.ko> dump.txt 0000000000006840<kvm_set_irq>: kvm_set_irq(): /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:148 6840: 55 push %rbp 6841: 48 89 e5 mov %rsp,%rbp 6844: 41 57 push %r15 6846: 41 89 cf mov %ecx,%r15d 6849: 41 56 push %r14 684b: 41 55 push %r13 684d: 49 89 fd mov %rdi,%r13 6850: 41 54 push %r12 6852: 53 push %rbx 6853: 89 d3 mov %edx,%ebx 6855: 48 81 ec a8 00 00 00 sub $0xa8,%rsp trace_kvm_set_irq(): /usr/src/GIT/linux-2.6-stable/include/trace/events/kvm.h:10 685c: 8b 15 00 00 00 00 mov 0x0(%rip),%edx # 6862<kvm_set_irq+0x22> kvm_set_irq(): /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:148 6862: 89 b5 3c ff ff ff mov %esi,-0xc4(%rbp) trace_kvm_set_irq(): /usr/src/GIT/linux-2.6-stable/include/trace/events/kvm.h:10 6868: 85 d2 test %edx,%edx 686a: 0f 85 d5 00 00 00 jne 6945<kvm_set_irq+0x105> kvm_set_irq(): /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:161 6870: 49 8b 85 58 24 00 00 mov 0x2458(%r13),%rax /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:162 6877: 3b 98 28 01 00 00 cmp 0x128(%rax),%ebx 687d: 73 61 jae 68e0<kvm_set_irq+0xa0> /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:163 687f: 89 db mov %ebx,%ebx 6881: 48 8b 84 d8 30 01 00 mov 0x130(%rax,%rbx,8),%rax 6888: 00 6889: 48 85 c0 test %rax,%rax 688c: 74 52 je 68e0<kvm_set_irq+0xa0> 688e: 48 8d 95 40 ff ff ff lea -0xc0(%rbp),%rdx 6895: 31 db xor %ebx,%ebx 6897: 48 8b 08 mov (%rax),%rcx /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:164 689a: 83 c3 01 add $0x1,%ebx /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:163 689d: 0f 18 09 prefetcht0 (%rcx) /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:164 68a0: 48 8b 48 e0 mov -0x20(%rax),%rcx 68a4: 48 89 0a mov %rcx,(%rdx) 68a7: 48 8b 48 e8 mov -0x18(%rax),%rcx 68ab: 48 89 4a 08 mov %rcx,0x8(%rdx) 68af: 48 8b 48 f0 mov -0x10(%rax),%rcx 68b3: 48 89 4a 10 mov %rcx,0x10(%rdx) 68b7: 48 8b 48 f8 mov -0x8(%rax),%rcx 68bb: 48 89 4a 18 mov %rcx,0x18(%rdx) 68bf: 48 8b 08 mov (%rax),%rcx 68c2: 48 89 4a 20 mov %rcx,0x20(%rdx) 68c6: 48 8b 48 08 mov 0x8(%rax),%rcx 68ca: 48 89 4a 28 mov %rcx,0x28(%rdx) /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:163 68ce: 48 8b 00 mov (%rax),%rax 68d1: 48 83 c2 30 add $0x30,%rdx 68d5: 48 85 c0 test %rax,%rax 68d8: 75 bd jne 6897<kvm_set_irq+0x57> 68da: eb 06 jmp 68e2<kvm_set_irq+0xa2> 68dc: 0f 1f 40 00 nopl 0x0(%rax) /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:162 68e0: 31 db xor %ebx,%ebx /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:169 68e2: 4c 8d b5 40 ff ff ff lea -0xc0(%rbp),%r14 /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:162 68e9: 41 bc ff ff ff ff mov $0xffffffff,%r12d /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:167 68ef: 85 db test %ebx,%ebx 68f1: 74 3d je 6930<kvm_set_irq+0xf0> 68f3: 83 eb 01 sub $0x1,%ebx /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:169 68f6: 44 89 f9 mov %r15d,%ecx 68f9: 8b 95 3c ff ff ff mov -0xc4(%rbp),%edx 68ff: 48 63 c3 movslq %ebx,%rax 6902: 4c 89 ee mov %r13,%rsi 6905: 48 8d 04 40 lea (%rax,%rax,2),%rax 6909: 48 c1 e0 04 shl $0x4,%rax 690d: 49 8d 3c 06 lea (%r14,%rax,1),%rdi 6911: ff 94 05 48 ff ff ff callq *-0xb8(%rbp,%rax,1) /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:170 6918: 85 c0 test %eax,%eax 691a: 78 d3 js 68ef<kvm_set_irq+0xaf> /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:173 691c: 45 85 e4 test %r12d,%r12d 691f: ba 00 00 00 00 mov $0x0,%edx 6924: 44 0f 48 e2 cmovs %edx,%r12d /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:167 6928: 85 db test %ebx,%ebx /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:173 692a: 46 8d 24 20 lea (%rax,%r12,1),%r12d /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:167 692e: 75 c3 jne 68f3<kvm_set_irq+0xb3> /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:177 6930: 48 81 c4 a8 00 00 00 add $0xa8,%rsp 6937: 44 89 e0 mov %r12d,%eax 693a: 5b pop %rbx 693b: 41 5c pop %r12 693d: 41 5d pop %r13 693f: 41 5e pop %r14 6941: 41 5f pop %r15 6943: c9 leaveq 6944: c3 retq trace_kvm_set_irq(): /usr/src/GIT/linux-2.6-stable/include/trace/events/kvm.h:10 6945: 4c 8b 25 00 00 00 00 mov 0x0(%rip),%r12 # 694c<kvm_set_irq+0x10c> 694c: 4d 85 e4 test %r12,%r12 694f: 0f 84 1b ff ff ff je 6870<kvm_set_irq+0x30> 6955: 49 8b 04 24 mov (%r12),%rax 6959: 49 8b 7c 24 08 mov 0x8(%r12),%rdi 695e: 49 83 c4 10 add $0x10,%r12 6962: 8b 8d 3c ff ff ff mov -0xc4(%rbp),%ecx 6968: 44 89 fa mov %r15d,%edx 696b: 89 de mov %ebx,%esi 696d: ff d0 callq *%rax 696f: 49 8b 04 24 mov (%r12),%rax 6973: 48 85 c0 test %rax,%rax 6976: 75 e1 jne 6959<kvm_set_irq+0x119> 6978: e9 f3 fe ff ff jmpq 6870<kvm_set_irq+0x30> kvm_set_irq(): 697d: 0f 1f 00 nopl (%rax) So, if i've read correctly, the offset is 0x6877 ? root@ayrshire:~# addr2line -e /lib/modules/2.6.37.2-dsiun-110105+/kernel/arch/x86/kvm/kvm.ko 0x6877 /usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:162 Is it the correct way to analyse this? Regards.Yes. So we have: irq_rt = rcu_dereference(kvm->irq_routing);ffffffffa03ee870: 49 8b 85 58 24 00 00 mov 0x2458(%r13),%rax | %eax => b6634c1 %r13 = ffff880419b600c0if (irq< irq_rt->nr_rt_entries)*ffffffffa03ee877: 3b 98 28 01 00 00 cmp 0x128(%rax),%ebx | %eax = b6634c1 %ebx = 18<--- faulting instructionThe problem then is that while the kvm pointer is ffff880419b600c0 which looks sane, the value we read from kvm->irq_routing is b6634c1 which does not make sense. When we dereference that, kaboom. Is the kvm pointer wrong or the memory corrupted? Try printing the kvm pointer during initialization, e.g. in kvm_vm_ioctl_create_vcpu, then and compare to markup_oops.
Hi, so this time the bug is:[17882.612303] BUG: unable to handle kernel paging request at 0000000000002458
[17882.612342] IP: [<ffffffffa03898a0>] kvm_set_irq+0x30/0x140 [kvm] markup_oops give me this:root@ayrshire:~# cat bug-0103.txt | perl markup_oops.pl -m /lib/modules/2.6.37.2-dsiun-110105+/kernel/arch/x86/kvm/kvm.ko /boot/vmlinuz-2.6.37.2-dsiun-110105+ vmaoffset = 18446744072102621184 ffffffffa0389871: 48 89 e5 mov %rsp,%rbp
ffffffffa0389874: 41 57 push %r15ffffffffa0389876: 41 89 cf mov %ecx,%r15d | %r15 => 1 %ecx = 1 ffffffffa0389879: 41 56 push %r14 | %r14 => ffffffffa038aad0
ffffffffa038987b: 41 55 push %r13ffffffffa038987d: 49 89 fd mov %rdi,%r13 | %edi = 0 %r13 => 0
ffffffffa0389880: 41 54 push %r12 | %r12 => 0 ffffffffa0389882: 53 push %rbx ffffffffa0389883: 89 d3 mov %edx,%ebx | %ebx => 1a ffffffffa0389885: 48 81 ec a8 00 00 00 sub $0xa8,%rspffffffffa038988c: 8b 15 00 00 00 00 mov 0x0(%rip),%edx # ffffffffa0389892 <kvm_set_irq+0x22> ffffffffa0389892: 89 b5 3c ff ff ff mov %esi,-0xc4(%rbp) | %esi = 0
ffffffffa0389898: 85 d2 test %edx,%edx | %edx => 0ffffffffa038989a: 0f 85 d5 00 00 00 jne ffffffffa0389975 <kvm_set_irq+0x105> *ffffffffa03898a0: 49 8b 85 58 24 00 00 mov 0x2458(%r13),%rax | %eax = 0 %r13 = 0 <--- faulting instruction
ffffffffa03898a7: 3b 98 28 01 00 00 cmp 0x128(%rax),%ebxffffffffa03898ad: 73 61 jae ffffffffa0389910 <kvm_set_irq+0xa0>
ffffffffa03898af: 89 db mov %ebx,%ebx ffffffffa03898b1: 48 8b 84 d8 30 01 00 mov 0x130(%rax,%rbx,8),%rax ffffffffa03898b8: 00 ffffffffa03898b9: 48 85 c0 test %rax,%raxffffffffa03898bc: 74 52 je ffffffffa0389910 <kvm_set_irq+0xa0>
ffffffffa03898be: 48 8d 95 40 ff ff ff lea -0xc0(%rbp),%rdx
ffffffffa03898c5: 31 db xor %ebx,%ebx
ffffffffa03898c7: 48 8b 08 mov (%rax),%rcx
ffffffffa03898ca: 83 c3 01 add $0x1,%ebx
ffffffffa03898cd: 0f 18 09 prefetcht0 (%rcx)
ffffffffa03898d0: 48 8b 48 e0 mov -0x20(%rax),%rcx
ffffffffa03898d4: 48 89 0a mov %rcx,(%rdx)
ffffffffa03898d7: 48 8b 48 e8 mov -0x18(%rax),%rcx
ffffffffa03898db: 48 89 4a 08 mov %rcx,0x8(%rdx)
ffffffffa03898df: 48 8b 48 f0 mov -0x10(%rax),%rcx
ffffffffa03898e3: 48 89 4a 10 mov %rcx,0x10(%rdx)
ffffffffa03898e7: 48 8b 48 f8 mov -0x8(%rax),%rcx
ffffffffa03898eb: 48 89 4a 18 mov %rcx,0x18(%rdx)
wich correspond to offset 68a0 (from objdump):
kvm_set_irq():
/usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:161
68a0: 49 8b 85 58 24 00 00 mov 0x2458(%r13),%rax
/usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:162
68a7: 3b 98 28 01 00 00 cmp 0x128(%rax),%ebx
root@ayrshire:~# addr2line -e
/lib/modules/2.6.37.2-dsiun-110105+/kernel/arch/x86/kvm/kvm.ko 0x68a0
/usr/src/GIT/linux-2.6-stable/arch/x86/kvm/../../../virt/kvm/irq_comm.c:161 So here kvm->irq_routing is null. How can it be? Regards.
<<attachment: jean-philippe_menil.vcf>>
