Problem (?) with LVM snapshots since Feb 12 updates

alphaniner · 2013-02-15 15:33:36

After the update, I'm seeing some LVM snapshot errors during boot. In context:

:: running hook [udev]
:: Triggering uevents
[ x.xxx ] device-mapper: table: 254:9: snapshot: Snapshot cow pairing for exception table handover failed
[ x.xxx ] device-mapper: table: 254:14: snapshot: Snapshot cow pairing for exception table handover failed
:: running hook [keymap]
:: performing fsck on <root LV>
arch: clean ...
:: mounting '<root LV>' on real root
:: running cleanup hook [shutdown]
:: running cleanup hook [lvm]
:: running cleanup hook [udev]

Welcome to Arch Linux!

The number of errors varies between zero and three, the latter being the number of snapshots I have.

The corresponding info in the journal is:

Feb 15 09:29:17 caddywhompus kernel: device-mapper: table: 254:9: snapshot: Snapshot cow pairing for exception table handover failed
Feb 15 09:29:17 caddywhompus kernel: device-mapper: ioctl: error adding target to table
Feb 15 09:29:17 caddywhompus kernel: device-mapper: table: 254:14: snapshot: Snapshot cow pairing for exception table handover failed
Feb 15 09:29:17 caddywhompus kernel: device-mapper: ioctl: error adding target to table

Since the errors seem to occur during initramfs, here's some info on that:

# cat /etc/mkinitcpio.conf
MODULES="nouveau ext4"
BINARIES=""
FILES=""
HOOKS="base udev autodetect block keymap lvm2 keyboard fsck shutdown"
COMPRESSION="xz"
COMPRESSION_OPTIONS="-e -9"

# lsinitcpio -a /boot/caddywhompus.img
==> Image: /boot/caddywhompus.img 
==> Created with mkinitcpio 0.13.0
==> Kernel: 3.7.7-1-ARCH
==> Size: 3.29 MiB
==> Compressed with: xz
  -> Uncompressed size: 12.37 MiB (.265 ratio)
  -> Estimated extraction time: 0.402s

==> Included modules:
  ahci			  dm-mirror		  ehci-hcd		  libahci		  pata_marvell		  usb-common
  ata_generic		  dm-mod		  ext4 [explicit]	  libata		  scsi_mod		  usbcore
  button		  dm-region-hash	  hid			  mbcache		  sd_mod		  usbhid
  cdrom			  dm-snapshot		  i2c-algo-bit		  mxm-wmi		  sr_mod		  usb-storage
  crc16			  drm			  i2c-core		  nouveau [explicit]	  ttm			  video
  dm-log		  drm_kms_helper	  jbd2			  pata_acpi		  uhci-hcd		  wmi

==> Included binaries:
  blkid		  cp		  findmnt	  fsck.ext4	  lsblk		  lvmetad	  switch_root	  udevd
  busybox	  dmsetup	  fsck		  kmod		  lvm		  mount		  udevadm

==> Early hook run order:
  udev
  lvm2

==> Hook run order:
  udev
  keymap

==> Cleanup hook run order:
  shutdown
  lvm2
  udev

Initially I missed the news to enable lvm-monitoring.service. I have since enabled the service, rebooted to another install of Arch which doesn't use LVM (all lvs are prevented from being activated with empty auto_activation_volume_list), and deleted and recreated the snapshots in case they had gotten borked. FWIW, the SSs now only exist for the purpose of troubleshooting this issue, so I'm not worried about their integrity.

I've done numerous boots and seen instances where both lvm-monitoring.service and dmeventd.service start, where both fail, and where one starts but the other fails. This doesn't seem to correspond with the occurence of the errors during boot. On my most recent boot both failed:

# systemctl status lvm-monitoring.service dmeventd.service 
lvm-monitoring.service - Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling
	  Loaded: loaded (/usr/lib/systemd/system/lvm-monitoring.service; enabled)
	  Active: failed (Result: exit-code) since Fri 2013-02-15 09:49:25 EST; 2min 10s ago
	    Docs: man:dmeventd(8)
	          man:lvcreate(8)
	          man:lvchange(8)
	          man:vgchange(8)
	 Process: 237 ExecStart=/usr/sbin/lvm vgchange --monitor y (code=exited, status=5)

Feb 15 09:49:18 caddywhompus lvm[237]: 2 logical volume(s) in volume group "VG1" monitored
Feb 15 09:49:25 caddywhompus lvm[237]: No input from event server.
Feb 15 09:49:25 caddywhompus lvm[237]: VG0-ss_var: event registration failed: Input/output error
Feb 15 09:49:25 caddywhompus lvm[237]: VG0/snapshot1: snapshot segment monitoring function failed.
Feb 15 09:49:25 caddywhompus lvm[237]: 8 logical volume(s) in volume group "VG0" monitored
Feb 15 09:49:25 caddywhompus systemd[1]: lvm-monitoring.service: main process exited, code=exited, status=5/NOTINSSTALLED
Feb 15 09:49:25 caddywhompus systemd[1]: Failed to start Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling.
Feb 15 09:49:25 caddywhompus systemd[1]: Unit lvm-monitoring.service entered failed state
Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.

dmeventd.service - Device-mapper event daemon
	  Loaded: loaded (/usr/lib/systemd/system/dmeventd.service; static)
	  Active: failed (Result: core-dump) since Fri 2013-02-15 09:49:35 EST; 2min 0s ago
	    Docs: man:dmeventd(8)
	 Process: 469 ExecStart=/usr/sbin/dmeventd (code=exited, status=0/SUCCESS)
	Main PID: 470 (code=dumped, signal=SEGV)
	  CGroup: name=systemd:/system/dmeventd.service

Feb 15 09:49:25 caddywhompus systemd[1]: Starting Device-mapper event daemon...
Feb 15 09:49:25 caddywhompus dmeventd[470]: dmeventd ready for processing.
Feb 15 09:49:25 caddywhompus systemd[1]: Started Device-mapper event daemon.
Feb 15 09:49:25 caddywhompus lvm[470]: Monitoring snapshot VG0-ss_var
Feb 15 09:49:25 caddywhompus lvm[470]: Monitoring snapshot VG0-ss_root
Feb 15 09:49:25 caddywhompus lvm[470]: Monitoring snapshot VG0-ss_home
Feb 15 09:49:35 caddywhompus systemd[1]: dmeventd.service: main process exited, code=dumped, status=11/SEGV
Feb 15 09:49:35 caddywhompus systemd-coredump[676]: Process 470 (dmeventd) dumped core.
Feb 15 09:49:35 caddywhompus systemd[1]: Unit dmeventd.service entered failed state

But in all cases, lvdisplay seems to indicate that the snapshots are working fine:

# lvdisplay VG0/ss_root VG0/ss_var VG0/ss_home
  --- Logical volume ---
  LV Path                /dev/VG0/ss_root
  LV Name                ss_root
  VG Name                VG0
  LV UUID                jQo9aS-392r-VEX4-36ra-LNS8-BfIJ-0d8NyL
  LV Write Access        read/write
  LV Creation host, time recover, 2013-02-14 17:37:31 -0500
  LV snapshot status     active destination for lv_root
  LV Status              available
  # open                 0
  LV Size                5.00 GiB
  Current LE             1280
  COW-table size         5.00 GiB
  COW-table LE           1280
  Allocated to snapshot  0.01%
  Snapshot chunk size    4.00 KiB
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           254:5
   
  --- Logical volume ---
  LV Path                /dev/VG0/ss_var
  LV Name                ss_var
  VG Name                VG0
  LV UUID                SPEFKY-nOYY-3B2L-GpAq-3eSe-aLtY-jlGLQJ
  LV Write Access        read/write
  LV Creation host, time recover, 2013-02-14 17:37:32 -0500
  LV snapshot status     active destination for lv_var
  LV Status              available
  # open                 0
  LV Size                5.71 GiB
  Current LE             1462
  COW-table size         5.71 GiB
  COW-table LE           1462
  Allocated to snapshot  0.51%
  Snapshot chunk size    4.00 KiB
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           254:14
   
  --- Logical volume ---
  LV Path                /dev/VG0/ss_home
  LV Name                ss_home
  VG Name                VG0
  LV UUID                MzJVwN-i49J-1nto-6UM4-bq0P-6jD9-F21ok2
  LV Write Access        read/write
  LV Creation host, time recover, 2013-02-14 17:37:32 -0500
  LV snapshot status     active destination for lv_home
  LV Status              available
  # open                 0
  LV Size                10.00 GiB
  Current LE             2560
  COW-table size         10.00 GiB
  COW-table LE           2560
  Allocated to snapshot  0.25%
  Snapshot chunk size    4.00 KiB
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           254:7

I made the suggested change to global_filter in lvm.conf, though I never had any problems booting; I just saw the occasional warning about fd0 and/or cdrom when running lvscan after boot, and figured it couldn't hurt.

And... I have no idea where to go from here.

Arch Linux

#1 2013-02-15 15:33:36

Problem (?) with LVM snapshots since Feb 12 updates

Board footer