Making snapshot of logical volumes handling HVM domU causes OOPS and instability

Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Scott Garron]

I use LVM volumes for domU disks.  To create backups, I create a
snapshot of the volume, mount the snapshot in the dom0, mount an
equally-sized backup volume from another physical storage source, run an
rsync from one to the other, unmount both, then remove the snapshot.
This includes creating a snapshot and mounting NTFS volumes from
Windows-based HVM guests.

This practice may not be perfect, but has worked fine for me for a
couple of years - while I was running Xen 3.2.1 and linux-2.6.18.8-xen
dom0 (and the same kernel for domU).  After upgrades of udev started
complaining about the kernel being too old, I thought it was well past
time to try to transition to a newer version of Xen and a newer dom0
kernel.  This transition has been a gigantic learning experience, let me
tell you.

After that transition, here's the problem I've been wrestling with and
can't seem to find a solution for:  It seems like any time I start
manipulating a volume group to add or remove a snapshot of a logical
volume that's used as a disk for a running HVM guest, new calls to LVM2
and/or Xen's storage locks up and spins forever.  The first time I ran
across the problem, there was no indication of a problem other than
any command I ran that handled anything to do with LVM would freeze and
be completely unable to be signaled to do anything.  In other words, no
error messages, nothing in dmesg, nothing in syslog...  The commands
would just freeze and not return.  That was with the 2.6.31.14 kernel
that is what's currently retrieved if you checkout xen-4.0-testing.hg
and just do a make dist.

I have since checked out and compiled 2.6.32.18 that comes from doing
git checkout -b xen/stable-2.6.32.x origin/xen/stable-2.6.32.x, as
described on the Wiki page here:
http://wiki.xensource.com/xenwiki/XenParavirtOps

If I run that kernel for dom0, but continue to use 2.6.31.14 for the
paravirtualized domUs, everything works fine until I try to manipulate
the snapshots of the HVM volumes.  Today, I got this kernel OOPS:

---------------------------

[78084.004530] BUG: unable to handle kernel paging request at
ffff8800267c9010
[78084.004710] IP: [<ffffffff810382ff>] xen_set_pmd+0x24/0x44
[78084.004886] PGD 1002067 PUD 1006067 PMD 217067 PTE 80100000267c9065
[78084.005065] Oops: 0003 [#1] SMP
[78084.005234] last sysfs file: /sys/devices/virtual/block/dm-32/removable
[78084.005256] CPU 1
[78084.005256] Modules linked in: tun xt_multiport fuse dm_snapshot
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]
[78084.005256] Pid: 22814, comm: udevd Tainted: G        W  2.6.32.18 #1
H8SMI
[78084.005256] RIP: e030:[<ffffffff810382ff>]  [<ffffffff810382ff>]
xen_set_pmd+0x24/0x44
[78084.005256] RSP: e02b:ffff88002e2e1d18  EFLAGS: 00010246
[78084.005256] RAX: 0000000000000000 RBX: ffff8800267c9010 RCX:
ffff880000000000
[78084.005256] RDX: dead000000100100 RSI: 0000000000000000 RDI:
0000000000000004
[78084.005256] RBP: ffff88002e2e1d28 R08: 0000000001993000 R09:
dead000000100100
[78084.005256] R10: 800000016e90e165 R11: 0000000000000000 R12:
0000000000000000
[78084.005256] R13: ffff880002d8f580 R14: 0000000000400000 R15:
ffff880029248000
[78084.005256] FS:  00007fa07d87f7a0(0000) GS:ffff880002d81000(0000)
knlGS:0000000000000000
[78084.005256] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[78084.005256] CR2: ffff8800267c9010 CR3: 0000000001001000 CR4:
0000000000000660
[78084.005256] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[78084.005256] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
0000000000000400
[78084.005256] Process udevd (pid: 22814, threadinfo ffff88002e2e0000,
task ffff880019491e80)
[78084.005256] Stack:
[78084.005256]  0000000000600000 000000000061e000 ffff88002e2e1de8
ffffffff810fb8a5
[78084.005256] <0> 00007fff13ffffff 0000000100000206 ffff880003158003
0000000000000000
[78084.005256] <0> 0000000000000000 000000000061dfff 000000000061dfff
000000000061dfff
[78084.005256] Call Trace:
[78084.005256]  [<ffffffff810fb8a5>] free_pgd_range+0x27c/0x45e
[78084.005256]  [<ffffffff810fbb2b>] free_pgtables+0xa4/0xc7
[78084.005256]  [<ffffffff810ff1fd>] exit_mmap+0x107/0x13f
[78084.005256]  [<ffffffff8107714b>] mmput+0x39/0xda
[78084.005256]  [<ffffffff8107adff>] exit_mm+0xfb/0x106
[78084.005256]  [<ffffffff8107c86d>] do_exit+0x1e8/0x6ff
[78084.005256]  [<ffffffff815c228b>] ? do_page_fault+0x2cd/0x2fd
[78084.005256]  [<ffffffff8107ce0d>] do_group_exit+0x89/0xb3
[78084.005256]  [<ffffffff8107ce49>] sys_exit_group+0x12/0x16
[78084.005256]  [<ffffffff8103cc82>] system_call_fastpath+0x16/0x1b
[78084.005256] Code: 48 83 c4 28 5b c9 c3 55 48 89 e5 41 54 49 89 f4 53
48 89 fb e8 fc ee ff ff 48 89 df ff 05 52 8f 9e 00 e8 78 e4 ff ff 84 c0
75 05 <4c> 89 23 eb 16 e8 e0 ee ff ff 4c 89 e6 48 89 df ff 05 37 8f 9e
[78084.005256] RIP  [<ffffffff810382ff>] xen_set_pmd+0x24/0x44
[78084.005256]  RSP <ffff88002e2e1d18>
[78084.005256] CR2: ffff8800267c9010
[78084.005256] ---[ end trace 4eaa2a86a8e2da24 ]---
[78084.005256] Fixing recursive fault but reboot is needed!

---------------------------

After that was printed on the console, use of anything that interacts
with Xen (xentop, xm) would freeze whatever command it was and not
return.  After trying to do a sane shutdown on the guests, the whole
dom0 locked completely.  Even the alt-sysrq things stopped working after
looking at a couple of them.

I feel it's probably necessary to mention that this is after several,
fairly rapid-fire creations and deletions of snapshot volumes.  I have
it scripted to make a snapshot, mount it, mount a backup volume, rsync
it, unmount both volumes, and delete the snapshot for 19 volumes in a
row.  In other words, there's a lot of disk I/O going on around the time
of the lockup.  It always seems to coincide with when it gets to the
volumes that are being used for active, running, Windows Server 2008,
HVM volumes.  That may be just coincidental, though, because those are
the last ones on the list.  15 volumes used in active, running
paravirtualized Linux guests are at the top of the list.


Another issue that comes up is that if I run the 2.6.32.18 pvops kernel
for my Linux domUs, after a time (usually only about an hour or so), the
network interfaces stop responding.  I don't know if the problem is
related, but it was something else that I noticed.  The only way to get
the network access to come back is to reboot the domU.  When I reverted
the domU kernel to 2.6.31.14, this problem goes away.  I'm not 100%
sure, but I think this issue also causes xm console to not allow you to
type on the console that you connect to.  If I connect to a console,
then issue an xm shutdown on the same domU from another terminal, all of
the console messages that show the play-by-play of the shutdown process
display, but my keyboard input doesn't seem to make it through.

Since I'm not a developer, I don't know if these questions are better
suited for the xen-users list, but since it generated an OOPS with the
word "BUG" in capital letters, I thought I'd post it here.  If that
assumption was incorrect, just give me a gentle nudge and I'll redirect
the inquiry to somewhere more appropriate.  :)

