Copy container from btrfs to lvm fails with I/O error

diabolusss · March 14, 2021, 6:07pm

Hello!
I believe, that I have a similar problem as mentioned here.
Container hosts gui messanger apps like Skype, Viber, etc and browsers, no other special use case, like lxd or docker inside.
So far I have tried to copy the container with snapshots, without them (–instance-only), with and without profiles applied (–no-profiles). Sadly, but everything has failed.

At the same time I have another container on the btrfs backend, but with no snapshots, and it hasn’t failed on copy to the new lvm backend.

UPD: Actually failed verification – update discarded seems to be a rsync error and i see a lot of them with opera/skype cache files stored in container.
lxd version

os_name: Arch Linux
  os_version: ""
  project: default
  server: lxd
  server_clustered: false
  server_version: "4.12"
  storage: btrfs | lvm
  storage_version: 4.15.1 | 2.02.187(2) (2020-03-24) / 1.02.170 (2020-03-24) / 4.43.0

Container info:

$ lxc info messangers-arch
Name: messangers-arch
Location: none
Remote: unix://
Architecture: x86_64
Created: 2020/11/20 16:48 UTC
Status: Running
Type: container
Profiles: pulseaudio, messangers-arch
Snapshots:
  201120-add-sudo-user (taken at 2020/11/20 17:11 UTC) (stateless)
  201120-basic-gui-audio-packages (taken at 2020/11/20 17:22 UTC) (stateless)
  201120-audio-ready (taken at 2020/11/20 20:55 UTC) (stateless)
  201120-gui-ready (taken at 2020/11/20 22:50 UTC) (stateless)
  201120-aur-helper (taken at 2020/11/20 23:06 UTC) (stateless)
  201121-complete (taken at 2020/11/21 18:30 UTC) (stateless)

Container source storage pool (current working state):

lxc storage info messangers-arch
info:
  description: 20GB
  driver: btrfs
  name: messangers-arch
  space used: 14.24GB
  total space: 20.00GB
used by:
  instances:
  - messangers-arch
  profiles:
  - messangers-arch

Container destination storage pool (2 - bigger):

 $ lxc storage info lvmTPool01
 info:
  description: ""
  driver: lvm
  name: lvmTPool01
  space used: 819.41MB
  total space: 51.54GB

I’ve found out that this command should be issued to change default lv size, so i’ve issued it when found. Obviously, without that I had the same error, but it’s expected.
lxc storage set lvm_pool volume.size XXGB

Result of attempt to copy only instance to the LVM pool:

rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/colt/.config/opera/Service Worker/CacheStorage/efb5023a1630344583faab602ea42e0ca473b65d/6bc2892c-701d-4187-8ba3-82e6155e8b99/17cc61884630086e_1": Input/output error (5)
WARNING: rootfs/home/colt/.config/opera/Service Worker/CacheStorage/579544fd7d0441717f082c9eb123588966aa57ac/8ef64737-bd09-4e73-9268-11e4e42b98c4/67c8aea7a5b97064_0 failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/colt/.config/opera/Service Worker/CacheStorage/579544fd7d0441717f082c9eb123588966aa57ac/8ef64737-bd09-4e73-9268-11e4e42b98c4/67c8aea7a5b97064_0": Input/output error (5)
WARNING: rootfs/home/colt/.config/opera/Service Worker/CacheStorage/efb5023a1630344583faab602ea42e0ca473b65d/6bc2892c-701d-4187-8ba3-82e6155e8b99/17cc61884630086e_1 failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/colt/.config/opera/Service Worker/CacheStorage/efb5023a1630344583faab602ea42e0ca473b65d/6bc2892c-701d-4187-8ba3-82e6155e8b99/17cc61884630086e_1": Input/output error (5)
ERROR: rootfs/home/colt/.config/opera/Service Worker/CacheStorage/579544fd7d0441717f082c9eb123588966aa57ac/8ef64737-bd09-4e73-9268-11e4e42b98c4/67c8aea7a5b97064_0 failed verification -- update discarded.
ERROR: rootfs/home/colt/.config/opera/Service Worker/CacheStorage/efb5023a1630344583faab602ea42e0ca473b65d/6bc2892c-701d-4187-8ba3-82e6155e8b99/17cc61884630086e_1 failed verification -- update discarded.
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.cache/mozilla/firefox/c7bzoruj.default-release/cache2/entries/3E1E786DB396415EE9C929E201DCC1989AF4805C": Input/output error (5)
WARNING: rootfs/home/ubuntu/.cache/mozilla/firefox/c7bzoruj.default-release/cache2/entries/3E1E786DB396415EE9C929E201DCC1989AF4805C failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.cache/mozilla/firefox/c7bzoruj.default-release/cache2/entries/3E1E786DB396415EE9C929E201DCC1989AF4805C": Input/output error (5)
ERROR: rootfs/home/ubuntu/.cache/mozilla/firefox/c7bzoruj.default-release/cache2/entries/3E1E786DB396415EE9C929E201DCC1989AF4805C failed verification -- update discarded.
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.cache/thunderbird/tl012p50.default/cache2/entries/26F2934535ABE6B0B451DE3DC7BD2779A29E2CD4": Input/output error (5)
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/Microsoft/Microsoft Teams/old_logs_20210110183021.txt": Input/output error (5)
WARNING: rootfs/home/ubuntu/.cache/thunderbird/tl012p50.default/cache2/entries/26F2934535ABE6B0B451DE3DC7BD2779A29E2CD4 failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.cache/thunderbird/tl012p50.default/cache2/entries/26F2934535ABE6B0B451DE3DC7BD2779A29E2CD4": Input/output error (5)
WARNING: rootfs/home/ubuntu/.config/Microsoft/Microsoft Teams/old_logs_20210110183021.txt failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/Microsoft/Microsoft Teams/old_logs_20210110183021.txt": Input/output error (5)
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/opera/History": Input/output error (5)
ERROR: rootfs/home/ubuntu/.cache/thunderbird/tl012p50.default/cache2/entries/26F2934535ABE6B0B451DE3DC7BD2779A29E2CD4 failed verification -- update discarded.
ERROR: rootfs/home/ubuntu/.config/Microsoft/Microsoft Teams/old_logs_20210110183021.txt failed verification -- update discarded.
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/opera/Local Extension Settings/kccohkcpppjjkkjppopfnflnebibpida/000527.ldb": Input/output error (5)
WARNING: rootfs/home/ubuntu/.config/opera/History failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/opera/History": Input/output error (5)
WARNING: rootfs/home/ubuntu/.config/opera/Local Extension Settings/kccohkcpppjjkkjppopfnflnebibpida/000527.ldb failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/opera/Local Extension Settings/kccohkcpppjjkkjppopfnflnebibpida/000527.ldb": Input/output error (5)
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/3be61d81a0976669_0": Input/output error (5)
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/73e9b0021fae97a4_0": Input/output error (5)
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/f5135f83e9b23320_0": Input/output error (5)
ERROR: rootfs/home/ubuntu/.config/opera/History failed verification -- update discarded.
ERROR: rootfs/home/ubuntu/.config/opera/Local Extension Settings/kccohkcpppjjkkjppopfnflnebibpida/000527.ldb failed verification -- update discarded.
WARNING: rootfs/home/ubuntu/.config/skypeforlinux/Cache/3be61d81a0976669_0 failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/3be61d81a0976669_0": Input/output error (5)
WARNING: rootfs/home/ubuntu/.config/skypeforlinux/Cache/73e9b0021fae97a4_0 failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/73e9b0021fae97a4_0": Input/output error (5)
WARNING: rootfs/home/ubuntu/.config/skypeforlinux/Cache/f5135f83e9b23320_0 failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/f5135f83e9b23320_0": Input/output error (5)
ERROR: rootfs/home/ubuntu/.config/skypeforlinux/Cache/3be61d81a0976669_0 failed verification -- update discarded.
ERROR: rootfs/home/ubuntu/.config/skypeforlinux/Cache/73e9b0021fae97a4_0 failed verification -- update discarded.
ERROR: rootfs/home/ubuntu/.config/skypeforlinux/Cache/f5135f83e9b23320_0 failed verification -- update discarded.
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/var/cache/man/sv/index.db": Input/output error (5)
WARNING: rootfs/var/cache/man/sv/index.db failed verification -- update discarded (will try again).
rsync: read errors mapping "/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/var/cache/man/sv/index.db": Input/output error (5)
ERROR: rootfs/var/cache/man/sv/index.db failed verification -- update discarded.
rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1196) [sender=3.1.2]
) Rsync receive failed: /var/snap/lxd/common/lxd/storage-pools/messangersTPool/containers/messangers/: [exit status 23] ()]

Space used few minutes before fail:

lxc storage info lvmTPool01
info:
  description: ""
  driver: lvm
  name: lvmTPool01
  space used: 11.02GB
  total space: 51.54GB
used by:
  instances:
  - messangers

sudo lvdisplay lvmTPoolVG01 --units G
  --- Logical volume ---
  LV Name                lvmTPool01
  VG Name                lvmTPoolVG01
  LV UUID                ZsTRzL-3QQQ-KAQN-a6eH-oLor-uCI1-J3V2ZU
  LV Write Access        read/write (activated read only)
  LV Creation host, time LIVE.ARCH.BOX, 2021-03-13 21:25:35 +0200
  LV Pool metadata       lvmTPool01_tmeta
  LV Pool data           lvmTPool01_tdata
  LV Status              available
  # open                 2
  LV Size                51.54 GB
  Allocated pool data    19.53%
  Allocated metadata     2.02%
  Current LE             12287
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           254:14
   
  --- Logical volume ---
  LV Path                /dev/lvmTPoolVG01/containers_messangers
  LV Name                containers_messangers
  VG Name                lvmTPoolVG01
  LV UUID                8zfgId-l7Kf-3JOp-3YuK-VRbQ-0tNC-n2eXkt
  LV Write Access        read/write
  LV Creation host, time LIVE.ARCH.BOX, 2021-03-14 18:35:46 +0200
  LV Pool name           lvmTPool01
  LV Status              available
  # open                 1
  LV Size                50.00 GB
  Mapped size            19.10%
  Current LE             11921
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           254:17

Thank you in advance for any help!

tomp · March 15, 2021, 10:25am

Please can you enable debug mode:

sudo snap set lxd daemon.debug=true; sudo systemctl reload snap.lxd.daemon

Then run:

sudo tail -f /var/snap/lxd/common/lxd/logs/lxd.log

Then in a separate window re-run your lxc copy command using the --instance-only flag and please show the exact command you run and also show the output of the tail log command once the error occurs. Thanks

diabolusss · March 15, 2021, 8:32pm

$ sudo snap set lxd daemon.debug=true
$ sudo snap restart lxd
$ sudo tail -f /var/snap/lxd/common/lxd/logs/lxd.log

=============================================

