|
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] Re: [Xen-devel] Making snapshot of logical volumes handling HVM domU causes OOPS and instability
On 8/31/2010 2:06 PM, Scott Garron wrote: I'm going to try to reproduce it on another, less critical machine today, so I can poke at it a little more. I'll let you know what I find.
To try to replicate my server environment as close as possible, I
installed, onto my desktop machine, the same version of Xen, the same
version of the Linux paravirt dom0 kernel, and four virtual machines: 1
64bit HVM, 1 32bit HVM, 1 64bit paravirt, and 1 32bit paravirt.
My desktop machine has "similar" architecture in that it's AMD (but
it's Athlon64 X2 5000+, not Opteron 1212) and I have not yet been able
to trigger the bug. I ran into a different problem in which both the
dom0 console and HVM domUs would periodically hang for several seconds
and then return as if nothing was wrong. That happened every minute or
so and was really annoying, but I ended up fixing it by unsetting
CONFIG_NO_HZ in the kernel, and everything ran pretty smoothly after that.
I went ahead and unset some other kernel options, too - mostly
things that were listed as "Experimental" or "If you don't know what
this is, say N" and such. It ran the entire day, and I set up a while
true; do lvcreate ; sleep 2 ; lvremove ; sleep 2 ; done kind of script
to just sit there and peg lvm/dm & udev for about 15-20 minutes
straight, without incident. I'm not sure what to make of that in terms
of a conclusion, though. It could just be slightly different
architecture or the fact that the machine has overall less RAM (4G
instead of 8G). The distribution is the same, and all of the versions
of software are the same. They're both dual core AMD 64bit CPUs.
On a hunch, I copied the kernel config from my desktop to the
server, recompiled with those options, booted into it, and tried
triggering the bug. It took more than two tries this time around, but
it became apparent pretty quickly that things weren't quite right.
Creations and removals of snapshot volumes started causing lvm to return
"/dev/dm-63: open failed: no such device or address" and something along
the lines of (paraphrasing here) "unable to remove active logical
volume" when the snapshot wasn't mounted or active anywhere, but a few
seconds later, without changing anything, you could remove it. udev
didn't seem to be removing the dm-?? devices from /dev, though.
After the backup script had created and deleted about 12 snapshots
or so (not necessarily ones associated with an HVM guest this time
around), I got an oops and the lvcreate command froze. I was able to
get the output of ps -eH -owchan,nwchan,cmd this time, though:
WCHAN WCHAN CMD
kthrea ffffff [kthreadd]
? ffffff [migration/0]
? ffffff [ksoftirqd/0]
migrat ffffff [migration/1]
ksofti ffffff [ksoftirqd/1]
? ffffff [events/0]
worker ffffff [events/1]
worker ffffff [khelper]
worker ffffff [netns]
async_ ffffff [async/mgr]
xenwat ffffff [xenwatch]
xb_wai ffffff [xenbus]
bdi_sy ffffff [sync_supers]
bdi_fo ffffff [bdi-default]
? ffffff [kblockd/0]
worker ffffff [kblockd/1]
worker ffffff [kacpid]
worker ffffff [kacpi_notify]
worker ffffff [kacpi_hotplug]
worker ffffff [ata/0]
worker ffffff [ata/1]
worker ffffff [ata_aux]
worker ffffff [ksuspend_usbd]
hub_th ffffff [khubd]
serio_ ffffff [kseriod]
worker ffffff [rpciod/0]
worker ffffff [rpciod/1]
kswapd ffffff [kswapd0]
ksm_sc ffffff [ksmd]
worker ffffff [aio/0]
worker ffffff [aio/1]
worker ffffff [nfsiod]
worker ffffff [crypto/0]
worker ffffff [crypto/1]
khvcd ffffff [khvcd]
scsi_e ffffff [scsi_eh_0]
scsi_e ffffff [scsi_eh_1]
scsi_e ffffff [scsi_eh_2]
scsi_e ffffff [scsi_eh_3]
scsi_e ffffff [scsi_eh_4]
scsi_e ffffff [scsi_eh_5]
scsi_e ffffff [scsi_eh_6]
scsi_e ffffff [scsi_eh_7]
worker ffffff [kpsmoused]
worker ffffff [kstriped]
worker ffffff [kondemand/0]
worker ffffff [kondemand/1]
worker ffffff [usbhid_resumer]
md_thr ffffff [md0_raid1]
md_thr ffffff [md1_raid1]
worker ffffff [kdmflush]
worker ffffff [reiserfs/0]
worker ffffff [reiserfs/1]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
worker ffffff [kdmflush]
bdi_wr ffffff [flush-253:39]
svc_re ffffff [lockd]
worker ffffff [nfsd4]
svc_re ffffff [nfsd]
svc_re ffffff [nfsd]
svc_re ffffff [nfsd]
svc_re ffffff [nfsd]
svc_re ffffff [nfsd]
svc_re ffffff [nfsd]
svc_re ffffff [nfsd]
svc_re ffffff [nfsd]
blkif_ ffffff [blkback.1.xvda1]
blkif_ ffffff [blkback.1.xvda2]
blkif_ ffffff [blkback.2.xvda1]
blkif_ ffffff [blkback.2.xvda2]
blkif_ ffffff [blkback.2.xvdb1]
blkif_ ffffff [blkback.3.xvda1]
blkif_ ffffff [blkback.3.xvda2]
loop_t ffffff [loop0]
bdi_wr ffffff [flush-253:40]
blkif_ ffffff [blkback.5.xvda1]
blkif_ ffffff [blkback.5.xvda2]
blkif_ ffffff [blkback.5.xvda3]
blkif_ ffffff [blkback.5.xvdb1]
blkif_ ffffff [blkback.5.xvdb2]
blkif_ ffffff [blkback.6.xvda1]
blkif_ ffffff [blkback.6.xvda2]
blkif_ ffffff [blkback.6.xvda3]
loop_t ffffff [loop1]
loop_t ffffff [loop2]
bdi_wr ffffff [flush-253:48]
blkif_ ffffff [blkback.9.xvda1]
blkif_ ffffff [blkback.9.xvda2]
blkif_ ffffff [blkback.10.xvda]
blkif_ ffffff [blkback.10.xvda]
worker ffffff [ksnapd]
poll_s ffffff init [2]
poll_s ffffff /sbin/portmap
poll_s ffffff /sbin/rpc.statd
epoll_ ffffff /usr/sbin/rpc.idmapd
sync_p ffffff /sbin/syslogd
hrtime ffffff /usr/sbin/nmbd -D
poll_s ffffff /usr/sbin/acpid
sync_p ffffff /usr/sbin/rpc.mountd --manage-gids
poll_s ffffff /usr/sbin/smbd -D
poll_s ffffff /usr/sbin/smbd -D
poll_s ffffff /usr/sbin/apache2 -k start
skb_re ffffff /usr/sbin/apache2 -k start
pipe_w ffffff /usr/sbin/apache2 -k start
pipe_w ffffff /usr/sbin/apache2 -k start
unix_w ffffff /sbin/klogd -x
poll_s ffffff /usr/bin/dbus-daemon --system
poll_s ffffff /sbin/mdadm --monitor --pid-file
/var/run/mdadm/monitor.pid --daemonise --scan --syslog
poll_s ffffff /usr/sbin/pptpd
poll_s ffffff /usr/sbin/bcrelay -i xenbr1 -o ppp[0-9].* -n
poll_s ffffff /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 110:110
hrtime ffffff /usr/sbin/cron
sync_p ffffff /USR/SBIN/CRON
sync_p ffffff /USR/SBIN/CRON
sync_p ffffff /USR/SBIN/CRON
sync_p ffffff /USR/SBIN/CRON
sync_p ffffff /USR/SBIN/CRON
pipe_w ffffff /usr/sbin/radvd -u radvd -p /var/run/radvd/radvd.pid
poll_s ffffff /usr/sbin/radvd -u radvd -p /var/run/radvd/radvd.pid
unix_w ffffff /usr/sbin/snmpd -Ls6d -Lf /dev/null -u snmp -g snmp -I
-smux -p /var/run/snmpd.pid 192.168.1.4
poll_s ffffff /usr/bin/python /usr/bin/fail2ban-server -b -s
/var/run/fail2ban/fail2ban.sock
epoll_ ffffff /usr/lib/postfix/master
epoll_ ffffff qmgr -l -t fifo -u
epoll_ ffffff pickup -l -t fifo -u -c
n_tty_ ffffff /sbin/getty 38400 tty2
n_tty_ ffffff /sbin/getty 38400 tty3
n_tty_ ffffff /sbin/getty 38400 tty4
n_tty_ ffffff /sbin/getty 38400 tty5
n_tty_ ffffff /sbin/getty 38400 tty6
poll_s ffffff /usr/sbin/console-kit-daemon --no-daemon
poll_s ffffff /usr/sbin/sshd
unix_s ffffff sshd: simba [priv]
poll_s ffffff sshd: simba@pts/10
wait 532bd -bash
wait ffffff su -
wait ffffff -su
wait ffffff /bin/bash ./backuplv hurricanevg1/digit-root
blockd ffffff lvcreate -p r -L 2048M -n
digit-root-backupsnap -s hurricanevg1/digit-root
unix_s ffffff sshd: simba [priv]
poll_s ffffff sshd: simba@pts/11
wait 532bd -bash
- - ps -eH -owchan,nwchan,cmd
poll_s ffffff xenstored --pid-file /var/run/xenstore.pid
poll_s ffffff xenconsoled
wait ffffff /usr/bin/python /usr/sbin/xend start
poll_s ffffff /usr/bin/python /usr/sbin/xend start
poll_s ffffff /usr/lib/xen/bin/qemu-dm -d 4 -domain-name orko
-videoram 4 -vnc 192.168.0.90:2,password -vncunused -vcpus 1 -vcpu_avail
0x1 -boot c -serial pty -acpi -net
nic,vlan=1,macaddr=00:16:3e:00:00:12,model=rtl8139 -net
tap,vlan=1,ifname=tap4.0,bridge=eth0 -net
nic,vlan=2,macaddr=00:16:3e:00:00:13,model=rtl8139 -net
tap,vlan=2,ifname=tap4.1,bridge=xenbr1 -M xenfv
poll_s ffffff /usr/lib/xen/bin/qemu-dm -d 7 -domain-name snarf
-videoram 4 -vnc 192.168.0.90:4,password -vncunused -vcpus 1 -vcpu_avail
0x1 -boot c -localtime -serial pty -acpi -net
nic,vlan=1,macaddr=00:16:3e:00:00:1B,model=rtl8139 -net
tap,vlan=1,ifname=tap7.0,bridge=eth0 -net
nic,vlan=2,macaddr=00:16:3e:00:00:1C,model=rtl8139 -net
tap,vlan=2,ifname=tap7.1,bridge=xenbr1 -net
nic,vlan=3,macaddr=00:16:3e:00:00:1D,model=rtl8139 -net
tap,vlan=3,ifname=tap7.2,bridge=xenbr2 -M xenfv
poll_s ffffff /usr/lib/xen/bin/qemu-dm -d 8 -domain-name scrappy
-videoram 4 -vnc 192.168.0.90:3,password -vncunused -vcpus 1 -vcpu_avail
0x1 -boot c -localtime -serial pty -acpi -net
nic,vlan=1,macaddr=00:16:3e:00:00:18,model=rtl8139 -net
tap,vlan=1,ifname=tap8.0,bridge=eth0 -net
nic,vlan=2,macaddr=00:16:3e:00:00:19,model=rtl8139 -net
tap,vlan=2,ifname=tap8.1,bridge=xenbr1 -net
nic,vlan=3,macaddr=00:16:3e:00:00:1A,model=rtl8139 -net
tap,vlan=3,ifname=tap8.2,bridge=xenbr2 -M xenfv
n_tty_ ffffff /sbin/getty 38400 tty1
unix_w ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
exit ffffff [udevd] <defunct>
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
exit ffffff [udevd] <defunct>
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
poll_s ffffff udevd --daemon
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-8
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-7
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-10
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-12
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-15
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-16
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-19
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-18
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-23
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-22
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-20
sync_p ffffff /sbin/blkid -o udev -p /dev/dm-21
? ffffff [udevd]
sync_p ffffff /lib/udev/udisks-part-id /dev/dm-4
########################
And the oops looks different this time around as well:
[ 6791.053986] ------------[ cut here ]------------
[ 6791.054160] kernel BUG at arch/x86/xen/mmu.c:1649!
[ 6791.054418] invalid opcode: 0000 [#1] SMP
[ 6791.054592] last sysfs file: /sys/devices/virtual/block/dm-1/removable
[ 6791.054761] CPU 0
[ 6791.054923] Modules linked in: dm_snapshot tun fuse xt_multiport
nf_nat_tftp nf_conntrack_tftp nf_nat_pptp nf_conntrack_pptp
nf_conntrack_proto_gre nf_nat_proto_gre ntfs parport_pc parport k8temp
floppy forcedeth [last unloaded: scsi_wait_scan]
[ 6791.055653] Pid: 8696, comm: udevd Tainted: G W 2.6.32.18 #2
H8SMI
[ 6791.055828] RIP: e030:[<ffffffff8100cc33>] [<ffffffff8100cc33>]
pin_pagetable_pfn+0x31/0x37
[ 6791.056010] RSP: e02b:ffff88001242fdb8 EFLAGS: 00010282
[ 6791.056010] RAX: 00000000ffffffea RBX: 000000000002af28 RCX:
00003ffffffff000
[ 6791.056010] RDX: 0000000000000000 RSI: 0000000000000001 RDI:
ffff88001242fdb8
[ 6791.056010] RBP: ffff88001242fdd8 R08: 00003ffffffff000 R09:
ffff880000000ab8
[ 6791.056010] R10: 0000000000007ff0 R11: 000000000001b4fe R12:
0000000000000003
[ 6791.056010] R13: ffff880001d03010 R14: ffff88001a8e88f0 R15:
ffff880027f50000
[ 6791.056010] FS: 00007fdb8bfd57a0(0000) GS:ffff880002d6e000(0000)
knlGS:0000000000000000
[ 6791.056010] CS: e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 6791.056010] CR2: 0000000000413e41 CR3: 000000001a84c000 CR4:
0000000000000660
[ 6791.056010] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[ 6791.056010] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
0000000000000400
[ 6791.056010] Process udevd (pid: 8696, threadinfo ffff88001242e000,
task ffff880027f50000)
[ 6791.056010] Stack:
[ 6791.056010] ffff880000000000 000000000016f22f 0000000000000010
000000000002af28
[ 6791.056010] <0> ffff88001242fdf8 ffffffff8100e515 ffff8800125a6680
000000000002af28
[ 6791.056010] <0> ffff88001242fe08 ffffffff8100e548 ffff88001242fe48
ffffffff810c8ab2
[ 6791.056010] Call Trace:
[ 6791.056010] [<ffffffff8100e515>] xen_alloc_ptpage+0x66/0x6b
[ 6791.056010] [<ffffffff8100e548>] xen_alloc_pte+0xe/0x10
[ 6791.056010] [<ffffffff810c8ab2>] __pte_alloc+0x7e/0xf8
[ 6791.056010] [<ffffffff810cae78>] handle_mm_fault+0xbb/0x7cb
[ 6791.056010] [<ffffffff81582f75>] ? page_fault+0x25/0x30
[ 6791.056010] [<ffffffff810381d1>] do_page_fault+0x273/0x28b
[ 6791.056010] [<ffffffff81582f75>] page_fault+0x25/0x30
[ 6791.056010] Code: ec 20 89 7d e0 48 89 f7 e8 c9 ff ff ff 48 8d 7d e0
48 89 45 e8 be 01 00 00 00 31 d2 41 ba f0 7f 00 00 e8 11 c7 ff ff 85 c0
74 04 <0f> 0b eb fe c9 c3 55 48 89 f8 a8 01 48 89 e5 53 74 21 48 bb ff
[ 6791.056010] RIP [<ffffffff8100cc33>] pin_pagetable_pfn+0x31/0x37
[ 6791.056010] RSP <ffff88001242fdb8>
[ 6791.056010] ---[ end trace 4eaa2a86a8e2da24 ]---
#################
Some other things that I noticed... During boot, there were
several messages that looked like this:
udevd: worker did not accept message -1 (Connection refused) kill it
(I may be slightly paraphrasing that)
and this "WARNING" also appears:
[ 0.004000] CPU: Physical Processor ID: 0
[ 0.004000] CPU: Processor Core ID: 0
[ 0.004015] mce: CPU supports 5 MCE banks
[ 0.004231] Performance Events: AMD PMU driver.
[ 0.004450] ------------[ cut here ]------------
[ 0.004644] WARNING: at arch/x86/xen/enlighten.c:742
xen_apic_write+0x15/0x17()
[ 0.004990] Hardware name: H8SMI
[ 0.005176] Modules linked in:
[ 0.005391] Pid: 0, comm: swapper Not tainted 2.6.32.18 #2
[ 0.005581] Call Trace:
[ 0.005771] [<ffffffff810504df>] warn_slowpath_common+0x77/0x8f
[ 0.005965] [<ffffffff81050506>] warn_slowpath_null+0xf/0x11
[ 0.006157] [<ffffffff8100b30b>] xen_apic_write+0x15/0x17
[ 0.006350] [<ffffffff8101f0d6>] perf_events_lapic_init+0x2e/0x30
[ 0.006545] [<ffffffff8193eae0>] init_hw_perf_events+0x33e/0x3db
[ 0.006740] [<ffffffff8193e714>] identify_boot_cpu+0x3c/0x3e
[ 0.006932] [<ffffffff8193e77e>] check_bugs+0x9/0x2d
[ 0.007125] [<ffffffff81935d1d>] start_kernel+0x3ae/0x3c3
[ 0.007318] [<ffffffff819352c1>] x86_64_start_reservations+0xac/0xb0
[ 0.007513] [<ffffffff81939184>] xen_start_kernel+0x643/0x64a
[ 0.007710] ---[ end trace 4eaa2a86a8e2da22 ]---
[ 0.007900] ... version: 0
[ 0.008000] ... bit width: 48
[ 0.008000] ... generic registers: 4
[ 0.008000] ... value mask: 0000ffffffffffff
[ 0.008000] ... max period: 00007fffffffffff
[ 0.008000] ... fixed-purpose events: 0
[ 0.008000] ... event mask: 000000000000000f
[ 0.008000] SMP alternatives: switching to UP code
[ 0.008000] ACPI: Core revision 20090903
Any ideas, or does this look more like a bug with LVM/DM?
( I've also tacked this new information, including the new kernel
configuration onto the text file at:
http://www.pridelands.org/~simba/hurricane-server.txt )
I haven't tried disabling udev yet, but to be honest, I'm not even
sure how to pull that off without really breaking things. Can I create
and remove snapshots and logical volumes without udev on a system that's
already kinda reliant on udev?
This post (and subsequent thread), made today, seems to be eerily
similar to the problem I'm experiencing. I'm wondering if they're related.
http://lists.xensource.com/archives/html/xen-devel/2010-09/msg00169.html
_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-devel
|
 |
Lists.xenproject.org is hosted with RackSpace, monitoring our |