vgchange (lvm) fails with large snapshots on low memory machines
I am running 2.6.32-5-orion5x on a dns-323 (800MHz processor, 64MB
RAM).
When I have large snapshots (e.g., 75GB), I cannot activate the
snapshots or the corresponding original lvm partition. In fact,
running the command "vgchange -ay" (or the equivalent lvchange
version) either hangs the machine or returns the line "killed" after a
few minutes.
Looking in the syslog, I get many error messages about memory
allocation failures, including:
vgchange: page allocation failure. order:0, mode:0x10
Nothing else is running on the machine and I have 500MB of swap
(almost all free). I also have a reasonable (for this low memory
machine) of unused RAM:
#free
total used free shared buffers cached
Mem: 61056 51688 9368 0 340 7156
-/+ buffers/cache: 44192 16864
Swap: 530104 6636 523468
Everything works if I switch the drive to a plugcomputer with 512MB
RAM though vgchange takes a couple of minutes to load (I believe that
is because snapshots are slow).
Also, it worked when I removed the older of the two 75GB snapshots.
And I think it didn't become a problem until the snapshot got "old"
(i.e., started to differ a lot from the original).
So what is going on with vgchange that it cannot allocate enough
kernel memory? Shouldn't the free RAM plus the swap be enough?
Or is there something special about vgchange that requires actual RAM?
I am attaching the verbose output of 'vgchange' and the corresponding
syslog output below.
-----------------------------------------------------------------------
vgchange -ay -vvvvv:
#lvmcmdline.c:914 Processing: vgchange -ay -vvvvv
#lvmcmdline.c:917 O_DIRECT will be used
#config/config.c:950 Setting global/locking_type to 1
#locking/locking.c:223 File-based locking selected.
#config/config.c:927 Setting global/locking_dir to /var/lock/lvm
#toollib.c:578 Finding all volume groups
#device/dev-io.c:439 Opened /dev/md0 RO O_DIRECT
#device/dev-io.c:134 /dev/md0: block size is 4096 bytes
#label/label.c:184 /dev/md0: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/md0
#device/dev-io.c:439 Opened /dev/dm-0 RO O_DIRECT
#device/dev-io.c:134 /dev/dm-0: block size is 4096 bytes
#label/label.c:184 /dev/dm-0: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/dm-0
#device/dev-io.c:439 Opened /dev/sda1 RO O_DIRECT
#device/dev-io.c:134 /dev/sda1: block size is 4096 bytes
#label/label.c:184 /dev/sda1: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/sda1
#device/dev-io.c:439 Opened /dev/dm-1 RO O_DIRECT
#device/dev-io.c:134 /dev/dm-1: block size is 4096 bytes
#label/label.c:184 /dev/dm-1: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/dm-1
#device/dev-io.c:439 Opened /dev/root RO O_DIRECT
#device/dev-io.c:134 /dev/root: block size is 4096 bytes
#label/label.c:184 /dev/root: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/root
#device/dev-io.c:439 Opened /dev/dm-2 RO O_DIRECT
#device/dev-io.c:134 /dev/dm-2: block size is 4096 bytes
#label/label.c:184 /dev/dm-2: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/dm-2
#device/dev-io.c:439 Opened /dev/md3 RO O_DIRECT
#device/dev-io.c:134 /dev/md3: block size is 4096 bytes
#label/label.c:160 /dev/md3: lvm2 label detected
#cache/lvmcache.c:965 lvmcache: /dev/md3: now in VG #orphans_lvm2 (#orphans_lvm2)
#format_text/format-text.c:1095 /dev/md3: Found metadata at 28160 size 2360 (in area at 4096 size 192512) for volume1 (Jn9uiZ-yQn1-SFSa-7UoU-67rb-5eYF-s2vtdd)
#cache/lvmcache.c:965 lvmcache: /dev/md3: now in VG volume1 with 1 mdas
#cache/lvmcache.c:752 lvmcache: /dev/md3: setting volume1 VGID to Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdd
#cache/lvmcache.c:1002 lvmcache: /dev/md3: VG volume1: Set creation host to raider.
#device/dev-io.c:485 Closed /dev/md3
#device/dev-io.c:439 Opened /dev/sda4 RO O_DIRECT
#device/dev-io.c:134 /dev/sda4: block size is 4096 bytes
#label/label.c:184 /dev/sda4: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/sda4
#device/dev-io.c:439 Opened /dev/md4 RO O_DIRECT
#device/dev-io.c:134 /dev/md4: block size is 4096 bytes
#label/label.c:160 /dev/md4: lvm2 label detected
#cache/lvmcache.c:965 lvmcache: /dev/md4: now in VG #orphans_lvm2 (#orphans_lvm2)
#format_text/format-text.c:1095 /dev/md4: Found metadata at 5632 size 883 (in area at 4096 size 192512) for volume2 (7cNqUI-uqut-jSmm-yzu2-E22I-n2yV-R6w0h2)
#cache/lvmcache.c:965 lvmcache: /dev/md4: now in VG volume2 with 1 mdas
#cache/lvmcache.c:752 lvmcache: /dev/md4: setting volume2 VGID to 7cNqUIuqutjSmmyzu2E22In2yVR6w0h2
#cache/lvmcache.c:1002 lvmcache: /dev/md4: VG volume2: Set creation host to raider.
#device/dev-io.c:485 Closed /dev/md4
#device/dev-io.c:439 Opened /dev/dm-4 RO O_DIRECT
#device/dev-io.c:134 /dev/dm-4: block size is 4096 bytes
#label/label.c:184 /dev/dm-4: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/dm-4
#device/dev-io.c:439 Opened /dev/sda5 RO O_DIRECT
#device/dev-io.c:134 /dev/sda5: block size is 512 bytes
#label/label.c:184 /dev/sda5: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/sda5
#device/dev-io.c:439 Opened /dev/sda6 RO O_DIRECT
#device/dev-io.c:134 /dev/sda6: block size is 1024 bytes
#label/label.c:184 /dev/sda6: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/sda6
#device/dev-io.c:439 Opened /dev/dm-6 RO O_DIRECT
#device/dev-io.c:134 /dev/dm-6: block size is 4096 bytes
#label/label.c:184 /dev/dm-6: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/dm-6
#device/dev-io.c:439 Opened /dev/sdb5 RO O_DIRECT
#device/dev-io.c:134 /dev/sdb5: block size is 1024 bytes
#label/label.c:184 /dev/sdb5: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/sdb5
#device/dev-io.c:439 Opened /dev/sdb6 RO O_DIRECT
#device/dev-io.c:134 /dev/sdb6: block size is 4096 bytes
#label/label.c:184 /dev/sdb6: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/sdb6
#device/dev-io.c:439 Opened /dev/sdb7 RO O_DIRECT
#device/dev-io.c:134 /dev/sdb7: block size is 4096 bytes
#label/label.c:184 /dev/sdb7: No label detected
#label/label.c:287 <backtrace>
#device/dev-io.c:485 Closed /dev/sdb7
#locking/file_locking.c:164 Locking /var/lock/lvm/V_volume2 RB
#toollib.c:491 Finding volume group "volume2"
#device/dev-io.c:439 Opened /dev/md4 RO O_DIRECT
#device/dev-io.c:134 /dev/md4: block size is 4096 bytes
#label/label.c:160 /dev/md4: lvm2 label detected
#cache/lvmcache.c:965 lvmcache: /dev/md4: now in VG #orphans_lvm2 (#orphans_lvm2) with 1 mdas
#format_text/format-text.c:1095 /dev/md4: Found metadata at 5632 size 883 (in area at 4096 size 192512) for volume2 (7cNqUI-uqut-jSmm-yzu2-E22I-n2yV-R6w0h2)
#cache/lvmcache.c:965 lvmcache: /dev/md4: now in VG volume2 with 1 mdas
#cache/lvmcache.c:752 lvmcache: /dev/md4: setting volume2 VGID to 7cNqUIuqutjSmmyzu2E22In2yVR6w0h2
#cache/lvmcache.c:1002 lvmcache: /dev/md4: VG volume2: Set creation host to raider.
#label/label.c:270 Using cached label for /dev/md4
#format_text/format-text.c:476 Read volume2 metadata (2) from /dev/md4 at 5632 size 883
#cache/lvmcache.c:90 Metadata cache: VG volume2 stored (883 bytes).
#metadata/pv_manip.c:272 /dev/md4 0: 0 596: root(0:0)
#format_text/format-text.c:787 Read volume group volume2 from /etc/lvm/backup/volume2
#activate/activate.c:447 Getting device info for volume2-root
#ioctl/libdm-iface.c:1606 dm version OF [16384]
#ioctl/libdm-iface.c:1606 dm info LVM-7cNqUIuqutjSmmyzu2E22In2yVR6w0h2clcIR26lJ2r8i716ojnjXu9j0ntgh9n7 NF [16384]
#vgchange.c:153 1 logical volume(s) in volume group "volume2" already active
#activate/activate.c:447 Getting device info for volume2-root
#ioctl/libdm-iface.c:1606 dm info LVM-7cNqUIuqutjSmmyzu2E22In2yVR6w0h2clcIR26lJ2r8i716ojnjXu9j0ntgh9n7 NF [16384]
#vgchange.c:159 1 existing logical volume(s) in volume group "volume2" monitored
#locking/file_locking.c:244 Locking LV 7cNqUIuqutjSmmyzu2E22In2yVR6w0h2clcIR26lJ2r8i716ojnjXu9j0ntgh9n7 (R)
#metadata/metadata.c:1858 Finding volume group for uuid 7cNqUIuqutjSmmyzu2E22In2yVR6w0h2clcIR26lJ2r8i716ojnjXu9j0ntgh9n7
#label/label.c:270 Using cached label for /dev/md4
#metadata/pv_manip.c:272 /dev/md4 0: 0 596: root(0:0)
#cache/lvmcache.c:513 Using cached metadata for VG volume2.
#metadata/metadata.c:1864 Found volume group "volume2"
#activate/activate.c:447 Getting device info for volume2-root
#ioctl/libdm-iface.c:1606 dm info LVM-7cNqUIuqutjSmmyzu2E22In2yVR6w0h2clcIR26lJ2r8i716ojnjXu9j0ntgh9n7 NF [16384]
#vgchange.c:165 Activated logical volumes in volume group "volume2"
#activate/activate.c:447 Getting device info for volume2-root
#ioctl/libdm-iface.c:1606 dm info LVM-7cNqUIuqutjSmmyzu2E22In2yVR6w0h2clcIR26lJ2r8i716ojnjXu9j0ntgh9n7 NF [16384]
#cache/lvmcache.c:71 Metadata cache: VG volume2 wiped.
#locking/file_locking.c:59 Unlocking /var/lock/lvm/V_volume2
#device/dev-io.c:485 Closed /dev/md4
#locking/file_locking.c:164 Locking /var/lock/lvm/V_volume1 RB
#toollib.c:491 Finding volume group "volume1"
#device/dev-io.c:439 Opened /dev/md3 RO O_DIRECT
#device/dev-io.c:134 /dev/md3: block size is 4096 bytes
#label/label.c:160 /dev/md3: lvm2 label detected
#cache/lvmcache.c:965 lvmcache: /dev/md3: now in VG #orphans_lvm2 (#orphans_lvm2) with 1 mdas
#format_text/format-text.c:1095 /dev/md3: Found metadata at 28160 size 2360 (in area at 4096 size 192512) for volume1 (Jn9uiZ-yQn1-SFSa-7UoU-67rb-5eYF-s2vtdd)
#cache/lvmcache.c:965 lvmcache: /dev/md3: now in VG volume1 with 1 mdas
#cache/lvmcache.c:752 lvmcache: /dev/md3: setting volume1 VGID to Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdd
#cache/lvmcache.c:1002 lvmcache: /dev/md3: VG volume1: Set creation host to raider.
#device/dev-io.c:439 Opened /dev/md4 RO O_DIRECT
#device/dev-io.c:134 /dev/md4: block size is 4096 bytes
#label/label.c:160 /dev/md4: lvm2 label detected
#cache/lvmcache.c:965 lvmcache: /dev/md4: now in VG #orphans_lvm2 (#orphans_lvm2) with 1 mdas
#format_text/format-text.c:1095 /dev/md4: Found metadata at 5632 size 883 (in area at 4096 size 192512) for volume2 (7cNqUI-uqut-jSmm-yzu2-E22I-n2yV-R6w0h2)
#cache/lvmcache.c:965 lvmcache: /dev/md4: now in VG volume2 with 1 mdas
#cache/lvmcache.c:752 lvmcache: /dev/md4: setting volume2 VGID to 7cNqUIuqutjSmmyzu2E22In2yVR6w0h2
#cache/lvmcache.c:1002 lvmcache: /dev/md4: VG volume2: Set creation host to raider.
#device/dev-io.c:485 Closed /dev/md4
#label/label.c:270 Using cached label for /dev/md3
#format_text/format-text.c:476 Read volume1 metadata (15) from /dev/md3 at 28160 size 2360
#cache/lvmcache.c:90 Metadata cache: VG volume1 stored (2360 bytes).
#metadata/pv_manip.c:272 /dev/md3 0: 0 1024: root(0:0)
#metadata/pv_manip.c:272 /dev/md3 1: 1024 64000: backuppc(0:0)
#metadata/pv_manip.c:272 /dev/md3 2: 65024 128000: backupfiles(0:0)
#metadata/pv_manip.c:272 /dev/md3 3: 193024 19200: backuppc-snapshot(0:0)
#metadata/pv_manip.c:272 /dev/md3 4: 212224 19200: backuppc-snapshot2(0:0)
#metadata/pv_manip.c:272 /dev/md3 5: 231424 2732: NULL(0:0)
#format_text/format-text.c:787 Read volume group volume1 from /etc/lvm/backup/volume1
#activate/activate.c:447 Getting device info for volume1-root
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddXbi9ta0AkiU33njbztAnNa0qrLdTD4iI NF [16384]
#activate/activate.c:447 Getting device info for volume1-backuppc
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs NF [16384]
#activate/activate.c:447 Getting device info for volume1-backupfiles
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddkHEX1qDMh0Hxgd6cRsv2401h4w10b4yP NF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddkHEX1qDMh0Hxgd6cRsv2401h4w10b4yP NF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-backupfiles NF [16384]
#activate/activate.c:447 Getting device info for volume1-snapshot0
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddJETI8PSQYRWzqgUHMt43MP2J5cxALeM1 NF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddJETI8PSQYRWzqgUHMt43MP2J5cxALeM1 NF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-snapshot0 NF [16384]
#activate/activate.c:447 Getting device info for volume1-snapshot1
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddkb1T3JnV8BFux1ylxgUuUgkY4n6j4YR1 NF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddkb1T3JnV8BFux1ylxgUuUgkY4n6j4YR1 NF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-snapshot1 NF [16384]
#vgchange.c:153 2 logical volume(s) in volume group "volume1" already active
#activate/activate.c:447 Getting device info for volume1-root
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddXbi9ta0AkiU33njbztAnNa0qrLdTD4iI NF [16384]
#activate/activate.c:447 Getting device info for volume1-backuppc
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs NF [16384]
#activate/activate.c:447 Getting device info for volume1-backupfiles
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddkHEX1qDMh0Hxgd6cRsv2401h4w10b4yP NF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddkHEX1qDMh0Hxgd6cRsv2401h4w10b4yP NF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-backupfiles NF [16384]
#activate/activate.c:447 Getting device info for volume1-backuppc--snapshot
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO NF [16384]
#activate/activate.c:447 Getting device info for volume1-backuppc--snapshot2
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E NF [16384]
#activate/activate.c:447 Getting device info for volume1-snapshot0
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddJETI8PSQYRWzqgUHMt43MP2J5cxALeM1 NF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddJETI8PSQYRWzqgUHMt43MP2J5cxALeM1 NF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-snapshot0 NF [16384]
#activate/activate.c:447 Getting device info for volume1-snapshot1
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddkb1T3JnV8BFux1ylxgUuUgkY4n6j4YR1 NF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddkb1T3JnV8BFux1ylxgUuUgkY4n6j4YR1 NF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-snapshot1 NF [16384]
#vgchange.c:159 4 existing logical volume(s) in volume group "volume1" monitored
#locking/file_locking.c:244 Locking LV Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddXbi9ta0AkiU33njbztAnNa0qrLdTD4iI (R)
#metadata/metadata.c:1858 Finding volume group for uuid Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddXbi9ta0AkiU33njbztAnNa0qrLdTD4iI
#label/label.c:270 Using cached label for /dev/md3
#metadata/pv_manip.c:272 /dev/md3 0: 0 1024: root(0:0)
#metadata/pv_manip.c:272 /dev/md3 1: 1024 64000: backuppc(0:0)
#metadata/pv_manip.c:272 /dev/md3 2: 65024 128000: backupfiles(0:0)
#metadata/pv_manip.c:272 /dev/md3 3: 193024 19200: backuppc-snapshot(0:0)
#metadata/pv_manip.c:272 /dev/md3 4: 212224 19200: backuppc-snapshot2(0:0)
#metadata/pv_manip.c:272 /dev/md3 5: 231424 2732: NULL(0:0)
#cache/lvmcache.c:513 Using cached metadata for VG volume1.
#metadata/metadata.c:1864 Found volume group "volume1"
#activate/activate.c:447 Getting device info for volume1-root
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddXbi9ta0AkiU33njbztAnNa0qrLdTD4iI NF [16384]
#locking/file_locking.c:257 Locking LV Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs (EX)
#metadata/metadata.c:1858 Finding volume group for uuid Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs
#label/label.c:270 Using cached label for /dev/md3
#metadata/pv_manip.c:272 /dev/md3 0: 0 1024: root(0:0)
#metadata/pv_manip.c:272 /dev/md3 1: 1024 64000: backuppc(0:0)
#metadata/pv_manip.c:272 /dev/md3 2: 65024 128000: backupfiles(0:0)
#metadata/pv_manip.c:272 /dev/md3 3: 193024 19200: backuppc-snapshot(0:0)
#metadata/pv_manip.c:272 /dev/md3 4: 212224 19200: backuppc-snapshot2(0:0)
#metadata/pv_manip.c:272 /dev/md3 5: 231424 2732: NULL(0:0)
#cache/lvmcache.c:513 Using cached metadata for VG volume1.
#metadata/metadata.c:1864 Found volume group "volume1"
#activate/activate.c:447 Getting device info for volume1-backuppc
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs NF [16384]
#mm/memlock.c:99 Locking memory
#mm/memlock.c:130 memlock_count inc to 1
#config/config.c:927 Setting activation/missing_stripe_filler to /dev/ioerror
#activate/dev_manager.c:632 Getting device info for volume1-backuppc [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs OF [16384]
#ioctl/libdm-iface.c:1606 dm deps (253:3) OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc-real [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs-real]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs-real OF [16384]
#ioctl/libdm-iface.c:1606 dm deps (253:2) OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc-cow [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs-cow]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs-cow OF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs-cow OF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-backuppc-cow OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc_mlog [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs-_mlog]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs-_mlog OF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtdddxWrfdYOSlsm0xdqPat7wyl12J9d0hjs-_mlog OF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-backuppc_mlog OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc--snapshot [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO OF [16384]
#ioctl/libdm-iface.c:1606 dm deps (253:5) OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc--snapshot-real [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO-real]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO-real OF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO-real OF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-backuppc--snapshot-real OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc--snapshot-cow [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO-cow]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO-cow OF [16384]
#ioctl/libdm-iface.c:1606 dm deps (253:4) OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc--snapshot_mlog [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO-_mlog]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO-_mlog OF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddZh9sIx2iIEUyHpFTt4sFEW33BiFdv2AO-_mlog OF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-backuppc--snapshot_mlog OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc--snapshot2 [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E OF [16384]
#ioctl/libdm-iface.c:1606 dm deps (253:7) OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc--snapshot2-real [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E-real]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E-real OF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E-real OF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-backuppc--snapshot2-real OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc--snapshot2-cow [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E-cow]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E-cow OF [16384]
#ioctl/libdm-iface.c:1606 dm deps (253:6) OF [16384]
#activate/dev_manager.c:632 Getting device info for volume1-backuppc--snapshot2_mlog [LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E-_mlog]
#ioctl/libdm-iface.c:1606 dm info LVM-Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E-_mlog OF [16384]
#ioctl/libdm-iface.c:1606 dm info Jn9uiZyQn1SFSa7UoU67rb5eYFs2vtddmVNRnOQkrr7f8WdSPFWNw8tuOO1y239E-_mlog OF [16384]
#ioctl/libdm-iface.c:1606 dm info volume1-backuppc--snapshot2_mlog OF [16384]
#activate/dev_manager.c:823 Checking kernel supports striped segment type for backuppc
#activate/activate.c:362 Getting target version for linear
#ioctl/libdm-iface.c:1606 dm versions OF [16384]
#activate/activate.c:362 Getting target version for striped
#ioctl/libdm-iface.c:1606 dm versions OF [16384]
#activate/dev_manager.c:823 Checking kernel supports striped segment type for backuppc-real
#activate/dev_manager.c:823 Checking kernel supports snapshot segment type for backuppc-snapshot
#activate/activate.c:362 Getting target version for snapshot
#ioctl/libdm-iface.c:1606 dm versions OF [16384]
#activate/activate.c:362 Getting target version for snapshot-origin
#ioctl/libdm-iface.c:1606 dm versions OF [16384]
#activate/dev_manager.c:823 Checking kernel supports snapshot segment type for backuppc-snapshot-cow
#activate/dev_manager.c:823 Checking kernel supports snapshot segment type for backuppc-snapshot2
#activate/dev_manager.c:823 Checking kernel supports snapshot segment type for backuppc-snapshot2-cow
#libdm-deptree.c:1463 Loading volume1-backuppc-real table
#libdm-deptree.c:1413 Adding target: 0 524288000 linear 9:3 8388992
#ioctl/libdm-iface.c:1606 dm table (253:2) OF [16384]
#libdm-deptree.c:1495 Suppressed volume1-backuppc-real identical table reload.
#libdm-deptree.c:1463 Loading volume1-backuppc--snapshot-cow table
#libdm-deptree.c:1413 Adding target: 0 157286400 linear 9:3 1581252992
#ioctl/libdm-iface.c:1606 dm table (253:4) OF [16384]
#libdm-deptree.c:1495 Suppressed volume1-backuppc--snapshot-cow identical table reload.
#libdm-deptree.c:1463 Loading volume1-backuppc--snapshot2-cow table
#libdm-deptree.c:1413 Adding target: 0 157286400 linear 9:3 1738539392
#ioctl/libdm-iface.c:1606 dm table (253:6) OF [16384]
#libdm-deptree.c:1495 Suppressed volume1-backuppc--snapshot2-cow identical table reload.
#libdm-deptree.c:1463 Loading volume1-backuppc--snapshot2 table
#libdm-deptree.c:1413 Adding target: 0 524288000 snapshot 253:2 253:6 P 8
#ioctl/libdm-iface.c:1606 dm table (253:7) OF [16384]
#ioctl/libdm-iface.c:1606 dm reload (253:7) NF [16384]
----------------------------------------------------------------------------------------
The corresponding syslog shows:
[ 1366.666698] 16384 pages of RAM
[ 1366.669753] 186 free pages
[ 1366.672457] 1193 reserved pages
[ 1366.675593] 7777 slab pages
[ 1366.678384] 4093 pages shared
[ 1366.681348] 0 pages swap cached
[ 1366.684490] SLUB: Unable to allocate memory on node -1 (gfp=0x20)
[ 1366.690574] cache: nsproxy, object size: 24, buffer size: 24, default order: 0, min order: 0
[ 1366.699168] node 0: slabs: 6803, objs: 1156510, free: 0
[ 1366.747658] device-mapper: ioctl: error adding target to table
[ 1388.693740] tail invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0
[ 1388.700620] tail cpuset=/ mems_allowed=0
[ 1388.704599] [<c002f070>] (unwind_backtrace+0x0/0xdc) from [<c00a7b50>] (oom_kill_process+0x5c/0x1d8)
[ 1388.714022] [<c00a7b50>] (oom_kill_process+0x5c/0x1d8) from [<c00a8100>] (__out_of_memory+0x148/0x16c)
[ 1388.723384] [<c00a8100>] (__out_of_memory+0x148/0x16c) from [<c00a818c>] (out_of_memory+0x68/0x9c)
[ 1388.732406] [<c00a818c>] (out_of_memory+0x68/0x9c) from [<c00aaf1c>] (__alloc_pages_nodemask+0x448/0x584)
[ 1388.742034] [<c00aaf1c>] (__alloc_pages_nodemask+0x448/0x584) from [<c00ac900>] (__do_page_cache_readahead+0x9c/0x1e4)
[ 1388.752801] [<c00ac900>] (__do_page_cache_readahead+0x9c/0x1e4) from [<c00aca70>] (ra_submit+0x28/0x30)
[ 1388.762247] [<c00aca70>] (ra_submit+0x28/0x30) from [<c00a5cf4>] (filemap_fault+0x1b0/0x380)
[ 1388.770747] [<c00a5cf4>] (filemap_fault+0x1b0/0x380) from [<c00ba560>] (__do_fault+0x50/0x3c8)
[ 1388.779418] [<c00ba560>] (__do_fault+0x50/0x3c8) from [<c00bb8b0>] (handle_mm_fault+0x2cc/0x664)
[ 1388.788263] [<c00bb8b0>] (handle_mm_fault+0x2cc/0x664) from [<c0030084>] (do_page_fault+0xe4/0x1ec)
[ 1388.797368] [<c0030084>] (do_page_fault+0xe4/0x1ec) from [<c00281ec>] (do_PrefetchAbort+0x34/0x94)
[ 1388.806572] [<c00281ec>] (do_PrefetchAbort+0x34/0x94) from [<c0028e00>] (ret_from_exception+0x0/0x10)
[ 1388.815825] Exception stack(0xc207ffb0 to 0xc207fff8)
[ 1388.820890] ffa0: 00000001 bea7fb08 3b9ac9ff 00000010
[ 1388.829115] ffc0: bea7fb08 bea7fb18 bea7fb38 bea7fb08 3b9ac9ff bea7feb0 3b9ac9ff 00000000
[ 1388.837342] ffe0: 000195e8 bea7fb00 0000e43c 400298ec 60000010 ffffffff
[ 1388.843946] Mem-info:
[ 1388.846257] Normal per-cpu:
[ 1388.849052] CPU 0: hi: 18, btch: 3 usd: 2
[ 1388.853859] active_anon:0 inactive_anon:0 isolated_anon:8
[ 1388.853874] active_file:20 inactive_file:0 isolated_file:0
[ 1388.853890] unevictable:3650 dirty:0 writeback:0 unstable:0
[ 1388.853906] free:253 slab_reclaimable:271 slab_unreclaimable:8071
[ 1388.853923] mapped:918 shmem:0 pagetables:111 bounce:0
[ 1388.881901] Normal free:1012kB min:1016kB low:1268kB high:1524kB active_anon:0kB inactive_anon:0kB active_file:80kB inactive_file:0kB unevictable:14600kB isolated(anon):32kB isolated(file):0kB present:65024kB mlocked:14600kB dirty:0kB writeback:0kB mapped:3672kB shmem:0kB slab_reclaimable:1084kB slab_unreclaimable:32284kB kernel_stack:728kB pagetables:444kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:94 all_unreclaimable? no
[ 1388.920726] lowmem_reserve[]: 0 0
[ 1388.924078] Normal: 227*4kB 1*8kB 0*16kB 1*32kB 1*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1012kB
[ 1388.934636] 952 total pagecache pages
[ 1388.938333] 7 pages in swap cache
[ 1388.941648] Swap cache stats: add 5548, delete 5541, find 1075/1573
[ 1388.947941] Free swap = 522380kB
[ 1388.951251] Total swap = 530104kB
[ 1388.957156] 16384 pages of RAM
[ 1388.960211] 424 free pages
[ 1388.962914] 1193 reserved pages
[ 1388.966110] 7535 slab pages
[ 1388.968902] 4077 pages shared
[ 1388.971866] 7 pages swap cached
[ 1392.521931] vgchange: page allocation failure. order:0, mode:0x10
[ 1392.528175] [<c002f070>] (unwind_backtrace+0x0/0xdc) from [<c00aafb8>] (__alloc_pages_nodemask+0x4e4/0x584)
[ 1392.538001] [<c00aafb8>] (__alloc_pages_nodemask+0x4e4/0x584) from [<c00cf108>] (__slab_alloc+0x170/0x52c)
[ 1392.547714] [<c00cf108>] (__slab_alloc+0x170/0x52c) from [<c00cfe0c>] (kmem_cache_alloc+0x70/0x100)
[ 1392.556851] [<c00cfe0c>] (kmem_cache_alloc+0x70/0x100) from [<bf138e80>] (alloc_exception+0x14/0x34 [dm_snapshot])
[ 1392.567290] [<bf138e80>] (alloc_exception+0x14/0x34 [dm_snapshot]) from [<bf1390b4>] (dm_add_exception+0x14/0x40 [dm_snapshot])
[ 1392.578864] [<bf1390b4>] (dm_add_exception+0x14/0x40 [dm_snapshot]) from [<bf13af28>] (persistent_read_metadata+0x358/0x3c8 [dm_snapshot])
[ 1392.591393] [<bf13af28>] (persistent_read_metadata+0x358/0x3c8 [dm_snapshot]) from [<bf1399e0>] (snapshot_ctr+0x2f0/0x614 [dm_snapshot])
[ 1392.603783] [<bf1399e0>] (snapshot_ctr+0x2f0/0x614 [dm_snapshot]) from [<bf123818>] (dm_table_add_target+0x170/0x208 [dm_mod])
[ 1392.615547] [<bf123818>] (dm_table_add_target+0x170/0x208 [dm_mod]) from [<bf125718>] (table_load+0x23c/0x268 [dm_mod])
[ 1392.626493] [<bf125718>] (table_load+0x23c/0x268 [dm_mod]) from [<bf1263f0>] (dm_ctl_ioctl+0x21c/0x29c [dm_mod])
[ 1392.636802] [<bf1263f0>] (dm_ctl_ioctl+0x21c/0x29c [dm_mod]) from [<c00e004c>] (vfs_ioctl+0x2c/0x70)
[ 1392.646003] [<c00e004c>] (vfs_ioctl+0x2c/0x70) from [<c00e0750>] (do_vfs_ioctl+0x4f4/0x55c)
[ 1392.654366] [<c00e0750>] (do_vfs_ioctl+0x4f4/0x55c) from [<c00e0808>] (sys_ioctl+0x50/0x74)
[ 1392.662778] [<c00e0808>] (sys_ioctl+0x50/0x74) from [<c0028e80>] (ret_fast_syscall+0x0/0x28)
[ 1392.671248] Mem-info:
[ 1392.673528] Normal per-cpu:
[ 1392.676365] CPU 0: hi: 18, btch: 3 usd: 0
[ 1392.681172] active_anon:0 inactive_anon:2 isolated_anon:0
[ 1392.681188] active_file:0 inactive_file:19 isolated_file:0
[ 1392.681203] unevictable:3650 dirty:0 writeback:0 unstable:0
[ 1392.681219] free:0 slab_reclaimable:271 slab_unreclaimable:8336
[ 1392.681236] mapped:916 shmem:0 pagetables:111 bounce:0
[ 1392.709043] Normal free:0kB min:1016kB low:1268kB high:1524kB active_anon:0kB inactive_anon:8kB active_file:0kB inactive_file:76kB unevictable:14600kB isolated(anon):0kB isolated(file):0kB present:65024kB mlocked:14600kB dirty:0kB writeback:0kB mapped:3664kB shmem:0kB slab_reclaimable:1084kB slab_unreclaimable:33344kB kernel_stack:728kB pagetables:444kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:129 all_unreclaimable? yes
[ 1392.747731] lowmem_reserve[]: 0 0
[ 1392.751071] Normal: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 0kB
[ 1392.761197] 937 total pagecache pages
[ 1392.764894] 2 pages in swap cache
[ 1392.768209] Swap cache stats: add 5567, delete 5565, find 1075/1576
[ 1392.774459] Free swap = 522376kB
[ 1392.777811] Total swap = 530104kB
[ 1392.783648] 16384 pages of RAM
[ 1392.786762] 169 free pages
[ 1392.789467] 1193 reserved pages
[ 1392.792603] 7779 slab pages
[ 1392.795438] 4065 pages shared
[ 1392.798401] 2 pages swap cached
[ 1392.801543] SLUB: Unable to allocate memory on node -1 (gfp=0x10)
[ 1392.807627] cache: nsproxy, object size: 24, buffer size: 24, default order: 0, min order: 0
[ 1392.816222] node 0: slabs: 6807, objs: 1157190, free: 0
[ 1392.821683] vgchange: page allocation failure. order:0, mode:0x20
[ 1392.827824] [<c002f070>] (unwind_backtrace+0x0/0xdc) from [<c00aafb8>] (__alloc_pages_nodemask+0x4e4/0x584)
[ 1392.837582] [<c00aafb8>] (__alloc_pages_nodemask+0x4e4/0x584) from [<c00cf108>] (__slab_alloc+0x170/0x52c)
[ 1392.847247] [<c00cf108>] (__slab_alloc+0x170/0x52c) from [<c00cfe0c>] (kmem_cache_alloc+0x70/0x100)
[ 1392.856330] [<c00cfe0c>] (kmem_cache_alloc+0x70/0x100) from [<bf1390b4>] (dm_add_exception+0x14/0x40 [dm_snapshot])
[ 1392.866814] [<bf1390b4>] (dm_add_exception+0x14/0x40 [dm_snapshot]) from [<bf13af28>] (persistent_read_metadata+0x358/0x3c8 [dm_snapshot])
[ 1392.879287] [<bf13af28>] (persistent_read_metadata+0x358/0x3c8 [dm_snapshot]) from [<bf1399e0>] (snapshot_ctr+0x2f0/0x614 [dm_snapshot])
[ 1392.891616] [<bf1399e0>] (snapshot_ctr+0x2f0/0x614 [dm_snapshot]) from [<bf123818>] (dm_table_add_target+0x170/0x208 [dm_mod])
[ 1392.903094] [<bf123818>] (dm_table_add_target+0x170/0x208 [dm_mod]) from [<bf125718>] (table_load+0x23c/0x268 [dm_mod])
[ 1392.913974] [<bf125718>] (table_load+0x23c/0x268 [dm_mod]) from [<bf1263f0>] (dm_ctl_ioctl+0x21c/0x29c [dm_mod])
[ 1392.924217] [<bf1263f0>] (dm_ctl_ioctl+0x21c/0x29c [dm_mod]) from [<c00e004c>] (vfs_ioctl+0x2c/0x70)
[ 1392.933361] [<c00e004c>] (vfs_ioctl+0x2c/0x70) from [<c00e0750>] (do_vfs_ioctl+0x4f4/0x55c)
[ 1392.941723] [<c00e0750>] (do_vfs_ioctl+0x4f4/0x55c) from [<c00e0808>] (sys_ioctl+0x50/0x74)
[ 1392.950089] [<c00e0808>] (sys_ioctl+0x50/0x74) from [<c0028e80>] (ret_fast_syscall+0x0/0x28)
[ 1392.958511] Mem-info:
[ 1392.960781] Normal per-cpu:
[ 1392.963575] CPU 0: hi: 18, btch: 3 usd: 0
[ 1392.968383] active_anon:0 inactive_anon:2 isolated_anon:0
[ 1392.968398] active_file:0 inactive_file:19 isolated_file:0
[ 1392.968414] unevictable:3650 dirty:0 writeback:0 unstable:0
[ 1392.968429] free:0 slab_reclaimable:271 slab_unreclaimable:8336
[ 1392.968446] mapped:916 shmem:0 pagetables:111 bounce:0
[ 1392.996203] Normal free:0kB min:1016kB low:1268kB high:1524kB active_anon:0kB inactive_anon:8kB active_file:0kB inactive_file:76kB unevictable:14600kB isolated(anon):0kB isolated(file):0kB present:65024kB mlocked:14600kB dirty:0kB writeback:0kB mapped:3664kB shmem:0kB slab_reclaimable:1084kB slab_unreclaimable:33344kB kernel_stack:728kB pagetables:444kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:129 all_unreclaimable? yes
[ 1393.034583] lowmem_reserve[]: 0 0
[ 1393.037927] Normal: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 0kB
[ 1393.048010] 937 total pagecache pages
[ 1393.051665] 2 pages in swap cache
[ 1393.054979] Swap cache stats: add 5567, delete 5565, find 1075/1576
[ 1393.061230] Free swap = 522376kB
[ 1393.064538] Total swap = 530104kB
[ 1393.070372] 16384 pages of RAM
[ 1393.073429] 169 free pages
[ 1393.076133] 1193 reserved pages
[ 1393.079269] 7779 slab pages
[ 1393.082060] 4065 pages shared
[ 1393.085024] 2 pages swap cached
[ 1393.088166] SLUB: Unable to allocate memory on node -1 (gfp=0x20)
[ 1393.094250] cache: nsproxy, object size: 24, buffer size: 24, default order: 0, min order: 0
[ 1393.102845] node 0: slabs: 6807, objs: 1157190, free: 0
[ 1393.156894] device-mapper: ioctl: error adding target to table
Reply to: