29731 2014-01-16 13:25:30 +0400 divide by zero in kvm_write_tsc 2014-01-21 09:02:49 +0400 1 1 4 Development Sisyphus kernel-image-std-def unstable all Linux NEW P3 major --- 1 4pavel_v vt aen asy kernelbot placeholder vt qa-sisyphus oldest_to_newest 144667 0 4pavel_v 2014-01-16 13:25:30 +0400 Уже не первый раз сталкиваюсь с таким. Имеется сервер на котором крутятся виртуальные машинки. Дистриб с офф сервера(altlinux-7.0.1-centaurus-i586-ru-install-dvd5.iso). Обновлено. Все работает в штатном режиме: перегружается, если надо. После очередного ребута(без установок и обновлений) перестает грузиться libvirtd. [root@vmbase3 ~]# uname -r 3.10.26-std-def-alt1 В логах следующее: Jan 16 15:56:07 vmbase3 libvirtd: libvirtd startup succeeded Jan 16 15:56:08 vmbase3 kernel: [ 295.789172] ip_tables: (C) 2000-2006 Netfilter Core Team Jan 16 15:56:08 vmbase3 kernel: [ 295.860358] nf_conntrack version 0.5.0 (16384 buckets, 65536 max) Jan 16 15:56:08 vmbase3 avahi-daemon[4250]: Joining mDNS multicast group on interface virbr0.IPv4 with address 192.168.122.1. Jan 16 15:56:08 vmbase3 avahi-daemon[4250]: New relevant interface virbr0.IPv4 for mDNS. Jan 16 15:56:08 vmbase3 avahi-daemon[4250]: Registering new address record for 192.168.122.1 on virbr0.IPv4. Jan 16 15:56:08 vmbase3 kernel: [ 295.898273] IPv6: ADDRCONF(NETDEV_UP): virbr0: link is not ready Jan 16 15:56:08 vmbase3 avahi-daemon[4250]: Interface virbr0.IPv4 no longer relevant for mDNS. Jan 16 15:56:08 vmbase3 avahi-daemon[4250]: Leaving mDNS multicast group on interface virbr0.IPv4 with address 192.168.122.1. Jan 16 15:56:08 vmbase3 avahi-daemon[4250]: Withdrawing address record for 192.168.122.1 on virbr0. Jan 16 15:56:08 vmbase3 dhcpcd[3508]: manage_link: No such device or address Jan 16 15:56:08 vmbase3 avahi-daemon[4250]: Withdrawing workstation service for virbr0. Jan 16 15:56:08 vmbase3 kernel: [ 296.442388] Ebtables v2.0 registered Jan 16 15:56:08 vmbase3 kernel: [ 296.471014] ip6_tables: (C) 2000-2006 Netfilter Core Team Jan 16 15:56:12 vmbase3 kernel: [ 300.284115] device vnet0 entered promiscuous mode Jan 16 15:56:12 vmbase3 kernel: [ 300.320142] breth0: port 2(vnet0) entered forwarding state Jan 16 15:56:12 vmbase3 kernel: [ 300.320157] breth0: port 2(vnet0) entered forwarding state Jan 16 15:56:14 vmbase3 avahi-daemon[4250]: Registering new address record for fe80::fc54:ff:fe30:30c0 on vnet0.*. Jan 16 15:56:17 vmbase3 kernel: [ 305.356120] divide error: 0000 [#1] SMP Jan 16 15:56:17 vmbase3 kernel: [ 305.356331] Modules linked in: vhost_net macvtap macvlan ip6table_filter ip6_tables ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables sunrpc af_packet bridge stp llc ipv6 dm_multipath scsi_dh coretemp kvm_intel kvm sr_mod iTCO_wdt cdrom iTCO_vendor_support gpio_ich ppdev snd_hda_codec_analog dm_mod microcode psmouse i2c_i801 lpc_ich pcspkr snd_hda_intel snd_hda_codec snd_hwdep snd_pcm intel_agp ahci uhci_hcd snd_page_alloc ehci_pci intel_gtt libahci ehci_hcd snd_timer pata_jmicron r8169 snd usbcore agpgart parport_pc mii soundcore asus_atk0110 usb_common parport acpi_cpufreq hwmon mperf processor button tun ext4 crc16 mbcache jbd2 sd_mod crc_t10dif evdev serio_raw ata_piix ata_generic pata_acpi libata scsi_mod Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] CPU: 0 PID: 5537 Comm: qemu-kvm Not tainted 3.10.26-std-def-alt1 #1 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] Hardware name: System manufacturer System Product Name/P5B, BIOS 0806 10/26/2006 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] task: f4edb2c0 ti: f2498000 task.ti: f2498000 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] EIP: 0060:[<f8ca8689>] EFLAGS: 00010002 CPU: 0 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] EIP is at kvm_write_tsc+0xc9/0x390 [kvm] Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] EAX: bd6d26a8 EBX: 00000046 ECX: 4dbf7487 EDX: 00176340 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] ESI: f4b5e000 EDI: f24b4040 EBP: f2499d78 ESP: f2499d2c Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] CR0: 8005003b CR2: 755ca000 CR3: 32487000 CR4: 000027d0 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] DR6: ffff0ff0 DR7: 00000400 Jan 16 15:56:17 vmbase3 kernel: [ 305.360042] Stack: Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] 00000296 bd6d26a8 00176340 f2499db0 f4b5f5ac e285c520 0000056b 00176060 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] 00000001 001c817f 18a44696 00000047 bc9afd39 000005fc 00000131 15399c96 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] 00000010 bc9afd39 f24b4040 f2499da8 f8dccd35 74ac45ec f2499db4 00000202 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] Call Trace: Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8dccd35>] vmx_set_msr+0x1d5/0x240 [kvm_intel] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8ca4c60>] ? kvm_enable_efer_bits+0x20/0x20 [kvm] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8ca4c8a>] do_set_msr+0x2a/0x40 [kvm] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8ca7f19>] msr_io+0x89/0x100 [kvm] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8cad833>] kvm_arch_vcpu_ioctl+0x563/0xdc0 [kvm] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8dcc281>] ? emulation_required+0x21/0x40 [kvm_intel] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8dcc476>] ? vmx_set_segment+0x96/0x210 [kvm_intel] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8cb085b>] ? kvm_arch_vcpu_ioctl_set_sregs+0x2cb/0x400 [kvm] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8cad133>] ? kvm_arch_vcpu_load+0x53/0x1f0 [kvm] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8c9d942>] kvm_vcpu_ioctl+0x192/0x4f0 [kvm] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<c1032ba7>] ? kmap_atomic_prot+0xd7/0xf0 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<c1104e41>] ? handle_pte_fault+0x1d1/0x420 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<f8c9d7b0>] ? vcpu_put+0x20/0x20 [kvm] Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<c1136b92>] do_vfs_ioctl+0x72/0x570 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<c140a9e0>] ? __do_page_fault+0x4b0/0x4b0 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<c140a777>] ? __do_page_fault+0x247/0x4b0 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<c1137100>] SyS_ioctl+0x70/0x80 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<c140789c>] syscall_call+0x7/0xb Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] [<c1400000>] ? rb_move_tail.isra.30+0x39/0x275 Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] Code: 1b 96 bc 15 00 00 89 45 b8 b8 e8 03 00 00 69 d2 e8 03 00 00 89 55 d0 f7 65 b8 89 45 b8 8b 45 d0 01 c2 8b 45 b8 89 55 bc 8b 55 bc <f7> 7d d8 31 d2 89 45 d0 8b 45 dc 89 55 d4 8b 55 e0 29 c8 19 da Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] EIP: [<f8ca8689>] kvm_write_tsc+0xc9/0x390 [kvm] SS:ESP 0068:f2499d2c Jan 16 15:56:18 vmbase3 kernel: [ 305.360042] ---[ end trace 0c4699bcaf67a469 ]--- Jan 16 15:56:27 vmbase3 kernel: [ 315.360049] breth0: port 2(vnet0) entered forwarding state Куда копать дальше? Обсуждение на форуме: http://forum.altlinux.org/index.php/topic,30539.0.html Похожий случай: https://bugzilla.redhat.com/show_bug.cgi?id=859282 144670 1 asy 2014-01-16 14:41:38 +0400 (In reply to comment #0) > Похожий случай: https://bugzilla.redhat.com/show_bug.cgi?id=859282 По поводу похожести, я на лог из первого сообщения с форума смотрел, там было Oct 31 15:34:53 vmbase3 kernel: [ 41.316033] BUG: sleeping function called from invalid context at kernel/rwsem.c:20 Oct 31 15:34:53 vmbase3 kernel: [ 41.316033] in_atomic(): 1, irqs_disabled(): 1, pid: 4049, name: qemu-kvm Oct 31 15:34:53 vmbase3 kernel: [ 41.316033] CPU: 0 PID: 4049 Comm: qemu-kvm Tainted: G D 3.10.12-std-def-alt1 #1 144676 2 boyarsh 2014-01-16 17:02:14 +0400 (В ответ на комментарий №1) > (In reply to comment #0) > > > Похожий случай: https://bugzilla.redhat.com/show_bug.cgi?id=859282 Этот патч (https://bugzilla.redhat.com/attachment.cgi?id=709835) присутствует в нашем ядре. 144685 3 4pavel_v 2014-01-17 05:48:28 +0400 Первый лог - без обновленного ядра, текущий - последнее ядро. Если патч присутствует в нашем ядре, то почему возникает ошибка? Какие мои дальнейшие действия? Как проверить, что патч задействован? 144686 4 4pavel_v 2014-01-17 06:01:18 +0400 Править свои комментарии тут нельзя :( Так же волнует вопрос: почему система при установке и после этого нормально работала. По идее ничего же не менялось. Почему данный косяк проявляется со временем. Причем заранее не известно, когда это произойдет следующий раз. В прошлые разы просто брал и по быстрому переустанавливал систему, импортировал виртуальные машинки и работал дальше. Но тогда я грешил на то, что это тестовый сервер, ставил кучу не нужного софта. Сейчас самый минимум для виртуализации. 144691 5 boyarsh 2014-01-17 11:50:07 +0400 (В ответ на комментарий №3) > Первый лог - без обновленного ядра, текущий - последнее ядро. > Если патч присутствует в нашем ядре, то почему возникает ошибка? Значит это похожая, но всё-таки другая ошибка. > Какие мои дальнейшие действия? Пока попробовать другие ядра (el-def, например). Во всяком случае, я пока совершенно не могу понять, как в этом месте может возникнуть такая ошибка после исправлений Marcelo Tosatti в марте прошлого года. 144692 6 4pavel_v 2014-01-17 12:22:39 +0400 (В ответ на комментарий №5) > Пока попробовать другие ядра (el-def, например). Во всяком случае, я пока > совершенно не могу понять, как в этом месте может возникнуть такая ошибка после > исправлений Marcelo Tosatti в марте прошлого года. С другими ядрами, другие проблемы :(. Уже точно не могу вспомнить какие проблемы были с ovz-el(когда только тестировал всю свою связку), но самым без проблемным оказался std-def. С программированием под линукс опыта очень мало, практически нет. Заранее извиняюсь за возможную корявость изложения, но есть следующее предложение. Можно ли как-то создать/написать аналог данной функции с выводом отладочной информации в консоль/фаил? Или скрипт написать? Что бы его запустить прям на моем сервере и посмотреть, что не так? Потом проанализировать, подправить и опять запустить? 144710 7 mike 2014-01-18 17:13:45 +0400 (В ответ на комментарий №6) > С другими ядрами, другие проблемы :(. Уже точно не могу вспомнить какие > проблемы были с ovz-el(когда только тестировал всю свою связку), но самым без > проблемным оказался std-def. Проверьте ещё led-ws. 144719 8 4pavel_v 2014-01-20 09:22:08 +0400 (В ответ на комментарий №7) > (В ответ на комментарий №6) > > С другими ядрами, другие проблемы :(. Уже точно не могу вспомнить какие > > проблемы были с ovz-el(когда только тестировал всю свою связку), но самым без > > проблемным оказался std-def. > Проверьте ещё led-ws. Все тоже самое: [root@vmbase3 ~]# uname -r 3.4.77-led-ws-alt0.M70P.1 cat /var/log/messages Jan 20 12:15:27 vmbase3 libvirtd: libvirtd startup succeeded Jan 20 12:15:27 vmbase3 kernel: ip_tables: (C) 2000-2006 Netfilter Core Team Jan 20 12:15:27 vmbase3 kernel: nf_conntrack version 0.5.0 (16384 buckets, 65536 max) Jan 20 12:15:27 vmbase3 avahi-daemon[3664]: Joining mDNS multicast group on interface virbr0.IPv4 with address 192.168.122.1. Jan 20 12:15:27 vmbase3 avahi-daemon[3664]: New relevant interface virbr0.IPv4 for mDNS. Jan 20 12:15:27 vmbase3 avahi-daemon[3664]: Registering new address record for 192.168.122.1 on virbr0.IPv4. Jan 20 12:15:27 vmbase3 kernel: ADDRCONF(NETDEV_UP): virbr0: link is not ready Jan 20 12:15:27 vmbase3 avahi-daemon[3664]: Interface virbr0.IPv4 no longer relevant for mDNS. Jan 20 12:15:27 vmbase3 avahi-daemon[3664]: Leaving mDNS multicast group on interface virbr0.IPv4 with address 192.168.122.1. Jan 20 12:15:27 vmbase3 avahi-daemon[3664]: Withdrawing address record for 192.168.122.1 on virbr0. Jan 20 12:15:27 vmbase3 dhcpcd[2918]: manage_link: No such device or address Jan 20 12:15:27 vmbase3 avahi-daemon[3664]: Withdrawing workstation service for virbr0. Jan 20 12:15:28 vmbase3 kernel: Ebtables v2.0 registered Jan 20 12:15:28 vmbase3 kernel: ip6_tables: (C) 2000-2006 Netfilter Core Team Jan 20 12:15:32 vmbase3 kernel: device vnet0 entered promiscuous mode Jan 20 12:15:32 vmbase3 kernel: breth0: port 2(vnet0) entered forwarding state Jan 20 12:15:32 vmbase3 kernel: breth0: port 2(vnet0) entered forwarding state Jan 20 12:15:33 vmbase3 avahi-daemon[3664]: Registering new address record for fe80::fc54:ff:fe7d:dec4 on vnet0.*. Jan 20 12:15:34 vmbase3 kernel: divide error: 0000 [#1] PREEMPT SMP Jan 20 12:15:34 vmbase3 kernel: Modules linked in: vhost_net macvtap macvlan ip6table_filter ip6_tables ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables sunrpc af_packet bridge stp llc ipv6 dm_multipath scsi_dh mousedev sr_mod kvm_intel(O) kvm(O) cdrom coretemp ahci acpi_cpufreq dm_mod mperf r8169 microcode libahci pata_jmicron 8250_pnp psmouse ppdev mii pcspkr i2c_i801 firmware_class 8250 serial_core intel_agp processor uhci_hcd intel_gtt parport_pc ehci_hcd agpgart parport thermal_sys asus_atk0110 hwmon tun ext4 crc16 jbd2 mbcache ata_piix ata_generic pata_acpi serio_raw libata evdev mac_hid Jan 20 12:15:34 vmbase3 kernel: Jan 20 12:15:34 vmbase3 kernel: Pid: 4954, comm: qemu-kvm Tainted: G O 3.4.77-led-ws-alt0.M70P.1 #1 System manufacturer System Product Name/P5B Jan 20 12:15:34 vmbase3 kernel: EIP: 0060:[<f85c1a1d>] EFLAGS: 00210016 CPU: 0 Jan 20 12:15:34 vmbase3 kernel: EIP is at kvm_write_tsc+0xfd/0x440 [kvm] Jan 20 12:15:34 vmbase3 kernel: EAX: a5fc7b38 EBX: f4cfc000 ECX: 001c817f EDX: 00175de4 Jan 20 12:15:34 vmbase3 kernel: ESI: 00175c78 EDI: f470fdd4 EBP: f4738000 ESP: f470fd48 Jan 20 12:15:34 vmbase3 kernel: DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068 Jan 20 12:15:34 vmbase3 kernel: CR0: 8005003b CR2: b75e62f0 CR3: 346da000 CR4: 000027d0 Jan 20 12:15:34 vmbase3 kernel: DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 Jan 20 12:15:34 vmbase3 kernel: DR6: ffff0ff0 DR7: 00000400 Jan 20 12:15:34 vmbase3 kernel: Process qemu-kvm (pid: 4954, ti=f470e000 task=f54d8860 task.ti=f470e000) Jan 20 12:15:34 vmbase3 kernel: Stack: Jan 20 12:15:34 vmbase3 kernel: 5d5998b3 000005fb 39cf93d7 00000019 00175c78 00000000 b2afa37f 00000018 Jan 20 12:15:34 vmbase3 kernel: 0258ff59 000005c0 f4cfd540 f470fdd4 a5fc7b38 00175de4 00200296 00000003 Jan 20 12:15:34 vmbase3 kernel: 0000006c 14825bd7 00000010 000005fb f4738000 5d5998b3 f865cff7 00000277 Jan 20 12:15:34 vmbase3 kernel: Call Trace: Jan 20 12:15:35 vmbase3 kernel: [<f865cff7>] ? vmx_read_l1_tsc+0x2d17/0xa453 [kvm_intel] Jan 20 12:15:35 vmbase3 kernel: [<f865a4f3>] ? vmx_read_l1_tsc+0x213/0xa453 [kvm_intel] Jan 20 12:15:35 vmbase3 kernel: [<f85bf6f0>] ? kvm_enable_efer_bits+0x20/0x180 [kvm] Jan 20 12:15:35 vmbase3 kernel: [<f85bf71b>] ? kvm_enable_efer_bits+0x4b/0x180 [kvm] Jan 20 12:15:35 vmbase3 kernel: [<f85c1081>] ? kvm_set_cr8+0x201/0x280 [kvm] Jan 20 12:15:35 vmbase3 kernel: [<f85c47c5>] ? kvm_arch_vcpu_ioctl+0x535/0xd30 [kvm] Jan 20 12:15:35 vmbase3 kernel: [<f865c4fe>] ? vmx_read_l1_tsc+0x221e/0xa453 [kvm_intel] Jan 20 12:15:35 vmbase3 kernel: [<f865c6f6>] ? vmx_read_l1_tsc+0x2416/0xa453 [kvm_intel] Jan 20 12:15:35 vmbase3 kernel: [<f85c768f>] ? kvm_arch_vcpu_ioctl_set_sregs+0x2df/0x410 [kvm] Jan 20 12:15:35 vmbase3 kernel: [<f85c40f0>] ? kvm_arch_vcpu_load+0x50/0x1f0 [kvm] Jan 20 12:15:35 vmbase3 kernel: [<f85bd151>] ? vcpu_put+0x1f1/0x560 [kvm] Jan 20 12:15:35 vmbase3 kernel: [<c10570a8>] ? trigger_load_balance+0x48/0x280 Jan 20 12:15:35 vmbase3 kernel: [<f85bcfc0>] ? vcpu_put+0x60/0x560 [kvm] Jan 20 12:15:35 vmbase3 kernel: [<c1100cba>] ? do_vfs_ioctl+0x7a/0x550 Jan 20 12:15:35 vmbase3 kernel: [<c101b863>] ? lapic_next_event+0x13/0x20 Jan 20 12:15:35 vmbase3 kernel: [<c106a81e>] ? clockevents_program_event+0x9e/0x150 Jan 20 12:15:35 vmbase3 kernel: [<c106b9b1>] ? tick_program_event+0x21/0x30 Jan 20 12:15:35 vmbase3 kernel: [<c10486bb>] ? hrtimer_interrupt+0x16b/0x280 Jan 20 12:15:35 vmbase3 kernel: [<c11011fa>] ? sys_ioctl+0x6a/0x80 Jan 20 12:15:35 vmbase3 kernel: [<c1339125>] ? syscall_call+0x7/0xb Jan 20 12:15:35 vmbase3 kernel: [<c1330000>] ? rcu_init_percpu_data+0x92/0xc6 Jan 20 12:15:35 vmbase3 kernel: Code: 8b 44 24 30 69 f2 e8 03 00 00 89 74 24 10 be e8 03 00 00 f7 e6 8b 74 24 10 01 f2 89 44 24 30 8b 44 24 30 89 54 24 34 8b 54 24 34 <f7> f9 31 d2 89 44 24 10 8b 44 24 08 89 54 24 14 8b 54 24 0c 2b Jan 20 12:15:35 vmbase3 kernel: EIP: [<f85c1a1d>] kvm_write_tsc+0xfd/0x440 [kvm] SS:ESP 0068:f470fd48 Jan 20 12:15:35 vmbase3 kernel: ---[ end trace 246409d94e521933 ]--- Jan 20 12:15:35 vmbase3 kernel: note: qemu-kvm[4954] exited with preempt_count 1 Jan 20 12:15:47 vmbase3 kernel: breth0: port 2(vnet0) entered forwarding state 144733 9 aen 2014-01-21 09:02:49 +0400 (В ответ на комментарий №2) > (В ответ на комментарий №1) > > (In reply to comment #0) > > > > > Похожий случай: https://bugzilla.redhat.com/show_bug.cgi?id=859282 > Этот патч (https://bugzilla.redhat.com/attachment.cgi?id=709835) присутствует в > нашем ядре. https://bugzilla.redhat.com/show_bug.cgi?id=969644 https://patchwork.kernel.org/patch/2707801/ Там же, но другой.