If you need any more information about my setup or steps used to
recreate the problem or other debugging information, I'll be happy to
accomodate.  Just let me know what you need and how I can get it.

Here's some more information about my setup:
http://www.pridelands.org/~simba/hurricane-server.txt


-- 
Scott Garron

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Jeremy Fitzhardinge]

 On 08/27/2010 06:22 PM, Scott Garron wrote:
> I use LVM volumes for domU disks.  To create backups, I create a
> snapshot of the volume, mount the snapshot in the dom0, mount an
> equally-sized backup volume from another physical storage source, run an
> rsync from one to the other, unmount both, then remove the snapshot.
> This includes creating a snapshot and mounting NTFS volumes from
> Windows-based HVM guests.
>
> This practice may not be perfect, but has worked fine for me for a
> couple of years - while I was running Xen 3.2.1 and linux-2.6.18.8-xen
> dom0 (and the same kernel for domU).  After upgrades of udev started
> complaining about the kernel being too old, I thought it was well past
> time to try to transition to a newer version of Xen and a newer dom0
> kernel.  This transition has been a gigantic learning experience, let me
> tell you.
>
> After that transition, here's the problem I've been wrestling with and
> can't seem to find a solution for:  It seems like any time I start
> manipulating a volume group to add or remove a snapshot of a logical
> volume that's used as a disk for a running HVM guest, new calls to LVM2
> and/or Xen's storage locks up and spins forever.  The first time I ran
> across the problem, there was no indication of a problem other than
> any command I ran that handled anything to do with LVM would freeze and
> be completely unable to be signaled to do anything.  In other words, no
> error messages, nothing in dmesg, nothing in syslog...  The commands
> would just freeze and not return.  That was with the 2.6.31.14 kernel
> that is what's currently retrieved if you checkout xen-4.0-testing.hg
> and just do a make dist.
>
> I have since checked out and compiled 2.6.32.18 that comes from doing
> git checkout -b xen/stable-2.6.32.x origin/xen/stable-2.6.32.x, as
> described on the Wiki page here:
> http://wiki.xensource.com/xenwiki/XenParavirtOps
>
> If I run that kernel for dom0, but continue to use 2.6.31.14 for the
> paravirtualized domUs, everything works fine until I try to manipulate
> the snapshots of the HVM volumes.  Today, I got this kernel OOPS:

That's definitely bad.  Something is causing udevd to end up with bad
pagetables which are causing a kernel crash on exit.  I'm not sure if
its *the* udevd or some transient child, but either way its bad.

Any thoughts on this Daniel?

>
> ---------------------------
>
> [78084.004530] BUG: unable to handle kernel paging request at
> ffff8800267c9010
> [78084.004710] IP: [<ffffffff810382ff>] xen_set_pmd+0x24/0x44
> [78084.004886] PGD 1002067 PUD 1006067 PMD 217067 PTE 80100000267c9065
> [78084.005065] Oops: 0003 [#1] SMP
> [78084.005234] last sysfs file:
> /sys/devices/virtual/block/dm-32/removable
> [78084.005256] CPU 1
> [78084.005256] Modules linked in: tun xt_multiport fuse dm_snapshot
> 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]
> [78084.005256] Pid: 22814, comm: udevd Tainted: G        W  2.6.32.18 #1
> H8SMI
> [78084.005256] RIP: e030:[<ffffffff810382ff>]  [<ffffffff810382ff>]
> xen_set_pmd+0x24/0x44
> [78084.005256] RSP: e02b:ffff88002e2e1d18  EFLAGS: 00010246
> [78084.005256] RAX: 0000000000000000 RBX: ffff8800267c9010 RCX:
> ffff880000000000
> [78084.005256] RDX: dead000000100100 RSI: 0000000000000000 RDI:
> 0000000000000004
> [78084.005256] RBP: ffff88002e2e1d28 R08: 0000000001993000 R09:
> dead000000100100
> [78084.005256] R10: 800000016e90e165 R11: 0000000000000000 R12:
> 0000000000000000
> [78084.005256] R13: ffff880002d8f580 R14: 0000000000400000 R15:
> ffff880029248000
> [78084.005256] FS:  00007fa07d87f7a0(0000) GS:ffff880002d81000(0000)
> knlGS:0000000000000000
> [78084.005256] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
> [78084.005256] CR2: ffff8800267c9010 CR3: 0000000001001000 CR4:
> 0000000000000660
> [78084.005256] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
> 0000000000000000
> [78084.005256] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
> 0000000000000400
> [78084.005256] Process udevd (pid: 22814, threadinfo ffff88002e2e0000,
> task ffff880019491e80)
> [78084.005256] Stack:
> [78084.005256]  0000000000600000 000000000061e000 ffff88002e2e1de8
> ffffffff810fb8a5
> [78084.005256] <0> 00007fff13ffffff 0000000100000206 ffff880003158003
> 0000000000000000
> [78084.005256] <0> 0000000000000000 000000000061dfff 000000000061dfff
> 000000000061dfff
> [78084.005256] Call Trace:
> [78084.005256]  [<ffffffff810fb8a5>] free_pgd_range+0x27c/0x45e
> [78084.005256]  [<ffffffff810fbb2b>] free_pgtables+0xa4/0xc7
> [78084.005256]  [<ffffffff810ff1fd>] exit_mmap+0x107/0x13f
> [78084.005256]  [<ffffffff8107714b>] mmput+0x39/0xda
> [78084.005256]  [<ffffffff8107adff>] exit_mm+0xfb/0x106
> [78084.005256]  [<ffffffff8107c86d>] do_exit+0x1e8/0x6ff
> [78084.005256]  [<ffffffff815c228b>] ? do_page_fault+0x2cd/0x2fd
> [78084.005256]  [<ffffffff8107ce0d>] do_group_exit+0x89/0xb3
> [78084.005256]  [<ffffffff8107ce49>] sys_exit_group+0x12/0x16
> [78084.005256]  [<ffffffff8103cc82>] system_call_fastpath+0x16/0x1b
> [78084.005256] Code: 48 83 c4 28 5b c9 c3 55 48 89 e5 41 54 49 89 f4 53
> 48 89 fb e8 fc ee ff ff 48 89 df ff 05 52 8f 9e 00 e8 78 e4 ff ff 84 c0
> 75 05 <4c> 89 23 eb 16 e8 e0 ee ff ff 4c 89 e6 48 89 df ff 05 37 8f 9e
> [78084.005256] RIP  [<ffffffff810382ff>] xen_set_pmd+0x24/0x44
> [78084.005256]  RSP <ffff88002e2e1d18>
> [78084.005256] CR2: ffff8800267c9010
> [78084.005256] ---[ end trace 4eaa2a86a8e2da24 ]---
> [78084.005256] Fixing recursive fault but reboot is needed!
>
> ---------------------------
>
> After that was printed on the console, use of anything that interacts
> with Xen (xentop, xm) would freeze whatever command it was and not
> return.  After trying to do a sane shutdown on the guests, the whole
> dom0 locked completely.  Even the alt-sysrq things stopped working after
> looking at a couple of them.
>
> I feel it's probably necessary to mention that this is after several,
> fairly rapid-fire creations and deletions of snapshot volumes.  I have
> it scripted to make a snapshot, mount it, mount a backup volume, rsync
> it, unmount both volumes, and delete the snapshot for 19 volumes in a
> row.  In other words, there's a lot of disk I/O going on around the time
> of the lockup.  It always seems to coincide with when it gets to the
> volumes that are being used for active, running, Windows Server 2008,
> HVM volumes.  That may be just coincidental, though, because those are
> the last ones on the list.  15 volumes used in active, running
> paravirtualized Linux guests are at the top of the list.
>
>
> Another issue that comes up is that if I run the 2.6.32.18 pvops kernel
> for my Linux domUs, after a time (usually only about an hour or so), the
> network interfaces stop responding.  I don't know if the problem is
> related, but it was something else that I noticed.  The only way to get
> the network access to come back is to reboot the domU.  When I reverted
> the domU kernel to 2.6.31.14, this problem goes away.

That's a separate problem in netfront that appears to be a bug in the
"smartpoll" code.  I think Dongxiao is looking into it.

> I'm not 100%
> sure, but I think this issue also causes xm console to not allow you to
> type on the console that you connect to.  If I connect to a console,
> then issue an xm shutdown on the same domU from another terminal, all of
> the console messages that show the play-by-play of the shutdown process
> display, but my keyboard input doesn't seem to make it through.

Hm, not familiar with this problem.  Perhaps its just something wrong
with your console settings for the domain?  Do you have "console=" on
the kernel command line?

> Since I'm not a developer, I don't know if these questions are better
> suited for the xen-users list, but since it generated an OOPS with the
> word "BUG" in capital letters, I thought I'd post it here.  If that
> assumption was incorrect, just give me a gentle nudge and I'll redirect
> the inquiry to somewhere more appropriate.  :)

Nope, they're both xen-devel fodder.  Thanks for posting.

    J

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Scott Garron]

On 08/30/2010 12:52 PM, Jeremy Fitzhardinge wrote:
> Something is causing udevd to end up with bad pagetables which are
> causing a kernel crash on exit.  I'm not sure if its *the* udevd or
> some transient child, but either way its bad.

      If it's any help, the version of udev on the machine in question is
160.  (udev_160-1_amd64.deb)  I've now added that info in the text file
that describes my system, referenced in my original post by this URL:
http://www.pridelands.org/~simba/hurricane-server.txt

>> I think this issue [unresponsive network interfaces] also causes xm
>> console to not allow you to type on the console
> Hm, not familiar with this problem.  Perhaps its just something wrong
> with your console settings for the domain?  Do you have "console=" on
> the kernel command line?

      I have "extra = "console=hvc0"" in the domU configuration files.
The keyboard input works just fine for some time.  It ceased accepting
input at around the same time that the network interfaces stopped
responding, but that could have just been coincidental.

      I wasn't paying full attention, so this may also have been related
to me attaching to the console twice (Running xm console on one ssh
session to the dom0 in addition to running xm console from another SSH
session to the dom0).  When I couldn't connect directly to the domU via
SSH on its network interface, I tried to attach to its console to do
troubleshooting.  I may have already been attached to its console from
another SSH session to the dom0 and I suppose that might cause a
conflict.   ...  which begs the question:  "Is this the desired/expected
behavior in this scenario?"

-- 
Scott Garron

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Daniel Stodden]

On Mon, 2010-08-30 at 12:52 -0400, Jeremy Fitzhardinge wrote:

> > After that transition, here's the problem I've been wrestling with and
> > can't seem to find a solution for:  It seems like any time I start
> > manipulating a volume group to add or remove a snapshot of a logical
> > volume that's used as a disk for a running HVM guest, new calls to LVM2
> > and/or Xen's storage locks up and spins forever.

Are you sure it's spinning or just freezing?

>   The first time I ran
> > across the problem, there was no indication of a problem other than
> > any command I ran that handled anything to do with LVM would freeze and
> > be completely unable to be signaled to do anything.  

> In other words, no
> > error messages, nothing in dmesg, nothing in syslog...  The commands
> > would just freeze and not return.  That was with the 2.6.31.14 kernel
> > that is what's currently retrieved if you checkout xen-4.0-testing.hg
> > and just do a make dist.

Can you try find the minimum number of steps necessary to get into that
state and try sth like $ ps -eH -owchan,nwchan,cmd

Also, is that sequence completely reproducible or does the behaviour
change evertime? Just trying if there's some point where deadlock ends
and corruption like the one quoted below would start.

Daniel

> > I have since checked out and compiled 2.6.32.18 that comes from doing
> > git checkout -b xen/stable-2.6.32.x origin/xen/stable-2.6.32.x, as
> > described on the Wiki page here:
> > http://wiki.xensource.com/xenwiki/XenParavirtOps
> >
> > If I run that kernel for dom0, but continue to use 2.6.31.14 for the
> > paravirtualized domUs, everything works fine until I try to manipulate
> > the snapshots of the HVM volumes.  Today, I got this kernel OOPS:
> 
> That's definitely bad.  Something is causing udevd to end up with bad
> pagetables which are causing a kernel crash on exit.  I'm not sure if
> its *the* udevd or some transient child, but either way its bad.
> 
> Any thoughts on this Daniel?
> 
> >
> > ---------------------------
> >
> > [78084.004530] BUG: unable to handle kernel paging request at
> > ffff8800267c9010
> > [78084.004710] IP: [<ffffffff810382ff>] xen_set_pmd+0x24/0x44
> > [78084.004886] PGD 1002067 PUD 1006067 PMD 217067 PTE 80100000267c9065
> > [78084.005065] Oops: 0003 [#1] SMP
> > [78084.005234] last sysfs file:
> > /sys/devices/virtual/block/dm-32/removable
> > [78084.005256] CPU 1
> > [78084.005256] Modules linked in: tun xt_multiport fuse dm_snapshot
> > 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]
> > [78084.005256] Pid: 22814, comm: udevd Tainted: G        W  2.6.32.18 #1
> > H8SMI
> > [78084.005256] RIP: e030:[<ffffffff810382ff>]  [<ffffffff810382ff>]
> > xen_set_pmd+0x24/0x44
> > [78084.005256] RSP: e02b:ffff88002e2e1d18  EFLAGS: 00010246
> > [78084.005256] RAX: 0000000000000000 RBX: ffff8800267c9010 RCX:
> > ffff880000000000
> > [78084.005256] RDX: dead000000100100 RSI: 0000000000000000 RDI:
> > 0000000000000004
> > [78084.005256] RBP: ffff88002e2e1d28 R08: 0000000001993000 R09:
> > dead000000100100
> > [78084.005256] R10: 800000016e90e165 R11: 0000000000000000 R12:
> > 0000000000000000
> > [78084.005256] R13: ffff880002d8f580 R14: 0000000000400000 R15:
> > ffff880029248000
> > [78084.005256] FS:  00007fa07d87f7a0(0000) GS:ffff880002d81000(0000)
> > knlGS:0000000000000000
> > [78084.005256] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
> > [78084.005256] CR2: ffff8800267c9010 CR3: 0000000001001000 CR4:
> > 0000000000000660
> > [78084.005256] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
> > 0000000000000000
> > [78084.005256] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
> > 0000000000000400
> > [78084.005256] Process udevd (pid: 22814, threadinfo ffff88002e2e0000,
> > task ffff880019491e80)
> > [78084.005256] Stack:
> > [78084.005256]  0000000000600000 000000000061e000 ffff88002e2e1de8
> > ffffffff810fb8a5
> > [78084.005256] <0> 00007fff13ffffff 0000000100000206 ffff880003158003
> > 0000000000000000
> > [78084.005256] <0> 0000000000000000 000000000061dfff 000000000061dfff
> > 000000000061dfff
> > [78084.005256] Call Trace:
> > [78084.005256]  [<ffffffff810fb8a5>] free_pgd_range+0x27c/0x45e
> > [78084.005256]  [<ffffffff810fbb2b>] free_pgtables+0xa4/0xc7
> > [78084.005256]  [<ffffffff810ff1fd>] exit_mmap+0x107/0x13f
> > [78084.005256]  [<ffffffff8107714b>] mmput+0x39/0xda
> > [78084.005256]  [<ffffffff8107adff>] exit_mm+0xfb/0x106
> > [78084.005256]  [<ffffffff8107c86d>] do_exit+0x1e8/0x6ff
> > [78084.005256]  [<ffffffff815c228b>] ? do_page_fault+0x2cd/0x2fd
> > [78084.005256]  [<ffffffff8107ce0d>] do_group_exit+0x89/0xb3
> > [78084.005256]  [<ffffffff8107ce49>] sys_exit_group+0x12/0x16
> > [78084.005256]  [<ffffffff8103cc82>] system_call_fastpath+0x16/0x1b
> > [78084.005256] Code: 48 83 c4 28 5b c9 c3 55 48 89 e5 41 54 49 89 f4 53
> > 48 89 fb e8 fc ee ff ff 48 89 df ff 05 52 8f 9e 00 e8 78 e4 ff ff 84 c0
> > 75 05 <4c> 89 23 eb 16 e8 e0 ee ff ff 4c 89 e6 48 89 df ff 05 37 8f 9e
> > [78084.005256] RIP  [<ffffffff810382ff>] xen_set_pmd+0x24/0x44
> > [78084.005256]  RSP <ffff88002e2e1d18>
> > [78084.005256] CR2: ffff8800267c9010
> > [78084.005256] ---[ end trace 4eaa2a86a8e2da24 ]---
> > [78084.005256] Fixing recursive fault but reboot is needed!
> >

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Scott Garron]

On 08/30/2010 03:13 PM, Daniel Stodden wrote:
> Are you sure it's spinning or just freezing?

      I'm not sure that I understand the difference between those two
terms, so I'm going to guess "freezing" is probably a more accurate
description.  The best way to describe what I was seeing was that my
scripted backup procedure would get to a certain point and freeze, then
I wouldn't be able to break out of it or issue a kill from another SSH
session on its PID.  The kill command freezes the same way (never
returns to a shell prompt and pressing CTRL-C just shows ^C on the
display without breaking out).

> Can you try find the minimum number of steps necessary to get into
> that state and try sth like $ ps -eH -owchan,nwchan,cmd

      The minimum number of steps that I took, just now, to make it
happen was as follows:

      There's an HVM domU that's active and running Windows 2008 Server,
called "scrappy", with the following Xen configuration:

kernel = "hvmloader"
builder='hvm'
memory = 768
name = "scrappy"
vcpus=1
vif = [ 'type=ioemu, mac=00:16:3e:00:00:18, bridge=eth0','type=ioemu,
mac=00:16:3e:00:00:19, bridge=xenbr1','type=ioemu,
mac=00:16:3e:00:00:1A, bridge=xenbr2' ]
disk = [ 'phy:hurricanevg1/scrappy-primarymaster,xvda,w',
'file:/mnt/scratch/WindowsServerStd2008OEM_x86-64.iso,xvdb:cdrom,r',
'phy:hurricanevg1/scrappy-secondarymaster,xvdc,w' ]
on_reboot   = 'restart'
device_model = 'qemu-dm'
sdl=0
opengl=1
vnc=1
vnclisten="192.168.0.90"
vncdisplay=3
vncunused=1
stdvga=0
serial='pty'
tsc_mode=0
localtime=1
rtc_timeoffset=-3600


      While that's running, I created a snapshot of the primarymaster
volume, then removed it, created one for the secondarymaster, removed
it, and created another one for the primarymaster, tried to remove it,
and the lvremove command froze.  A minute or two later, I got a similar
kernel OOPS message on my console to the one that I posted before.
These are the commands that I used to create and remove the volumes:

lvcreate -L 2G -n scrappy-primarymaster-backupsnap -s
hurricanevg1/scrappy-primarymaster

lvremove hurricanevg1/scrappy-primarymaster-backupsnap

lvcreate -L 2G -n scrappy-secondarymaster-backupsnap -s
hurricanevg1/scrappy-secondarymaster

lvremove hurricanevg1/scrappy-secondarymaster-backupsnap

lvcreate -L 2G -n scrappy-primarymaster-backupsnap -s
hurricanevg1/scrappy-primarymaster

lvremove hurricanevg1/scrappy-primarymaster-backupsnap


      This time, the console froze completely and I couldn't open any new
SSH sessions into the machine, and couldn't run the ps -eH command that
you asked for in your previous message.  If I go for another attempt,
I'll try to have a few logins already going so I can try to get that
output for you.  This is a somewhat critical, production server, though,
so I didn't want to keep bouncing it in the middle of the day.

> Also, is that sequence completely reproducible or does the behaviour
>  change evertime? Just trying if there's some point where deadlock
> ends and corruption like the one quoted below would start.

      It seems to be 3 for 3 at this point.

-- 
Scott Garron

RE: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Xu, Dongxiao]