$ sudo tail -f /var/snap/lxd/common/lxd/logs/lxd.log
t=2021-03-15T22:10:44+0200 lvl=info msg="Expiring log files" 
t=2021-03-15T22:10:44+0200 lvl=dbug msg="Started task operation: 826c30e6-8d37-4a8d-9cb9-4ef587b6089f" 
t=2021-03-15T22:10:44+0200 lvl=dbug msg="New task Operation: 59841177-e418-4fd1-9830-c6e15444fb1e" 
t=2021-03-15T22:10:44+0200 lvl=info msg="Updating instance types" 
t=2021-03-15T22:10:44+0200 lvl=dbug msg="Started task operation: 59841177-e418-4fd1-9830-c6e15444fb1e" 
t=2021-03-15T22:10:44+0200 lvl=info msg="Done expiring log files" 
t=2021-03-15T22:10:44+0200 lvl=info msg="Done updating instance types" 
t=2021-03-15T22:10:44+0200 lvl=dbug msg="Success for task operation: 826c30e6-8d37-4a8d-9cb9-4ef587b6089f" 
t=2021-03-15T22:10:44+0200 lvl=dbug msg=Handling ip=@ method=GET protocol=unix url=/internal/ready username=root
t=2021-03-15T22:10:48+0200 lvl=dbug msg="Success for task operation: 59841177-e418-4fd1-9830-c6e15444fb1e" 
t=2021-03-15T22:12:13+0200 lvl=dbug msg=Handling ip=@ method=GET protocol=unix url=/1.0 username=colt
t=2021-03-15T22:12:13+0200 lvl=dbug msg=Handling ip=@ method=GET protocol=unix url=/1.0/instances/messangers-arch username=colt
t=2021-03-15T22:12:13+0200 lvl=dbug msg=Handling ip=@ method=GET protocol=unix url=/1.0/events username=colt
t=2021-03-15T22:12:13+0200 lvl=dbug msg="New event listener: ecb89255-ef42-4405-8c58-8a911cb9a154" 
t=2021-03-15T22:12:13+0200 lvl=dbug msg=Handling ip=@ method=POST protocol=unix url=/1.0/instances username=colt
t=2021-03-15T22:12:13+0200 lvl=dbug msg="\n\t{\n\t\t\"architecture\": \"x86_64\",\n\t\t\"config\": {\n\t\t\t\"image.architecture\": \"amd64\",\n\t\t\t\"image.description\": \"Archlinux current amd64 (20201120_04:33)\",\n\t\t\t\"image.os\": \"Archlinux\",\n\t\t\t\"image.release\": \"current\",\n\t\t\t\"image.serial\": \"20201120_04:33\",\n\t\t\t\"image.type\": \"squashfs\",\n\t\t\t\"image.variant\": \"default\",\n\t\t\t\"volatile.base_image\": \"737bda162198539f35db7497ce1bf0e9c1f5a791e59835170b2149a1e94ea21c\"\n\t\t},\n\t\t\"devices\": {\n\t\t\t\"root\": {\n\t\t\t\t\"path\": \"/\",\n\t\t\t\t\"pool\": \"messangersTPool\",\n\t\t\t\t\"type\": \"disk\"\n\t\t\t}\n\t\t},\n\t\t\"ephemeral\": false,\n\t\t\"profiles\": [],\n\t\t\"stateful\": false,\n\t\t\"description\": \"\",\n\t\t\"name\": \"messangers\",\n\t\t\"source\": {\n\t\t\t\"type\": \"copy\",\n\t\t\t\"certificate\": \"\",\n\t\t\t\"base-image\": \"737bda162198539f35db7497ce1bf0e9c1f5a791e59835170b2149a1e94ea21c\",\n\t\t\t\"source\": \"messangers-arch\",\n\t\t\t\"instance_only\": true,\n\t\t\t\"container_only\": true\n\t\t},\n\t\t\"instance_type\": \"\",\n\t\t\"type\": \"container\"\n\t}" 
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Responding to instance create" 
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Skipping key from copy source" instance=messangers key=volatile.eth0.hwaddr project=default sourceInstance=messangers-arch sourceProject=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Skipping key from copy source" instance=messangers key=volatile.idmap.base project=default sourceInstance=messangers-arch sourceProject=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Skipping key from copy source" instance=messangers key=volatile.idmap.next project=default sourceInstance=messangers-arch sourceProject=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Skipping key from copy source" instance=messangers key=volatile.last_state.power project=default sourceInstance=messangers-arch sourceProject=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Skipping key from copy source" instance=messangers key=volatile.idmap.current project=default sourceInstance=messangers-arch sourceProject=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Skipping key from copy source" instance=messangers key=volatile.uuid project=default sourceInstance=messangers-arch sourceProject=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="New task Operation: de98972a-6813-4571-b317-4c19224e0b15" 
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Started task operation: de98972a-6813-4571-b317-4c19224e0b15" 
t=2021-03-15T22:12:13+0200 lvl=dbug msg="\n\t{\n\t\t\"type\": \"async\",\n\t\t\"status\": \"Operation created\",\n\t\t\"status_code\": 100,\n\t\t\"operation\": \"/1.0/operations/de98972a-6813-4571-b317-4c19224e0b15\",\n\t\t\"error_code\": 0,\n\t\t\"error\": \"\",\n\t\t\"metadata\": {\n\t\t\t\"id\": \"de98972a-6813-4571-b317-4c19224e0b15\",\n\t\t\t\"class\": \"task\",\n\t\t\t\"description\": \"Creating instance\",\n\t\t\t\"created_at\": \"2021-03-15T22:12:13.770540111+02:00\",\n\t\t\t\"updated_at\": \"2021-03-15T22:12:13.770540111+02:00\",\n\t\t\t\"status\": \"Running\",\n\t\t\t\"status_code\": 103,\n\t\t\t\"resources\": {\n\t\t\t\t\"containers\": [\n\t\t\t\t\t\"/1.0/containers/messangers\",\n\t\t\t\t\t\"/1.0/containers/messangers-arch\"\n\t\t\t\t],\n\t\t\t\t\"instances\": [\n\t\t\t\t\t\"/1.0/instances/messangers\",\n\t\t\t\t\t\"/1.0/instances/messangers-arch\"\n\t\t\t\t]\n\t\t\t},\n\t\t\t\"metadata\": null,\n\t\t\t\"may_cancel\": false,\n\t\t\t\"err\": \"\",\n\t\t\t\"location\": \"none\"\n\t\t}\n\t}" 
t=2021-03-15T22:12:13+0200 lvl=info msg="Creating container" ephemeral=false instance=messangers instanceType=container project=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg=Handling ip=@ method=GET protocol=unix url=/1.0/operations/de98972a-6813-4571-b317-4c19224e0b15 username=colt
t=2021-03-15T22:12:13+0200 lvl=dbug msg="FillInstanceConfig started" driver=lvm instance=messangers pool=messangersTPool project=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="FillInstanceConfig finished" driver=lvm instance=messangers pool=messangersTPool project=default
t=2021-03-15T22:12:13+0200 lvl=info msg="Created container" ephemeral=false instance=messangers instanceType=container project=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="CreateInstanceFromCopy started" driver=lvm instance=messangers pool=messangersTPool project=default snapshots=false src=messangers-arch
t=2021-03-15T22:12:13+0200 lvl=dbug msg="CreateInstanceFromCopy cross-pool mode detected" driver=lvm instance=messangers pool=messangersTPool project=default snapshots=false src=messangers-arch
t=2021-03-15T22:12:13+0200 lvl=dbug msg="CreateInstanceFromMigration started" args="{Name:messangers Description: Config:map[] Snapshots:[] MigrationType:{FSType:RSYNC Features:[xattrs delete compress bidirectional]} TrackProgress:false Refresh:false Live:false VolumeSize:0 ContentType:}" driver=lvm instance=messangers pool=messangersTPool project=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="MigrateInstance started" args="&{Name:messangers-arch Snapshots:[] MigrationType:{FSType:RSYNC Features:[xattrs delete compress bidirectional]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType:}" driver=btrfs instance=messangers-arch pool=messangers-arch project=default
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Sending filesystem volume" bwlimit= driver=btrfs path=/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/ pool=messangers-arch rsyncArgs=[] volName=messangers-arch
t=2021-03-15T22:12:13+0200 lvl=dbug msg="Database error: &errors.errorString{s:\"No such object\"}" 
t=2021-03-15T22:12:40+0200 lvl=dbug msg="Logical volume created" driver=lvm fs=ext4 lv_name=containers_messangers pool=messangersTPool size=20000000000b vg_name=messangersTPoolVG
t=2021-03-15T22:12:40+0200 lvl=dbug msg="Mounted logical volume" dev=/dev/messangersTPoolVG/containers_messangers driver=lvm options=discard path=/var/snap/lxd/common/lxd/storage-pools/messangersTPool/containers/messangers pool=messangersTPool
t=2021-03-15T22:12:40+0200 lvl=dbug msg="Unmounted logical volume" driver=lvm keepBlockDev=false path=/var/snap/lxd/common/lxd/storage-pools/messangersTPool/containers/messangers pool=messangersTPool
t=2021-03-15T22:12:40+0200 lvl=dbug msg="Deactivated logical volume" dev=/dev/messangersTPoolVG/containers_messangers driver=lvm pool=messangersTPool
t=2021-03-15T22:12:40+0200 lvl=dbug msg="Activated logical volume" dev=/dev/messangersTPoolVG/containers_messangers driver=lvm pool=messangersTPool
t=2021-03-15T22:12:40+0200 lvl=dbug msg="Mounted logical volume" dev=/dev/messangersTPoolVG/containers_messangers driver=lvm options=discard path=/var/snap/lxd/common/lxd/storage-pools/messangersTPool/containers/messangers pool=messangersTPool
t=2021-03-15T22:12:40+0200 lvl=dbug msg="Receiving filesystem volume" driver=lvm path=/var/snap/lxd/common/lxd/storage-pools/messangersTPool/containers/messangers/ pool=messangersTPool volName=messangers
t=2021-03-15T22:12:40+0200 lvl=dbug msg="Updated metadata for task Operation: de98972a-6813-4571-b317-4c19224e0b15" 
t=2021-03-15T22:12:41+0200 lvl=dbug msg="Updated metadata for task Operation: de98972a-6813-4571-b317-4c19224e0b15" 
... same msg for n times ...
t=2021-03-15T22:19:17+0200 lvl=dbug msg="Updated metadata for task Operation: de98972a-6813-4571-b317-4c19224e0b15" 
t=2021-03-15T22:19:18+0200 lvl=dbug msg="MigrateInstance finished" args="&{Name:messangers-arch Snapshots:[] MigrationType:{FSType:RSYNC Features:[xattrs delete compress bidirectional]} TrackProgress:true MultiSync:false FinalSync:false Data:<nil> ContentType:}" driver=btrfs instance=messangers-arch pool=messangers-arch project=default
t=2021-03-15T22:20:25+0200 lvl=dbug msg="Unmounted logical volume" driver=lvm keepBlockDev=false path=/var/snap/lxd/common/lxd/storage-pools/messangersTPool/containers/messangers pool=messangersTPool
t=2021-03-15T22:20:25+0200 lvl=dbug msg="Deactivated logical volume" dev=/dev/messangersTPoolVG/containers_messangers driver=lvm pool=messangersTPool
t=2021-03-15T22:20:26+0200 lvl=dbug msg="Logical volume removed" dev=/dev/messangersTPoolVG/containers_messangers driver=lvm pool=messangersTPool
t=2021-03-15T22:20:26+0200 lvl=dbug msg="DeleteInstance started" driver=lvm instance=messangers pool=messangersTPool project=default
t=2021-03-15T22:20:26+0200 lvl=dbug msg="Deleting instance volume" driver=lvm instance=messangers pool=messangersTPool project=default volName=messangers
t=2021-03-15T22:20:26+0200 lvl=dbug msg="DeleteInstance finished" driver=lvm instance=messangers pool=messangersTPool project=default
t=2021-03-15T22:20:26+0200 lvl=dbug msg="CreateInstanceFromMigration finished" args="{Name:messangers Description: Config:map[] Snapshots:[] MigrationType:{FSType:RSYNC Features:[xattrs delete compress bidirectional]} TrackProgress:false Refresh:false Live:false VolumeSize:0 ContentType:}" driver=lvm instance=messangers pool=messangersTPool project=default
t=2021-03-15T22:20:26+0200 lvl=dbug msg="DeleteInstance started" driver=lvm instance=messangers pool=messangersTPool project=default
t=2021-03-15T22:20:26+0200 lvl=dbug msg="Deleting instance volume" driver=lvm instance=messangers pool=messangersTPool project=default volName=messangers
t=2021-03-15T22:20:26+0200 lvl=dbug msg="Database error: &errors.errorString{s:\"No such object\"}" 
t=2021-03-15T22:20:26+0200 lvl=dbug msg="DeleteInstance finished" driver=lvm instance=messangers pool=messangersTPool project=default
t=2021-03-15T22:20:26+0200 lvl=dbug msg="CreateInstanceFromCopy finished" driver=lvm instance=messangers pool=messangersTPool project=default snapshots=false src=messangers-arch
t=2021-03-15T22:20:26+0200 lvl=info msg="Deleting container" created=2021-03-15T22:12:13+0200 ephemeral=false instance=messangers instanceType=container project=default used=1970-01-01T03:00:00+0300
t=2021-03-15T22:20:26+0200 lvl=dbug msg="Database error: &errors.errorString{s:\"No such object\"}" 
t=2021-03-15T22:20:26+0200 lvl=info msg="Deleted container" created=2021-03-15T22:12:13+0200 ephemeral=false instance=messangers instanceType=container project=default used=1970-01-01T03:00:00+0300
t=2021-03-15T22:20:26+0200 lvl=dbug msg="Failure for task operation: de98972a-6813-4571-b317-4c19224e0b15: Create instance from copy: Create instance volume from copy failed: [Rsync send failed: messangers-arch, /var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/: [exit status 23 read unix @lxd/6bdafc0d-01ab-48c0-938b-53a8682a0229->@: use of closed network connection] (rsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/colt/.config/opera/Service Worker/CacheStorage/579544fd7d0441717f082c9eb123588966aa57ac/8ef64737-bd09-4e73-9268-11e4e42b98c4/67c8aea7a5b97064_0\": Input/output error (5)\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/colt/.config/opera/Service Worker/CacheStorage/efb5023a1630344583faab602ea42e0ca473b65d/6bc2892c-701d-4187-8ba3-82e6155e8b99/17cc61884630086e_1\": Input/output error (5)\nWARNING: rootfs/home/colt/.config/opera/Service Worker/CacheStorage/579544fd7d0441717f082c9eb123588966aa57ac/8ef64737-bd09-4e73-9268-11e4e42b98c4/67c8aea7a5b97064_0 failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/colt/.config/opera/Service Worker/CacheStorage/579544fd7d0441717f082c9eb123588966aa57ac/8ef64737-bd09-4e73-9268-11e4e42b98c4/67c8aea7a5b97064_0\": Input/output error (5)\nWARNING: rootfs/home/colt/.config/opera/Service Worker/CacheStorage/efb5023a1630344583faab602ea42e0ca473b65d/6bc2892c-701d-4187-8ba3-82e6155e8b99/17cc61884630086e_1 failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/colt/.config/opera/Service Worker/CacheStorage/efb5023a1630344583faab602ea42e0ca473b65d/6bc2892c-701d-4187-8ba3-82e6155e8b99/17cc61884630086e_1\": Input/output error (5)\nERROR: rootfs/home/colt/.config/opera/Service Worker/CacheStorage/579544fd7d0441717f082c9eb123588966aa57ac/8ef64737-bd09-4e73-9268-11e4e42b98c4/67c8aea7a5b97064_0 failed verification -- update discarded.\nERROR: rootfs/home/colt/.config/opera/Service Worker/CacheStorage/efb5023a1630344583faab602ea42e0ca473b65d/6bc2892c-701d-4187-8ba3-82e6155e8b99/17cc61884630086e_1 failed verification -- update discarded.\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.cache/mozilla/firefox/c7bzoruj.default-release/cache2/entries/3E1E786DB396415EE9C929E201DCC1989AF4805C\": Input/output error (5)\nWARNING: rootfs/home/ubuntu/.cache/mozilla/firefox/c7bzoruj.default-release/cache2/entries/3E1E786DB396415EE9C929E201DCC1989AF4805C failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.cache/mozilla/firefox/c7bzoruj.default-release/cache2/entries/3E1E786DB396415EE9C929E201DCC1989AF4805C\": Input/output error (5)\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.cache/thunderbird/tl012p50.default/cache2/entries/26F2934535ABE6B0B451DE3DC7BD2779A29E2CD4\": Input/output error (5)\nERROR: rootfs/home/ubuntu/.cache/mozilla/firefox/c7bzoruj.default-release/cache2/entries/3E1E786DB396415EE9C929E201DCC1989AF4805C failed verification -- update discarded.\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/Microsoft/Microsoft Teams/old_logs_20210110183021.txt\": Input/output error (5)\nWARNING: rootfs/home/ubuntu/.cache/thunderbird/tl012p50.default/cache2/entries/26F2934535ABE6B0B451DE3DC7BD2779A29E2CD4 failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.cache/thunderbird/tl012p50.default/cache2/entries/26F2934535ABE6B0B451DE3DC7BD2779A29E2CD4\": Input/output error (5)\nWARNING: rootfs/home/ubuntu/.config/Microsoft/Microsoft Teams/old_logs_20210110183021.txt failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/Microsoft/Microsoft Teams/old_logs_20210110183021.txt\": Input/output error (5)\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/opera/History\": Input/output error (5)\nERROR: rootfs/home/ubuntu/.cache/thunderbird/tl012p50.default/cache2/entries/26F2934535ABE6B0B451DE3DC7BD2779A29E2CD4 failed verification -- update discarded.\nERROR: rootfs/home/ubuntu/.config/Microsoft/Microsoft Teams/old_logs_20210110183021.txt failed verification -- update discarded.\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/opera/Local Extension Settings/kccohkcpppjjkkjppopfnflnebibpida/000527.ldb\": Input/output error (5)\nWARNING: rootfs/home/ubuntu/.config/opera/History failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/opera/History\": Input/output error (5)\nWARNING: rootfs/home/ubuntu/.config/opera/Local Extension Settings/kccohkcpppjjkkjppopfnflnebibpida/000527.ldb failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/opera/Local Extension Settings/kccohkcpppjjkkjppopfnflnebibpida/000527.ldb\": Input/output error (5)\nERROR: rootfs/home/ubuntu/.config/opera/History failed verification -- update discarded.\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/3be61d81a0976669_0\": Input/output error (5)\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/73e9b0021fae97a4_0\": Input/output error (5)\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/f5135f83e9b23320_0\": Input/output error (5)\nERROR: rootfs/home/ubuntu/.config/opera/Local Extension Settings/kccohkcpppjjkkjppopfnflnebibpida/000527.ldb failed verification -- update discarded.\nWARNING: rootfs/home/ubuntu/.config/skypeforlinux/Cache/3be61d81a0976669_0 failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/3be61d81a0976669_0\": Input/output error (5)\nWARNING: rootfs/home/ubuntu/.config/skypeforlinux/Cache/73e9b0021fae97a4_0 failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/73e9b0021fae97a4_0\": Input/output error (5)\nWARNING: rootfs/home/ubuntu/.config/skypeforlinux/Cache/f5135f83e9b23320_0 failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/home/ubuntu/.config/skypeforlinux/Cache/f5135f83e9b23320_0\": Input/output error (5)\nERROR: rootfs/home/ubuntu/.config/skypeforlinux/Cache/3be61d81a0976669_0 failed verification -- update discarded.\nERROR: rootfs/home/ubuntu/.config/skypeforlinux/Cache/73e9b0021fae97a4_0 failed verification -- update discarded.\nERROR: rootfs/home/ubuntu/.config/skypeforlinux/Cache/f5135f83e9b23320_0 failed verification -- update discarded.\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/var/cache/man/sv/index.db\": Input/output error (5)\nWARNING: rootfs/var/cache/man/sv/index.db failed verification -- update discarded (will try again).\nrsync: read errors mapping \"/var/snap/lxd/common/lxd/storage-pools/messangers-arch/containers/messangers-arch/rootfs/var/cache/man/sv/index.db\": Input/output error (5)\nERROR: rootfs/var/cache/man/sv/index.db failed verification -- update discarded.\nrsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1196) [sender=3.1.2]\n) Rsync receive failed: /var/snap/lxd/common/lxd/storage-pools/messangersTPool/containers/messangers/: [exit status 23] ()]" 
t=2021-03-15T22:20:26+0200 lvl=dbug msg="Event listener finished: ecb89255-ef42-4405-8c58-8a911cb9a154" 
t=2021-03-15T22:20:26+0200 lvl=dbug msg="Disconnected event listener: ecb89255-ef42-4405-8c58-8a911cb9a154"

$ lxc copy messangers-arch messangers --storage=messangersTPool --instance-only --no-profiles

Lvm size at time of receiving message “MigrateInstance finished” (t=2021-03-15T22:19:18+0200)
sudo lvdisplay messangersTPoolVG --units G

  --- Logical volume ---
  LV Name                messangersTPool
  VG Name                messangersTPoolVG
  LV UUID                avtsx2-dJkY-8zOX-UpqM-o6vM-gWOv-ezthDC
  LV Write Access        read/write (activated read only)
  LV Creation host, time LIVE.ARCH.BOX, 2021-03-13 21:18:08 +0200
  LV Pool metadata       messangersTPool_tmeta
  LV Pool data           messangersTPool_tdata
  LV Status              available
  # open                 2
  LV Size                19.32 GB
  Allocated pool data    45.55%
  Allocated metadata     1.96%
  Current LE             4607
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           254:15
   
  --- Logical volume ---
  LV Path                /dev/messangersTPoolVG/containers_messangers
  LV Name                containers_messangers
  VG Name                messangersTPoolVG
  LV UUID                pmO1lB-ijB7-5o6w-H9dU-763L-1l31-uuCaHu
  LV Write Access        read/write
  LV Creation host, time LIVE.ARCH.BOX, 2021-03-15 22:12:14 +0200
  LV Pool name           messangersTPool
  LV Status              available
  # open                 1
  LV Size                20.00 GB
  Mapped size            43.13%
  Current LE             4769
  Segments               1
  Allocation             inherit
  Read ahead sectors     auto
  - currently set to     256
  Block device           254:17