Jeremy Fitzhardinge wrote:
>  On 08/27/2010 06:22 PM, Scott Garron wrote:
>> I use LVM volumes for domU disks.  To create backups, I create a
>> snapshot of the volume, mount the snapshot in the dom0, mount an
>> equally-sized backup volume from another physical storage source, run
>> an rsync from one to the other, unmount both, then remove the
>> snapshot. 
>> This includes creating a snapshot and mounting NTFS volumes from
>> Windows-based HVM guests.
>> 
>> This practice may not be perfect, but has worked fine for me for a
>> couple of years - while I was running Xen 3.2.1 and
>> linux-2.6.18.8-xen 
>> dom0 (and the same kernel for domU).  After upgrades of udev started
>> complaining about the kernel being too old, I thought it was well
>> past 
>> time to try to transition to a newer version of Xen and a newer dom0
>> kernel.  This transition has been a gigantic learning experience, let
>> me tell you.
>> 
>> After that transition, here's the problem I've been wrestling with
>> and 
>> can't seem to find a solution for:  It seems like any time I start
>> manipulating a volume group to add or remove a snapshot of a logical
>> volume that's used as a disk for a running HVM guest, new calls to
>> LVM2 and/or Xen's storage locks up and spins forever.  The first time
>> I ran across the problem, there was no indication of a problem other
>> than any command I ran that handled anything to do with LVM would
>> freeze and be completely unable to be signaled to do anything.  In
>> other words, no error messages, nothing in dmesg, nothing in
>> syslog... 
>> The commands would just freeze and not return.  That was with the
>> 2.6.31.14 kernel that is what's currently retrieved if you checkout
>> xen-4.0-testing.hg and just do a make dist.
>> 
>> I have since checked out and compiled 2.6.32.18 that comes from doing
>> git checkout -b xen/stable-2.6.32.x origin/xen/stable-2.6.32.x, as
>> described on the Wiki page here:
>> http://wiki.xensource.com/xenwiki/XenParavirtOps
>> 
>> If I run that kernel for dom0, but continue to use 2.6.31.14 for the
>> paravirtualized domUs, everything works fine until I try to
>> manipulate 
>> the snapshots of the HVM volumes.  Today, I got this kernel OOPS:
> 
> That's definitely bad.  Something is causing udevd to end up with bad
> pagetables which are causing a kernel crash on exit.  I'm not sure if
> its *the* udevd or some transient child, but either way its bad.  
> 
> Any thoughts on this Daniel?
> 
>> 
>> ---------------------------
>> 
>> [78084.004530] BUG: unable to handle kernel paging request at
>> ffff8800267c9010 [78084.004710] IP: [<ffffffff810382ff>]
>> xen_set_pmd+0x24/0x44 [78084.004886] PGD 1002067 PUD 1006067 PMD
>> 217067 PTE 80100000267c9065 [78084.005065] Oops: 0003 [#1] SMP
>> [78084.005234] last sysfs file:
>> /sys/devices/virtual/block/dm-32/removable
>> [78084.005256] CPU 1
>> [78084.005256] Modules linked in: tun xt_multiport fuse dm_snapshot
>> 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]
>> [78084.005256] Pid: 22814, comm: udevd Tainted: G        W 
>> 2.6.32.18 #1 
>> H8SMI
>> [78084.005256] RIP: e030:[<ffffffff810382ff>]  [<ffffffff810382ff>]
>> xen_set_pmd+0x24/0x44 [78084.005256] RSP: e02b:ffff88002e2e1d18 
>> EFLAGS: 00010246 [78084.005256] RAX: 0000000000000000 RBX:
>> ffff8800267c9010 RCX: 
>> ffff880000000000
>> [78084.005256] RDX: dead000000100100 RSI: 0000000000000000 RDI:
>> 0000000000000004 [78084.005256] RBP: ffff88002e2e1d28 R08:
>> 0000000001993000 R09: 
>> dead000000100100
>> [78084.005256] R10: 800000016e90e165 R11: 0000000000000000 R12:
>> 0000000000000000 [78084.005256] R13: ffff880002d8f580 R14:
>> 0000000000400000 R15: 
>> ffff880029248000
>> [78084.005256] FS:  00007fa07d87f7a0(0000) GS:ffff880002d81000(0000)
>> knlGS:0000000000000000 [78084.005256] CS:  e033 DS: 0000 ES: 0000
>> CR0: 000000008005003b [78084.005256] CR2: ffff8800267c9010 CR3:
>> 0000000001001000 CR4: 0000000000000660
>> [78084.005256] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
>> 0000000000000000 [78084.005256] DR3: 0000000000000000 DR6:
>> 00000000ffff0ff0 DR7: 0000000000000400 [78084.005256] Process udevd
>> (pid: 22814, threadinfo ffff88002e2e0000, 
>> task ffff880019491e80) [78084.005256] Stack:
>> [78084.005256]  0000000000600000 000000000061e000 ffff88002e2e1de8
>> ffffffff810fb8a5
>> [78084.005256] <0> 00007fff13ffffff 0000000100000206 ffff880003158003
>> 0000000000000000 [78084.005256] <0> 0000000000000000 000000000061dfff
>> 000000000061dfff 000000000061dfff [78084.005256] Call Trace:
>> [78084.005256]  [<ffffffff810fb8a5>] free_pgd_range+0x27c/0x45e
>> [78084.005256]  [<ffffffff810fbb2b>] free_pgtables+0xa4/0xc7
>> [78084.005256]  [<ffffffff810ff1fd>] exit_mmap+0x107/0x13f
>> [78084.005256]  [<ffffffff8107714b>] mmput+0x39/0xda [78084.005256]
>> [<ffffffff8107adff>] exit_mm+0xfb/0x106 [78084.005256]
>> [<ffffffff8107c86d>] do_exit+0x1e8/0x6ff [78084.005256]
>> [<ffffffff815c228b>] ? do_page_fault+0x2cd/0x2fd [78084.005256]
>> [<ffffffff8107ce0d>] do_group_exit+0x89/0xb3 [78084.005256]
>> [<ffffffff8107ce49>] sys_exit_group+0x12/0x16 [78084.005256]
>> [<ffffffff8103cc82>] system_call_fastpath+0x16/0x1b [78084.005256]
>> Code: 48 83 c4 28 5b c9 c3 55 48 89 e5 41 54 49 89 f4 53
>> 48 89 fb e8 fc ee ff ff 48 89 df ff 05 52 8f 9e 00 e8 78 e4 ff ff 84
>> c0
>> 75 05 <4c> 89 23 eb 16 e8 e0 ee ff ff 4c 89 e6 48 89 df ff 05 37 8f
>> 9e [78084.005256] RIP  [<ffffffff810382ff>] xen_set_pmd+0x24/0x44
>> [78084.005256]  RSP <ffff88002e2e1d18> [78084.005256] CR2:
>> ffff8800267c9010 [78084.005256] ---[ end trace 4eaa2a86a8e2da24 ]---
>> [78084.005256] Fixing recursive fault but reboot is needed!
>> 
>> ---------------------------
>> 
>> After that was printed on the console, use of anything that interacts
>> with Xen (xentop, xm) would freeze whatever command it was and not
>> return.  After trying to do a sane shutdown on the guests, the whole
>> dom0 locked completely.  Even the alt-sysrq things stopped working
>> after looking at a couple of them.
>> 
>> I feel it's probably necessary to mention that this is after several,
>> fairly rapid-fire creations and deletions of snapshot volumes.  I
>> have 
>> it scripted to make a snapshot, mount it, mount a backup volume,
>> rsync 
>> it, unmount both volumes, and delete the snapshot for 19 volumes in a
>> row.  In other words, there's a lot of disk I/O going on around the
>> time of the lockup.  It always seems to coincide with when it gets to
>> the volumes that are being used for active, running, Windows Server
>> 2008, HVM volumes.  That may be just coincidental, though, because
>> those are the last ones on the list.  15 volumes used in active,
>> running paravirtualized Linux guests are at the top of the list.
>> 
>> 
>> Another issue that comes up is that if I run the 2.6.32.18 pvops
>> kernel for my Linux domUs, after a time (usually only about an hour
>> or 
>> so), the network interfaces stop responding.  I don't know if the
>> problem is related, but it was something else that I noticed.  The
>> only way to get the network access to come back is to reboot the
>> domU. 
>> When I reverted the domU kernel to 2.6.31.14, this problem goes away.
> 
> That's a separate problem in netfront that appears to be a bug in the
> "smartpoll" code.  I think Dongxiao is looking into it. 

Yes, I tried to reproduce these days, however I could catch it locally. I tried both netperf and ping for a long time, but the bug is not triggered. What workload are you using when met the bug?

Thanks,
Dongxiao

> 
>> I'm not 100%
>> sure, but I think this issue also causes xm console to not allow you
>> to type on the console that you connect to.  If I connect to a
>> console, then issue an xm shutdown on the same domU from another
>> terminal, all of the console messages that show the play-by-play of
>> the shutdown process display, but my keyboard input doesn't seem to
>> make it through. 
> 
> Hm, not familiar with this problem.  Perhaps its just something wrong
> with your console settings for the domain?  Do you have "console=" on
> the kernel command line?  
> 
>> Since I'm not a developer, I don't know if these questions are better
>> suited for the xen-users list, but since it generated an OOPS with
>> the 
>> word "BUG" in capital letters, I thought I'd post it here.  If that
>> assumption was incorrect, just give me a gentle nudge and I'll
>> redirect the inquiry to somewhere more appropriate.  :)
> 
> Nope, they're both xen-devel fodder.  Thanks for posting.
> 
>     J

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Scott Garron]

>> Scott Garron wrote:
>>> Another issue that comes up is that if I run the 2.6.32.18 pvops
>>> kernel for my Linux domUs, after a time (usually only about an
>>> hour or so), the network interfaces stop responding.

> Jeremy Fitzhardinge wrote:
>> That's a separate problem in netfront that appears to be a bug in
>> the "smartpoll" code.  I think Dongxiao is looking into it.

On 8/31/2010 2:59 AM, Xu, Dongxiao wrote:
> Yes, I tried to reproduce these days, however I could catch it
> locally. I tried both netperf and ping for a long time, but the bug
> is not triggered. What workload are you using when met the bug?

      I'd say that the whole machine is under moderate to high
utilization because it has 10 virtual machines running - three of which
are Windows 2008 Servers as HVM guests.  However, as far as the "load"
goes, most of the virtual machines are fairly idle and probably not
under much stress, overall.  Just to give you an idea, we have a
10Mbit/s connection to the Internet, and this server's physical network
interface (all 10 of the domUs' traffic, combined) usually accounts for
less than 2Mbit/s of the outbound traffic at any given point in the day.
  Aside from Windows being Windows (the HVM guests are running graphical
desktops), I wouldn't say that any of them cause a high CPU load,
either.  Database load is fairly low to moderate on guests running MySQL
and/or PostgreSQL.  The only guest that seems to use more CPU and
RAM is one serving e-mail, and that's because it runs ClamAV and
SpamAssassin.  That e-mail server was one that kept its network
connectivity the longest, though (after a few hours, it did stop
responding, but that was after some guests with lighter loads stopped
responding).

      An observation that I made, and it may just be coincidental,
but at least noteworthy, is that the virtual machines that are assigned
less RAM seem to lose connectivity more quickly than those with more
RAM.  The most recent time that I was able to trigger the bug, the
virtual machine that lost connectivity was only assigned 384MB RAM,
running 2.6.32.18.  At the time, the rest of my paravirtualized guests
were running 2.6.31.14, and they didn't experience the problem.

      I've previously triggered the bug in multiple domUs that were
running a more recent kernel (I think it was 2.6.32.17 - before I
reverted to a netback-patched 2.6.31.14 kernel), and the first ones to
disappear from the network were ones that were only assigned 256MB.
Eventually, they all disappeared, though.  The only "load" on one of the
first to disappear is an installation of bind9, servicing about 50
domain names - none of which receive an abnormally high hit count.

      The first time I noticed the problem, I had started 7
paravirtualized guests, of varying memory assignments.  The moment I
started the 8th guest, an HVM Windows 2008 Server, the networking on all
of the running of the guests (the paravirt ones) stopped responding at
the same time.  That may also be something to try/look at.

      After a reboot, I avoided starting any of the HVM guests, and the
connectivity lasted a couple of hours on the 7 running paravirt guests,
but started disappearing one guest at a time, over the course of the
next few hours.

      I didn't mention in my previous e-mail that in order to get
networking to work in a stable fashion in the 2.6.31.14 kernel (the one
I reverted to), I had to apply the patch mentioned here:
http://lists.xensource.com/archives/html/xen-devel/2010-05/msg01570.html
Otherwise, networking became unstable immediately at the time of guest
creation.  That patch was already applied to the 2.6.32.18 kernel that
is giving me the eventual network loss problems, though.

      More specifics about my configuration can be found here:
http://www.pridelands.org/~simba/hurricane-server.txt

-- 
Scott Garron

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Daniel Stodden]

On Mon, 2010-08-30 at 16:30 -0400, Scott Garron wrote:
> On 08/30/2010 03:13 PM, Daniel Stodden wrote:
> > Are you sure it's spinning or just freezing?
> 
>       I'm not sure that I understand the difference between those two
> terms, so I'm going to guess "freezing" is probably a more accurate
> description.  The best way to describe what I was seeing was that my
> scripted backup procedure would get to a certain point and freeze, then
> I wouldn't be able to break out of it or issue a kill from another SSH
> session on its PID.  The kill command freezes the same way (never
> returns to a shell prompt and pressing CTRL-C just shows ^C on the
> display without breaking out).

If it were just some or more tasks hanging initially, and it's caught
some wait state, then identifying the point where things broke can
sometimes be quite straightforward. Doesn't seem to be the case here.

> > Can you try find the minimum number of steps necessary to get into
> > that state and try sth like $ ps -eH -owchan,nwchan,cmd
> 
>       The minimum number of steps that I took, just now, to make it
> happen was as follows:
> 
>       There's an HVM domU that's active and running Windows 2008 Server,
> called "scrappy", with the following Xen configuration:
> 
> kernel = "hvmloader"
> builder='hvm'
> memory = 768
> name = "scrappy"
> vcpus=1
> vif = [ 'type=ioemu, mac=00:16:3e:00:00:18, bridge=eth0','type=ioemu,
> mac=00:16:3e:00:00:19, bridge=xenbr1','type=ioemu,
> mac=00:16:3e:00:00:1A, bridge=xenbr2' ]
> disk = [ 'phy:hurricanevg1/scrappy-primarymaster,xvda,w',
> 'file:/mnt/scratch/WindowsServerStd2008OEM_x86-64.iso,xvdb:cdrom,r',
> 'phy:hurricanevg1/scrappy-secondarymaster,xvdc,w' ]
> on_reboot   = 'restart'
> device_model = 'qemu-dm'
> sdl=0
> opengl=1
> vnc=1
> vnclisten="192.168.0.90"
> vncdisplay=3
> vncunused=1
> stdvga=0
> serial='pty'
> tsc_mode=0
> localtime=1
> rtc_timeoffset=-3600
> 
> 
>       While that's running, I created a snapshot of the primarymaster
> volume, then removed it, created one for the secondarymaster, removed
> it, and created another one for the primarymaster, tried to remove it,
> and the lvremove command froze.  A minute or two later, I got a similar
> kernel OOPS message on my console to the one that I posted before.
> These are the commands that I used to create and remove the volumes:
> 
> lvcreate -L 2G -n scrappy-primarymaster-backupsnap -s
> hurricanevg1/scrappy-primarymaster
> 
> lvremove hurricanevg1/scrappy-primarymaster-backupsnap
> 
> lvcreate -L 2G -n scrappy-secondarymaster-backupsnap -s
> hurricanevg1/scrappy-secondarymaster
> 
> lvremove hurricanevg1/scrappy-secondarymaster-backupsnap
> 
> lvcreate -L 2G -n scrappy-primarymaster-backupsnap -s
> hurricanevg1/scrappy-primarymaster
> 
> lvremove hurricanevg1/scrappy-primarymaster-backupsnap
> 
> 
>       This time, the console froze completely and I couldn't open any new
> SSH sessions into the machine, and couldn't run the ps -eH command that
> you asked for in your previous message.  If I go for another attempt,
> I'll try to have a few logins already going so I can try to get that
> output for you.  This is a somewhat critical, production server, though,
> so I didn't want to keep bouncing it in the middle of the day.
> 
> > Also, is that sequence completely reproducible or does the behaviour
> >  change evertime? Just trying if there's some point where deadlock
> > ends and corruption like the one quoted below would start.
> 
>       It seems to be 3 for 3 at this point.

Okay. I guess that won't be simple to repro. I wonder what you are
running in dom0. Distro and version, what you upgraded and what not, any
customized software builds etc.

Given the rate at which you reproduce this and because only the
snapshots seem to trigger the problem, to me this looks more like an
LVM/DM issue than pvops specific.

Also, it might be worth trying to turn off udev and see whether that
changes sth.

Daniel

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Scott Garron]

On 08/31/2010 05:20 AM, Daniel Stodden wrote:
> If it were just some or more tasks hanging initially, and it's caught
> some wait state, then identifying the point where things broke can
> sometimes be quite straightforward. Doesn't seem to be the case
> here.

      True.  It's at least narrowed down to something with the way LVM/DM
and udev interact during creation and removal of snapshots since the
machine can run for days without incident until I start adding and
removing snapshots (of running HVM volumes).