And progress continued some time after that for ~7%. Finally error was thrown.

tomp · March 16, 2021, 9:46am

Thanks.

When this happens is there anything in sudo dmesg or sudo journalctl about LVM disk space running out?

diabolusss · March 16, 2021, 11:07am

No, not at all. But, sadly, i have found out that there is something wrong with btrfs image pool.
Dmesg is spammed with this errors every 5 seconds nonstop…

Mar 16 09:27:36 LIVE.ARCH.BOX lxd.daemon[1098]: t=2021-03-16T09:27:36+0200 lvl=dbug msg="Initializing and checking storage pool \"messangers-arch\""
Mar 16 09:27:36 LIVE.ARCH.BOX lxd.daemon[1098]: t=2021-03-16T09:27:36+0200 lvl=dbug msg="Mount started" driver=btrfs pool=messangers-arch
Mar 16 09:27:36 LIVE.ARCH.BOX kernel: BTRFS: device label messangers-arch devid 1 transid 137297 /dev/loop9 scanned by lxd (1098)
Mar 16 09:27:36 LIVE.ARCH.BOX kernel: BTRFS info (device loop9): disk space caching is enabled
Mar 16 09:27:36 LIVE.ARCH.BOX kernel: BTRFS info (device loop9): has skinny extents
Mar 16 09:27:36 LIVE.ARCH.BOX kernel: BTRFS info (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143283, gen 0
Mar 16 09:27:36 LIVE.ARCH.BOX lxd.daemon[1098]: t=2021-03-16T09:27:36+0200 lvl=dbug msg="Mount finished" driver=btrfs pool=messangers-arch

Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143284, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143285, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143286, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143287, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143288, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143289, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143290, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143291, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143292, gen 0
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054143293, gen 0

Mar 16 09:32:11 LIVE.ARCH.BOX lxd.daemon[1098]: t=2021-03-16T09:32:11+0200 lvl=info msg="Started container" action=start created=2020-11-20T18:48:14+0200 ephemeral=false instance=messangers-arch instanceType=container project=default stateful=false used=2021-03-15T22:26:54+0200

Mar 16 09:32:15 LIVE.ARCH.BOX kernel: btrfs_print_data_csum_error: 47174 callbacks suppressed
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: btrfs_dev_stat_print_on_error: 47174 callbacks suppressed
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190468, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190469, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190470, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190471, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190472, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190473, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190474, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190475, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1054190476, gen 0
Mar 16 09:32:15 LIVE.ARCH.BOX kernel: BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1



Mar 16 10:43:50 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1299993001, gen 0
Mar 16 10:43:50 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1299993002, gen 0
Mar 16 10:43:50 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1299993003, gen 0
Mar 16 10:43:50 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1299993004, gen 0
Mar 16 10:43:50 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1299993005, gen 0
Mar 16 10:43:50 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1299993006, gen 0
Mar 16 10:43:50 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1299993007, gen 0
Mar 16 10:43:50 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1299993008, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304270, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304271, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304272, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304273, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304274, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304275, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304276, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304277, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304278, gen 0
Mar 16 10:43:55 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300304279, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600040, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600041, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600042, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600043, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600044, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600045, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600046, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600047, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600048, gen 0
Mar 16 10:44:00 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300600049, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907378, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907379, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907380, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907381, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907382, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907383, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907384, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907385, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907386, gen 0
Mar 16 10:44:05 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1300907387, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202128, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202129, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202130, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202131, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202132, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202133, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202134, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202135, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202136, gen 0
Mar 16 10:44:10 LIVE.ARCH.BOX kernel: BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 1301202137, gen 0

[12824.474762] btrfs_dev_stat_print_on_error: 257632 callbacks suppressed
[12829.478109] btrfs_print_data_csum_error: 269633 callbacks suppressed
[12829.478113] btrfs_dev_stat_print_on_error: 269633 callbacks suppressed
[12834.481490] btrfs_print_data_csum_error: 276269 callbacks suppressed
[12834.481499] btrfs_dev_stat_print_on_error: 276269 callbacks suppressed
[12839.484853] btrfs_print_data_csum_error: 260803 callbacks suppressed
[12839.484862] btrfs_dev_stat_print_on_error: 260803 callbacks suppressed
[12844.488214] btrfs_print_data_csum_error: 240463 callbacks suppressed
[12844.488219] btrfs_dev_stat_print_on_error: 240463 callbacks suppressed
[12849.491591] btrfs_print_data_csum_error: 273118 callbacks suppressed
[12849.491597] btrfs_dev_stat_print_on_error: 273118 callbacks suppressed
[12854.494954] btrfs_print_data_csum_error: 277447 callbacks suppressed
[12854.494964] btrfs_dev_stat_print_on_error: 277447 callbacks suppressed
[12859.498329] btrfs_print_data_csum_error: 261014 callbacks suppressed
[12859.498339] btrfs_dev_stat_print_on_error: 261014 callbacks suppressed
[12864.501705] btrfs_print_data_csum_error: 251457 callbacks suppressed
[12864.501709] btrfs_dev_stat_print_on_error: 251457 callbacks suppressed
[12869.505051] btrfs_print_data_csum_error: 220975 callbacks suppressed
[12869.505055] btrfs_dev_stat_print_on_error: 220975 callbacks suppressed
[12874.508418] btrfs_print_data_csum_error: 220016 callbacks suppressed
[12874.508431] btrfs_dev_stat_print_on_error: 220016 callbacks suppressed
[12879.511788] btrfs_print_data_csum_error: 220732 callbacks suppressed
[12879.511796] btrfs_dev_stat_print_on_error: 220732 callbacks suppressed
[12884.515145] btrfs_print_data_csum_error: 235139 callbacks suppressed

tomp · March 16, 2021, 11:55am

Oh yes that doesn’t look good, and will most likely explain the rsync errors too. Have you rebooted that machine recently?

diabolusss · March 16, 2021, 1:53pm

I start it afresh every day. And it works like a clock.
I have rebooted it a few days ago when tried to export, and manually removed some profiles from it (lxc profile remove).

I’ll try to export it as image and import back into new storage.

UPD1
I have managed to export almost all snapshots, but the last one results in i/o error.
I’ll try to delete files listed in error, maybe it will help to solve this problem.

UPD2
Removing files listed in error helped to successfully complete migration. Now I can easily export --instance-only and snapshots not affected by these files.
The last snapshot has faulty files, which means that they don’t interfere with snapshot creation, but mainly disturbs rsync work.

Thus, I think that it would be useful to add the option for lxd rsync to --exclude-dirs and --exclude-files as a possible workaround.

And another strange thing is with btrfs pool csum error - dmesg is full of errors and warnings, but lxd on its own doesn’t warn that i’m running containers on faulty pool.

I believe that lxd should warn the user on any action with such faulty pool.

Anyway, thank you, @tomp, for pointing me in the right direction.

tomp · March 17, 2021, 10:15am

If the btrfs CLI tools we use to perform BTRFS volume operations don’t report an error then LXD cannot know there is a problem with the volume. It sounds like there has been some corruption to your loop file at some point, perhaps a system crash/power loss or disk issue.

diabolusss · March 17, 2021, 11:45am

I can’t argue with that, but the fact is that the first error gets caught right at the moment of mounting device:

Mar 17 08:18:57 LIVE.ARCH.BOX lxd.daemon[1084]: t=2021-03-17T08:18:57+0200 lvl=dbug msg="Initializing and checking storage pool \"messangers-arch\""
Mar 17 08:18:57 LIVE.ARCH.BOX lxd.daemon[1084]: t=2021-03-17T08:18:57+0200 lvl=dbug msg="Mount started" driver=btrfs pool=messangers-arch
Mar 17 08:18:58 LIVE.ARCH.BOX kernel: BTRFS: device label messangers-arch devid 1 transid 138506 /dev/loop9 scanned by lxd (1090)
Mar 17 08:18:58 LIVE.ARCH.BOX kernel: BTRFS info (device loop9): disk space caching is enabled
Mar 17 08:18:58 LIVE.ARCH.BOX kernel: BTRFS info (device loop9): has skinny extents
Mar 17 08:18:59 LIVE.ARCH.BOX kernel: BTRFS info (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 3764750118, gen 0
Mar 17 08:18:59 LIVE.ARCH.BOX lxd.daemon[1084]: t=2021-03-17T08:18:59+0200 lvl=dbug msg="Mount finished" driver=btrfs pool=messangers-arch

I believe that this information can be used and possibly retrieved even with BTRFS CLI tools, because somehow it gets printed into logs. Maybe it stays unnoticed because BTRFS marks it incorrectly at mount stage as in journal it’s printed with INFO level. Only some time after logs get spammed with warning & error messages.

[ 3863.115331] BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1
[ 3863.115333] BTRFS error (device loop9): bdev /dev/loop9 errs: wr 0, rd 0, flush 0, corrupt 3927761390, gen 0
[ 3863.115357] BTRFS warning (device loop9): csum failed root 259 ino 1129170 off 8192 csum 0x873b3747 expected csum 0x40f72b0f mirror 1

tomp · March 20, 2021, 5:58am

@stgraber mentioned btrfs scrub start which may be useful for you:

diabolusss · March 20, 2021, 11:10am

Thank you, @stgraber and @tomp for mentioning this utility. I have tried that and received bad news:

    UUID:             6692850c-1e88-436c-a960-65a041c1c658
Scrub started:    Sat Mar 20 11:44:29 2021
Status:           finished
Duration:         0:01:50
Total to scrub:   13.38GiB
Rate:             124.59MiB/s
Error summary:    csum=29
  Corrected:      0
  Uncorrectable:  29
  Unverified:     0

However, to bulletproof that the cause is really fs, i have:

created new snapshot after removing mentioned buggy files
reverted to previous non failure snapshot (the one that i’ve managed to export with no errors)
successfully exported it with --instance-only, but failed on full export
the funniest thing is that errors was reported to a recent new snapshot, not the one was reported earlier, so i’ve removed all new snapshots and all previous ones left intact (my mistake here was that i’ve removed fixed snapshot… but luckily i’ve exported it earlier)
and full export finished with success with no btrfs errors.
finally i rerun btrfs scan and problem was gone.

sudo  btrfs scrub start -B  /mnt
scrub done for 6692850c-1e88-436c-a960-65a041c1c658
Scrub started:    Sat Mar 20 12:59:08 2021
Status:           finished
Duration:         0:00:23
Total to scrub:   17.52GiB
Rate:             315.48MiB/s
Error summary:    no errors found

So is it really a buggy fs or just a rsync failure - file size mismatch at validation?

tomp · March 22, 2021, 9:00am

If btrfs scrub is reporting errors then its an FS issue and not rsync, although rsync may have been triggering the operation that made BTRFS detect the csum error.