> Okay. I guess that won't be simple to repro. I wonder what you are
> running in dom0. Distro and version, what you upgraded and what not,
> any customized software builds etc.

      I'm running Debian Squeeze (testing) and have included a full list
of installed packages (dpkg -l) in the text file referenced in some of
my previous e-mails, here:
http://www.pridelands.org/~simba/hurricane-server.txt

      I've also included the output of "ps -eH -owchan,nwchan,cmd" during
normal operations (not yet in the "crashed" state).

      I don't recall running any customized software builds on dom0.
It's a fairly bog standard Debian installation.  If I'm going to do
anything customized, I usually do it on a domU.

> Given the rate at which you reproduce this and because only the
> snapshots seem to trigger the problem, to me this looks more like an
> LVM/DM issue than pvops specific.

      That has crossed my mind.  The only reason that I suspected
anything to do with Xen or pvops was that it only seems to happen when
creating/removing a snapshot of an active, running HVM.  I can create
and remove snapshots of other volumes all day and not trigger the bug
(tested yesterday).  It would probably be impossible to trigger the bug
on a baremetal machine that's not running a hypervisor.

> Also, it might be worth trying to turn off udev and see whether that
> changes sth.

      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.

-- 
Scott Garron

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Scott Garron]

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

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Jeremy Fitzhardinge]

 On 09/03/2010 01:02 AM, Scott Garron wrote:
> 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.

What kernel is this?  This sounds like a symptom of the sched_clock
problem I fixed a few weeks ago.

>      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.

The RAM difference could be a significant factor.  If you have less than
4G then all pages are guaranteed to be directly accessible with 32-bit
pointers and 32-bit devices, whereas with more than 4G you need to deal
with the case where the kernel thinks a page is below 4G (=DMA
accessible by 32-bit device) but it is actually physically resident above.

I don't know if that's a specific factor in this case, but the error you
got suggested something very strange going on with unusual memory mappings.

>      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.

What happens if you boot that system with "mem=4G" on the Xen command line?

[...]

>
>      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!

So it has just allocated a new page to include in a pagetable, but it is
failing to pin it.  That suggests that there's another mapping of that
page somewhere which is preventing the pin.

This means that something is leaving stray mappings of pages around
somewhere.  We already deal with the standard mechanisms for doing this,
but perhaps LVM is keeping a private cache of mappings off to one side. 
But I'm surprised we haven't seen anything like this before, given the
widespread use of LVM.

> [ 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

Are they atypical?

>
> (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()

That's not a big concern. It's the AMD perf counter driver trying to
access the registers which Xen doesn't allow it to access.

>      Any ideas, or does this look more like a bug with LVM/DM?

Possibly some unexpected Xen/LVM interaction rather than an outright bug.

>
> ( 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?

I think udev is the victim here, not the culprit.

>
>      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

Aside from udev being involved, they symptom looks quite different.

    J

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Scott Garron]

Scott Garron wrote:
>> dom0 console and HVM domUs would periodically hang for several
>> seconds and then return as if nothing was wrong.  [.snip.] I ended
>>  up fixing it by unsetting CONFIG_NO_HZ in the kernel

Jeremy Fitzhardinge wrote:
> What kernel is this?  This sounds like a symptom of the sched_clock
> problem I fixed a few weeks ago.

2.6.32.18
ref: refs/heads/xen/stable-2.6.32.x

git log shows this as the most recent commit (from Aug 30):
commit 2968b258b1ca6bd16d758dd68900669419caff2b

>> It could just be slightly different architecture or the fact that
>> the machine has overall less RAM (4G instead of 8G).
>
> What happens if you boot that system with "mem=4G"

I managed to finally be able to try this last night, and it didn't seem
to make any difference.  It did seem to last a bit longer (I had it
creating and removing snapshots every 6 seconds while the backup process
was also creating and removing them as needed, and it went along for
about 20 minutes before becoming unstable).  The OOPS message was
different than last time, but similar to the first one I sent when
reporting this.

After it crashed, I also went ahead and flashed the BIOS to the latest
version, to see if it made any difference.  After flashing, I booted
normally (without mem=4G), and got it to crash again - this time with a
similar OOPS message to the one I sent to you in my previous e-mail.
The new BIOS didn't help, obviously.  I've appended the ps -eH
-owchan,nwchan,cmd outputs and kernel OOPS messages from last night to
the end of the text file at:

http://www.pridelands.org/~simba/hurricane-server.txt

>> udevd: worker did not accept message -1 (Connection refused) kill
>
> Are they atypical?

I don't recall seeing them before, but after flashing the BIOS, they are
no longer occurring.

>> This post seems to be eerily similar to the problem I'm
>> experiencing.  http:[...]xen-devel/2010-09/msg00169.html
>
> Aside from udev being involved, the symptom looks quite different.

I suppose that's true, but he mentions in this post:

http://lists.xensource.com/archives/html/xen-devel/2010-09/msg00286.html

that lvcreate and udev are hanging while creating a snapshot volume.
That's the reason I thought it was similar.  (That, and he seems to do
backups in a similar way that I do:  creates a snapshot, makes a copy of
the snapshot [although, he block-attaches the volume to a domU to do it
whereas I just use dom0], then removes the snapshot.)

-- 
Scott Garron

RE: Making snapshot of logical volumes handling HVM domUcauses OOPS and instability

[James Harper]

> >> This post seems to be eerily similar to the problem I'm
> >> experiencing.  http:[...]xen-devel/2010-09/msg00169.html
> >
> > Aside from udev being involved, the symptom looks quite different.
> 
> I suppose that's true, but he mentions in this post:
> 
>
http://lists.xensource.com/archives/html/xen-devel/2010-09/msg00286.html
> 
> that lvcreate and udev are hanging while creating a snapshot volume.
> That's the reason I thought it was similar.  (That, and he seems to do
> backups in a similar way that I do:  creates a snapshot, makes a copy
of
> the snapshot [although, he block-attaches the volume to a domU to do
it
> whereas I just use dom0], then removes the snapshot.)
> 

That was me. While it doesn't rule out that the block-attach is causing
the problem, the hang is happening in the lvcreate in my script. My
other theory is that the block-detach is hanging something which means
the subsequent lvcreate can't progress so I see the hang there.

Unfortunately I don't have a machine I can burn to play with this so I
can't test it much, and it breaks the entire Dom0 so it's a bit of a big
deal.

James

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[J. Roeleveld]

Hi All,

Thought I'd chip in with some info from what I experienced/noticed on my 
system. (Not seen the instability described though).
I hope these help with isolating the OPs issue.

On Monday 30 August 2010 20:18:08 Scott Garron wrote:
> On 08/30/2010 12:52 PM, Jeremy Fitzhardinge wrote:

<snipped udev>

> >> I think this issue [unresponsive network interfaces] also causes xm
> >> console to not allow you to type on the console
> > 
> > Hm, not familiar with this problem.  Perhaps its just something wrong
> > with your console settings for the domain?  Do you have "console=" on
> > the kernel command line?
> 
>       I have "extra = "console=hvc0"" in the domU configuration files.
> The keyboard input works just fine for some time.  It ceased accepting
> input at around the same time that the network interfaces stopped
> responding, but that could have just been coincidental.
> 
>       I wasn't paying full attention, so this may also have been related
> to me attaching to the console twice (Running xm console on one ssh
> session to the dom0 in addition to running xm console from another SSH
> session to the dom0).  When I couldn't connect directly to the domU via
> SSH on its network interface, I tried to attach to its console to do
> troubleshooting.  I may have already been attached to its console from
> another SSH session to the dom0 and I suppose that might cause a
> conflict.   ...  which begs the question:  "Is this the desired/expected
> behavior in this scenario?"

I noticed this behaviour already in older Xen-versions:
1) " xm console x "
2) (in a different shell-session) : " xm console x "

Observed situation: input and output for the xenconsole session is "weird" in 
that commands entered and results returning are not showing where I expect it.

I believe this is " expected " behaviour.

--
Joost

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[J. Roeleveld]

Hi All,

Same again here, thought I'd chip in with some info from what I 
experienced/noticed on my system. (Not seen the instability described though).
I hope these help with isolating the OPs issue.

On Friday 03 September 2010 10:06:45 Scott Garron wrote:
> On 8/31/2010 2:06 PM, Scott Garron wrote:

<snipped>

I also use LVMs extensively and do similar steps for backups.
1) umount in domU
2) block-detach
3) lvcreate snapshot
4) block-attach
5) mount in domU

I, however, have no need for HVM and only use PV guests.
(All Linux)

>       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.

I also, on occasion, get the same issue with the "unable to remove active 
logical volume" even though they have been umounted.
Sometimes I can then remove them later, sometimes I have to "force" the 
snapshot to fail by filling up the snapshot myself.
when that happens, I get similar messages about " /dev/dm-63: open failed: no 
such device or address "

Are you certain the snapshots are large enough to hold all possible changes 
that might occur on the LV during the existence of the snapshot?

Another thing I notice, which might be of help to people who understand this 
better then I do, in my backup-script, sometimes step "5" fails because the 
domU hasn't noticed the device is attached again when I try to mount it.
The domU-commands are run using SSH-connections.

--
Joost

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[Scott Garron]

On 9/12/2010 5:41 AM, J. Roeleveld wrote:
> I also use LVMs extensively and do similar steps for backups.
> 1) umount in domU
> 2) block-detach
> 3) lvcreate snapshot
> 4) block-attach
> 5) mount in domU

      I think the biggest difference, here, is that you unmount and
detach the source volumes before creating the snapshot whereas I just
leave them active and mounted in the guest.  I don't know if that will
end up being the difference between stability and instability on my
system, but it's an observation and probably worth experimentation.

> I, however, have no need for HVM and only use PV guests.

      It turns out that it doesn't seem isolated to HVM guests on my
system any longer.  That was just coincidental during the first few
crashes that I observed.

> Are you certain the snapshots are large enough to hold all possible
> changes that might occur on the LV during the existence of the
> snapshot?

      Certainly.  The most recent one to cause a crash has existed
through the crash and for 3 days now, and is only using 2.65% of its COW
space.  They usually don't get a chance to go above even 0.3% before the
rsync on them is finished and they are unmounted and removed by the
backup script.

> Another thing I notice, which might be of help to people who
> understand this better then I do, in my backup-script, sometimes step
> "5" fails because the domU hasn't noticed the device is attached
> again when I try to mount it. The domU-commands are run using
> SSH-connections.

      That probably just has to do with variations in how long it takes
the guest kernel to poll or be notified of device changes, and how long
it takes for its udev to create the device files and whatnot.
Introducing some sanity checks or just a longer delay in your backup
script would likely get around that problem.  (I could be wrong, though)

-- 
Scott Garron

RE: Making snapshot of logical volumes handling HVM domUcauses OOPS and instability

[James Harper]

> > Another thing I notice, which might be of help to people who
> > understand this better then I do, in my backup-script, sometimes
step
> > "5" fails because the domU hasn't noticed the device is attached
> > again when I try to mount it. The domU-commands are run using
> > SSH-connections.
> 
>       That probably just has to do with variations in how long it
takes
> the guest kernel to poll or be notified of device changes, and how
long
> it takes for its udev to create the device files and whatnot.
> Introducing some sanity checks or just a longer delay in your backup
> script would likely get around that problem.  (I could be wrong,
though)
> 

I found that too. I just put the mount in a loop, breaking out when then
device actually appears in the DomU. It's just a timing thing and I
don't think its relevant to the problem at hand.

James

Re: Making snapshot of logical volumes handling HVM domU causes OOPS and instability

[J. Roeleveld]

On Sunday 12 September 2010 20:48:09 Scott Garron wrote:
> On 9/12/2010 5:41 AM, J. Roeleveld wrote:
> > I also use LVMs extensively and do similar steps for backups.
> > 1) umount in domU
> > 2) block-detach
> > 3) lvcreate snapshot
> > 4) block-attach
> > 5) mount in domU
> 
>       I think the biggest difference, here, is that you unmount and
> detach the source volumes before creating the snapshot whereas I just
> leave them active and mounted in the guest.  I don't know if that will
> end up being the difference between stability and instability on my
> system, but it's an observation and probably worth experimentation.

I tend to umount first to ensure the filesystem is consistent and no writes are 
still left in the write-buffer on the guest.
Filesystem recoveries are fine, but why rely on them when it's not necessary? 
:)

> > I, however, have no need for HVM and only use PV guests.
> 
>       It turns out that it doesn't seem isolated to HVM guests on my
> system any longer.  That was just coincidental during the first few
> crashes that I observed.

Ok, I believe the issue might be related to the LVM-stack and the way Xen 
holds the devices locked when they are actually mounted and attached?

> > Are you certain the snapshots are large enough to hold all possible
> > changes that might occur on the LV during the existence of the
> > snapshot?
> 
>       Certainly.  The most recent one to cause a crash has existed
> through the crash and for 3 days now, and is only using 2.65% of its COW
> space.  They usually don't get a chance to go above even 0.3% before the
> rsync on them is finished and they are unmounted and removed by the
> backup script.

Ok, guess that's not the cause :)
Although, I get the "unable to remove active" error when there is 0% used, but 
also over 20% used, so there is no clear indication what is causing it (to me)

> > Another thing I notice, which might be of help to people who
> > understand this better then I do, in my backup-script, sometimes step
> > "5" fails because the domU hasn't noticed the device is attached
> > again when I try to mount it. The domU-commands are run using
> > SSH-connections.
> 
>       That probably just has to do with variations in how long it takes
> the guest kernel to poll or be notified of device changes, and how long
> it takes for its udev to create the device files and whatnot.
> Introducing some sanity checks or just a longer delay in your backup
> script would likely get around that problem.  (I could be wrong, though)

I do need to add some sanity checks into the script at some point, but 
currently I start these manually and 'fix' the left-overs myself.
The mount-issue is a simple one and I notice this within 30-40 seconds of the 
scripts starting.

--
Joost

Re: Making snapshot of logical volumes handling HVM domUcauses OOPS and instability

[J. Roeleveld]

On Monday 13 September 2010 02:15:28 James Harper wrote:
> > > Another thing I notice, which might be of help to people who
> > > understand this better then I do, in my backup-script, sometimes
> 
> step
> 
> > > "5" fails because the domU hasn't noticed the device is attached
> > > again when I try to mount it. The domU-commands are run using
> > > SSH-connections.
> > > 
> >       That probably just has to do with variations in how long it
> 
> takes
> 
> > the guest kernel to poll or be notified of device changes, and how
> 
> long
> 
> > it takes for its udev to create the device files and whatnot.
> > Introducing some sanity checks or just a longer delay in your backup
> > script would likely get around that problem.  (I could be wrong,
> 
> though)
> 
> 
> I found that too. I just put the mount in a loop, breaking out when then
> device actually appears in the DomU. It's just a timing thing and I
> don't think its relevant to the problem at hand.
> 
> James

I agree, but I thought I'd mention it here just in case it could have been 
relevant.
I am not familiar enough with all the internals to be able to determine what 
we can and can not exclude.
A comparison with a system that doesn't crash is always usefull, in my 
experience :)

--
Joost