Open Atemu opened 6 years ago
Zygo
commented
6 years ago What are your mount options for this filesystem?
If they include nodatacow then setting the compression bit won't work...but dedup overrides nodatacow, so it doesn't make sense to use both on the same filesystem.
Atemu
commented
6 years ago My mount options are rw,relatime,compress=zstd,space_cache,subvolid=5,subvol=/
Atemu
commented
6 years ago Is there anything else thay could cause these exceptions?
Was my setup wrong maybe? Because I'm pretty sure I did it wrong.
businessBoris
commented
6 years ago @Atemu Is your subvol really called "5"? With id of 5? The root subvol is usually id 5, I think and that is never called "5".
Zygo
commented
6 years ago subvol=5 is definitely wrong (subvol ID 5 is never named "5", so either subvol is wrong or subvolid is wrong); however, I don't see how it causes the reported problems. If both options are given I think btrfs just ignores subvol=5.
Could you try stat -f -c %T /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/ and see if it says "btrfs"? Some of the errors could occur if the filesystem was not mounted at that mount point; however, if the filesystem was not mounted there, then the rest of the btrfs ioctls should also be failing, and it appears they are not failing (it is still finding extents and opening files).
So I don't really know what is going on here.
Zygo
commented
6 years ago You could try commenting out the line ioctl_iflags_set(m_fd, flags); in src/bees.cc and see if the exception goes away, or if it starts failing somehere else. That might provide a clue if nothing else.
Atemu
commented
6 years ago @Atemu Is your subvol really called "5"? With id of 5?
Nope, that's a typo, my bad!
I edited my comment and copied the mount options out of /etc/fstab this time.
@Zygo I'll try that, thanks
Atemu
commented
6 years ago Could you try stat -f -c %T /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/ and see if it says "btrfs"?
When I cancel the process it says tmpfs but and the dir is empty when I stat while it's running it says btrfs and the dir contains the content of /.
Atemu
commented
6 years ago I forked the repo, uncommented the line, edited the PKGBUILD for the AUR package to use my fork, ran makepkg -si and here's what I get now:
[atemu@HEPHAISTOS ~]$ sudo beesd 8d2b3f38-f8ac-4ab3-948b-767c1b10741f
INFO: Find 8d2b3f38-f8ac-4ab3-948b-767c1b10741f in //etc/bees//beesd.conf, use as conf
INFO: Check: Disk exists
INFO: Check: Disk with btrfs
INFO: WORK DIR: /run/bees/
INFO: MOUNT DIR: /run/bees//mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f
bees version v0.5-126-g239baa6
2018-05-01 16:19:41 18139.18139<6> bees: setting rlimit NOFILE to 10340
2018-05-01 16:19:41 18139.18139<6> bees: set_root_path /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f
2018-05-01 16:19:41 18139.18139<6> bees: set_root_fd /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f
2018-05-01 16:19:41 18139.18139<6> bees: Filesystem UUID is 8d2b3f38-f8ac-4ab3-948b-767c1b10741f
2018-05-01 16:19:41 18139.18139<6> bees: BeesStringFile /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beescrawl.dat max size 1M
2018-05-01 16:19:41 18139.18139<7> bees: BeesThread exec crawl_transid
2018-05-01 16:19:41 18139.18139<6> bees: returning from set_root_fd in /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f
2018-05-01 16:19:41 18139.18139<7> bees: BeesThread construct status
2018-05-01 16:19:41 18139.18139<7> bees: BeesThread exec status
2018-05-01 16:19:41 18139.18152<7> crawl_transid: Starting thread crawl_transid
2018-05-01 16:19:41 18139.18153<7> status: Starting thread status
2018-05-01 16:19:41 18139.18153<6> status: Writing status to file '/run/bees//8d2b3f38-f8ac-4ab3-948b-767c1b10741f.status' every 1 sec
2018-05-01 16:19:41 18139.18152<6> crawl_transid: loading crawl state
2018-05-01 16:19:41 18139.18152<7> crawl_transid: BeesThread exec crawl_writeback
2018-05-01 16:19:41 18139.18154<7> crawl_writeback: Starting thread crawl_writeback
2018-05-01 16:19:41 18139.18154<6> crawl_writeback: Saving crawl state
2018-05-01 16:19:41 18139.18154<6> crawl_writeback: Nothing to save
2018-05-01 16:19:41 18139.18152<6> crawl_transid: Crawl master resumed after 0.00600173s at transid 83328
2018-05-01 16:19:41 18139.18152<7> crawl_transid: Polling 9.99802s for next 10 transid RateEstimator { count = 83328, raw = 0 / 0.00405875, ratio = 1 / 1, rate = 1, duration(1) = 1, seconds_for(1) = 1 }
2018-05-01 16:19:41 18139.18145<6> crawl_master: Crawl finished BeesCrawlState 258:256 offset 0x45922147 transid 0..83328 started 2018-05-01-16-19-41 (0s ago)
2018-05-01 16:19:41 18139.18141<6> crawl_9927: BeesStringFile /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beesstats.txt max size 1M
2018-05-01 16:19:41 18139.18141<6> crawl_9927: opened hash table filename 'beeshash.dat' length 1073741824
2018-05-01 16:19:41 18139.18141<6> crawl_9927: cells 67108864, buckets 262144, extents 64
2018-05-01 16:19:41 18139.18141<6> crawl_9927: flush rate limit 1.19305e+06
2018-05-01 16:19:41 18139.18141<6> crawl_9927: mapping hash table size 1073741824 with flags MAP_PRIVATE|MAP_ANONYMOUS
2018-05-01 16:19:41 18139.18141<6> crawl_9927: mmap done in 0.001 sec
2018-05-01 16:19:41 18139.18141<7> crawl_9927: BeesThread exec hash_writeback
2018-05-01 16:19:41 18139.18141<7> crawl_9927: BeesThread exec hash_prefetch
2018-05-01 16:19:41 18139.18155<7> hash_writeback: Starting thread hash_writeback
2018-05-01 16:19:41 18139.18141<7> crawl_9927: Adding 9927:257 to blacklist
2018-05-01 16:19:41 18139.18156<7> hash_prefetch: Starting thread hash_prefetch
2018-05-01 16:19:41 18139.18147<6> crawl_9927: copy: 128K [0x3100000..0x3120000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18142<6> crawl_9927: copy: 128K [0x30e0000..0x3100000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18141<6> crawl_9927: copy: 128K [0x3080000..0x30a0000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18143<6> crawl_9927: copy: 128K [0x30a0000..0x30c0000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18150<6> crawl_9927: copy: 128K [0x3060000..0x3080000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18144<6> crawl_9927: copy: 128K [0x30c0000..0x30e0000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18140<6> crawl_9927: copy: 128K [0x3020000..0x3040000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18146<6> crawl_9927: copy: 128K [0x3040000..0x3060000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18149<6> crawl_9927: copy: 128K [0x3140000..0x3160000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18148<6> crawl_9927: copy: 128K [0x3120000..0x3140000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18151<6> crawl_9927: copy: 128K [0x3000000..0x3020000] fd = 6 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat'
2018-05-01 16:19:41 18139.18145<6> crawl_master: Crawl finished BeesCrawlState 9927:259 offset 0x101 transid 0..83328 started 2018-05-01-16-19-41 (0s ago)
2018-05-01 16:19:41 18139.18141<6> crawl_9927: scan: 128K 0x3080000 [++++++++++++++++++++++++++++++++] 0x30a0000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18147<6> crawl_9927: scan: 128K 0x3100000 [++++++++++++++++++++++++++++++++] 0x3120000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18150<6> crawl_9927: scan: 128K 0x3060000 [++++++++++++++++++++++++++++++++] 0x3080000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18142<6> crawl_9927: scan: 128K 0x30e0000 [++++++++++++++++++++++++++++++++] 0x3100000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18144<6> crawl_9927: scan: 128K 0x30c0000 [++++++++++++++++++++++++++++++++] 0x30e0000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18143<6> crawl_9927: scan: 128K 0x30a0000 [++++++++++++++++++++++++++++++++] 0x30c0000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18149<6> crawl_9927: scan: 128K 0x3140000 [++++++++++++++++++++++++++++++++] 0x3160000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18140<6> crawl_9927: scan: 128K 0x3020000 [++++++++++++++++++++++++++++++++] 0x3040000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18146<6> crawl_9927: scan: 128K 0x3040000 [++++++++++++++++++++++++++++++++] 0x3060000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18151<6> crawl_9927: scan: 128K 0x3000000 [++++++++++++++++++++++++++++++++] 0x3020000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18148<6> crawl_9927: scan: 128K 0x3120000 [++++++++++++++++++++++++++++++++] 0x3140000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/.beeshome/beeshash.dat
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: Now: 2018-05-01-16-19-41
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: Uptime: 0.430483 seconds
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: Version: v0.5-126-g239baa6
2018-05-01 16:19:41 18139.18156<6> hash_prefetch:
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: Hash table page occupancy histogram (8083/67108864 cells occupied, 0%)
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: 262144 pages
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 131072
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 65536
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 32768
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 16384
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 8192
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 4096
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 2048
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 1024
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 512
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 256
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 128
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 64
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 32
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 16
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 8
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 4
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: # 2
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: ## 1
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: 0% | 25% | 50% | 75% | 100% page fill
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: compressed 355 (4%)
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: uncompressed 7728 (95%) unaligned_eof 53 (0%) toxic 0 (0%)
2018-05-01 16:19:41 18139.18156<6> hash_prefetch:
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: TOTAL:
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: addr_block=14405 addr_compressed_offset=930 addr_eof_e=90 addr_from_fd=11 addr_ms=26 addr_uncompressed=13475
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: block_bytes=63085452 block_hash=14042 block_read=15450 block_zero=1056
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: crawl_create=3 crawl_empty=2 crawl_gen_high=1 crawl_hole=7 crawl_inline=24 crawl_items=61063 crawl_nondata=60306 crawl_push=724 crawl_scan=719 crawl_search=64
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: dedup_copy=1441792
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: hash_already=114 hash_bump=122 hash_extent_in=64 hash_extent_out=1 hash_insert=13525 hash_lookup=13688
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: inserted_block=13638
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: matched_0=13688
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: open_file=95 open_hit=95 open_ino_ms=4 open_lookup_ok=95
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: replacesrc_try=11
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: resolve_ms=2 resolve_ok=11
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: root_found=1 root_ok=1 root_parent_open_ok=1 root_parent_open_try=1
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: scan_blacklisted=373 scan_block=14042 scan_extent=266 scan_forward=647 scan_found=237 scan_hash_preinsert=14041 scan_lookup=13688 scan_rewrite=11 scan_twice=237 scan_zero_compressed=11
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: scanf_extent=263 scanf_extent_ms=4372 scanf_total=263 scanf_total_ms=4582
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: tmp_aligned=11 tmp_block_zero=352 tmp_copy=11 tmp_copy_ms=8 tmp_create=11 tmp_resize=11
2018-05-01 16:19:41 18139.18156<6> hash_prefetch:
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: RATES:
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: addr_block=33456.2 addr_compressed_offset=2159.96 addr_eof_e=209.029 addr_from_fd=25.548 addr_ms=60.387 addr_uncompressed=31296.2
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: block_bytes=1.46518e+08 block_hash=32613.1 block_read=35883.2 block_zero=2452.6
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: crawl_create=6.968 crawl_empty=4.646 crawl_gen_high=2.323 crawl_hole=16.258 crawl_inline=55.741 crawl_items=141821 crawl_nondata=140063 crawl_push=1681.52 crawl_scan=1669.91 crawl_search=148.643
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: dedup_copy=3.34862e+06
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: hash_already=264.77 hash_bump=283.35 hash_extent_in=148.643 hash_extent_out=2.323 hash_insert=31412.4 hash_lookup=31790.9
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: inserted_block=31674.8
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: matched_0=31790.9
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: open_file=220.642 open_hit=220.642 open_ino_ms=9.291 open_lookup_ok=220.642
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: replacesrc_try=25.548
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: resolve_ms=4.646 resolve_ok=25.548
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: root_found=2.323 root_ok=2.323 root_parent_open_ok=2.323 root_parent_open_try=2.323
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: scan_blacklisted=866.308 scan_block=32613.1 scan_extent=617.796 scan_forward=1502.68 scan_found=550.442 scan_hash_preinsert=32610.8 scan_lookup=31790.9 scan_rewrite=25.548 scan_twice=550.442 scan_zero_compressed=25.548
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: scanf_extent=610.829 scanf_extent_ms=10154.1 scanf_total=610.829 scanf_total_ms=10641.9
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: tmp_aligned=25.548 tmp_block_zero=817.535 tmp_copy=25.548 tmp_copy_ms=18.581 tmp_create=25.548 tmp_resize=25.548
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: mlock(1G)...
2018-05-01 16:19:41 18139.18156<6> hash_prefetch: mlock(1G) done in 0.001 sec
2018-05-01 16:19:41 18139.18142<6> crawl_5: copy: 16K [0x5000..0x9000] fd = 115 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog'
2018-05-01 16:19:41 18139.18141<6> crawl_5: zero bbd BeesBlockData { 4K 0xa000 fd = 115 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog', address = 0x953a69ee000, hash = 0x0, data[4096] }
2018-05-01 16:19:41 18139.18141<6> crawl_5: in extent Extent { begin = 0xa000, end = 0xb000, physical = 0x953a69ee000, flags = , physical_len = 0x1000, logical_len = 0x1000 }
2018-05-01 16:19:41 18139.18141<6> crawl_5: copy: 4K [0xa000..0xb000] fd = 115 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog'
2018-05-01 16:19:41 18139.18140<6> crawl_5: zero bbd BeesBlockData { 4K 0x20000 fd = 115 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog', address = 0x85e7e675000, hash = 0x0, data[4096] }
2018-05-01 16:19:41 18139.18140<6> crawl_5: in extent Extent { begin = 0x20000, end = 0x40000, physical = 0x85e7e675000, flags = Extent::OBSCURED|, physical_len = 0x6582000, logical_len = 0x20000, offset = 0x14c0000 }
2018-05-01 16:19:41 18139.18140<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 115 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog'
2018-05-01 16:19:41 18139.18143<6> crawl_5: copy: 4K [0x46000..0x47000] fd = 115 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog'
2018-05-01 16:19:41 18139.18143<6> crawl_5: dedup: src 4K [0x21000..0x22000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989940 (deleted)
2018-05-01 16:19:41 18139.18143<6> crawl_5: dst 4K [0x46000..0x47000] {0x92ba31c6000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog
2018-05-01 16:19:41 18139.18143<6> crawl_5: scan: 4K 0x46000 [+] 0x47000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog
2018-05-01 16:19:41 18139.18142<6> crawl_5: dedup: src 16K [0x21000..0x25000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989938 (deleted)
2018-05-01 16:19:41 18139.18142<6> crawl_5: dst 16K [0x5000..0x9000] {0x92ba31c5000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog
2018-05-01 16:19:41 18139.18142<6> crawl_5: scan: 16K 0x5000 [++++] 0x9000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog
2018-05-01 16:19:41 18139.18141<6> crawl_5: dedup: src 4K [0x21000..0x22000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989939 (deleted)
2018-05-01 16:19:41 18139.18141<6> crawl_5: dst 4K [0xa000..0xb000] {0x953a69ee000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog
2018-05-01 16:19:41 18139.18141<6> crawl_5: scan: 4K 0xa000 [+] 0xb000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/lastlog
2018-05-01 16:19:41 18139.18149<4> crawl_5: Opening /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/journal/4be3c22b07f34c49a442b29773dec97c/system@00056183b3db238b-4e500011dcfa19ca.journal~ found FS_NOCOW_FL flag in 0x800000
2018-05-01 16:19:41 18139.18150<6> crawl_5: zero bbd BeesBlockData { 2.563K 0xf000 fd = 327 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/tallylog', address = 0x95553564000u, hash = 0x0, data[2624] }
2018-05-01 16:19:41 18139.18150<6> crawl_5: in extent Extent { begin = 0xf000, end = 0xfa40, physical = 0x95553564000, flags = FIEMAP_EXTENT_LAST, physical_len = 0x1000, logical_len = 0x1000 }
2018-05-01 16:19:41 18139.18150<6> crawl_5: copy: 2.563K [0xf000..0xfa40) fd = 327 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/tallylog'
2018-05-01 16:19:41 18139.18151<6> crawl_5: copy: 8K [0x1000..0x3000] fd = 327 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/tallylog'
2018-05-01 16:19:41 18139.18150<6> crawl_5: dedup: src 2.563K [0x21000..0x21a40] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989941 (deleted)
2018-05-01 16:19:41 18139.18150<6> crawl_5: dst 2.563K [0xf000..0xfa40] {0x95553564000u} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/tallylog
2018-05-01 16:19:41 18139.18150<6> crawl_5: scan: 2.563K 0xf000 [+] 0xfa40 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/tallylog
2018-05-01 16:19:41 18139.18151<6> crawl_5: dedup: src 8K [0x21000..0x23000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989947 (deleted)
2018-05-01 16:19:41 18139.18151<6> crawl_5: dst 8K [0x1000..0x3000] {0x92ba31c8000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/tallylog
2018-05-01 16:19:41 18139.18151<6> crawl_5: scan: 8K 0x1000 [++] 0x3000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/tallylog
2018-05-01 16:19:41 18139.18146<4> crawl_5: Opening /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/log/journal/4be3c22b07f34c49a442b29773dec97c/user-1000@2bfef0500f3e480ba52ab6a66dac43c8-00000000000007fb-00055f646cc7ce66.journal found FS_NOCOW_FL flag in 0x800000
2018-05-01 16:19:41 18139.18149<6> crawl_5: copy: 12K [0x8000..0xb000) fd = 440 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_0'
2018-05-01 16:19:41 18139.18147<6> crawl_5: copy: 8K [0x40000..0x42000) fd = 441 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_1'
2018-05-01 16:19:41 18139.18150<6> crawl_5: zero bbd BeesBlockData { 368 0x40000 fd = 444 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/index', address = 0x92c5ec89000u, hash = 0x0, data[368] }
2018-05-01 16:19:41 18139.18150<6> crawl_5: in extent Extent { begin = 0x40000, end = 0x40170, physical = 0x92c5ec89000, flags = FIEMAP_EXTENT_LAST, physical_len = 0x1000, logical_len = 0x1000 }
2018-05-01 16:19:41 18139.18150<6> crawl_5: copy: 368 [0x40000..0x40170) fd = 444 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/index'
2018-05-01 16:19:41 18139.18148<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 441 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_1'
2018-05-01 16:19:41 18139.18141<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 444 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/index'
2018-05-01 16:19:41 18139.18149<6> crawl_5: dedup: src 12K [0x21000..0x24000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989945 (deleted)
2018-05-01 16:19:41 18139.18149<6> crawl_5: dst 12K [0x8000..0xb000] {0x92c6199d000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_0
2018-05-01 16:19:41 18139.18149<6> crawl_5: scan: 12K 0x8000 [+++] 0xb000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_0
2018-05-01 16:19:41 18139.18150<6> crawl_5: dedup: src 368 [0x1000..0x1170] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989948 (deleted)
2018-05-01 16:19:41 18139.18150<6> crawl_5: dst 368 [0x40000..0x40170] {0x92c5ec89000u} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/index
2018-05-01 16:19:41 18139.18147<6> crawl_5: dedup: src 8K [0x21000..0x23000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989937 (deleted)
2018-05-01 16:19:41 18139.18147<6> crawl_5: dst 8K [0x40000..0x42000] {0x92c3fd81000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_1
2018-05-01 16:19:41 18139.18150<6> crawl_5: scan: 368 0x40000 [+] 0x40170 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/index
2018-05-01 16:19:41 18139.18147<6> crawl_5: scan: 8K 0x40000 [++] 0x42000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_1
2018-05-01 16:19:41 18139.18141<6> crawl_5: dedup: src 128K [0x22000..0x42000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989939 (deleted)
2018-05-01 16:19:41 18139.18141<6> crawl_5: dst 128K [0x20000..0x40000] {0x92cb8a95000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/index
2018-05-01 16:19:41 18139.18141<6> crawl_5: scan: 128K 0x20000 [++++++++++++++++++++++++++++++++] 0x40000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/index
2018-05-01 16:19:42 18139.18148<6> crawl_5: dedup: src 128K [0x21000..0x41000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989946 (deleted)
2018-05-01 16:19:42 18139.18148<6> crawl_5: dst 128K [0x20000..0x40000] {0x92cb8875000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_1
2018-05-01 16:19:42 18139.18148<6> crawl_5: scan: 128K 0x20000 [++++++++++++++++++++++++++++++++] 0x40000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/Cache/data_1
2018-05-01 16:19:42 18139.18150<6> crawl_5: copy: 8K [0x40000..0x42000) fd = 524 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/data_1'
2018-05-01 16:19:42 18139.18147<6> crawl_5: zero bbd BeesBlockData { 368 0x40000 fd = 527 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/index', address = 0x952da005000u, hash = 0x0, data[368] }
2018-05-01 16:19:42 18139.18147<6> crawl_5: in extent Extent { begin = 0x40000, end = 0x40170, physical = 0x952da005000, flags = FIEMAP_EXTENT_LAST, physical_len = 0x1000, logical_len = 0x1000 }
2018-05-01 16:19:42 18139.18147<6> crawl_5: copy: 368 [0x40000..0x40170) fd = 527 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/index'
2018-05-01 16:19:42 18139.18143<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 524 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/data_1'
2018-05-01 16:19:42 18139.18146<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 527 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/index'
2018-05-01 16:19:42 18139.18150<6> crawl_5: dedup: src 8K [0x1000..0x3000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989949 (deleted)
2018-05-01 16:19:42 18139.18150<6> crawl_5: dst 8K [0x40000..0x42000] {0x92cb8b12000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/data_1
2018-05-01 16:19:42 18139.18150<6> crawl_5: scan: 8K 0x40000 [++] 0x42000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/data_1
2018-05-01 16:19:42 18139.18144<4> crawl_5: WORKAROUND: abandoned toxic match for hash 0x8676aa3cf9f696f9 addr NILt matching bbd BeesBlockData { 4K 0x1000 fd = 544 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/pulse/b3eb7f17c4d4487b96e2d0f02675ccfa-card-database.tdb', address = 0x92c6594b000z1000, hash = 0x8676aa3cf9f696f9, data[4096] }
2018-05-01 16:19:42 18139.18147<6> crawl_5: dedup: src 368 [0x23000..0x23170] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989937 (deleted)
2018-05-01 16:19:42 18139.18147<6> crawl_5: dst 368 [0x40000..0x40170] {0x952da005000u} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/index
2018-05-01 16:19:42 18139.18141<4> crawl_5: WORKAROUND: abandoned toxic match for hash 0x8676aa3cf9f696f9 addr NILt matching bbd BeesBlockData { 4K 0x1000 fd = 546 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/pulse/b3eb7f17c4d4487b96e2d0f02675ccfa-stream-volumes.tdb', address = 0x92c6594d000z1000, hash = 0x8676aa3cf9f696f9, data[4096] }
2018-05-01 16:19:42 18139.18147<6> crawl_5: scan: 368 0x40000 [+] 0x40170 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/index
2018-05-01 16:19:42 18139.18146<6> crawl_5: dedup: src 128K [0x21000..0x41000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989944 (deleted)
2018-05-01 16:19:42 18139.18146<6> crawl_5: dst 128K [0x20000..0x40000] {0x92cb8d21000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/index
2018-05-01 16:19:42 18139.18146<6> crawl_5: scan: 128K 0x20000 [++++++++++++++++++++++++++++++++] 0x40000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/index
2018-05-01 16:19:42 18139.18143<6> crawl_5: dedup: src 128K [0x22000..0x42000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989940 (deleted)
2018-05-01 16:19:42 18139.18143<6> crawl_5: dst 128K [0x20000..0x40000] {0x92cb8aaf000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/data_1
2018-05-01 16:19:42 18139.18143<6> crawl_5: scan: 128K 0x20000 [++++++++++++++++++++++++++++++++] 0x40000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/.config/Code/GPUCache/data_1
2018-05-01 16:19:42 18139.18147<6> crawl_5: copy: 12K [0x8000..0xb000) fd = 558 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_0'
2018-05-01 16:19:42 18139.18141<6> crawl_5: copy: 8K [0x2000..0x4000] fd = 559 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1'
2018-05-01 16:19:42 18139.18146<6> crawl_5: copy: 8K [0x40000..0x42000) fd = 559 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1'
2018-05-01 16:19:42 18139.18149<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 559 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1'
2018-05-01 16:19:42 18139.18148<6> crawl_5: zero bbd BeesBlockData { 368 0x40000 fd = 563 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/index', address = 0x92c5ec9a000u, hash = 0x0, data[368] }
2018-05-01 16:19:42 18139.18148<6> crawl_5: in extent Extent { begin = 0x40000, end = 0x40170, physical = 0x92c5ec9a000, flags = FIEMAP_EXTENT_LAST, physical_len = 0x1000, logical_len = 0x1000 }
2018-05-01 16:19:42 18139.18148<6> crawl_5: copy: 368 [0x40000..0x40170) fd = 563 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/index'
2018-05-01 16:19:42 18139.18150<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 563 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/index'
2018-05-01 16:19:42 18139.18148<6> crawl_5: dedup: src 368 [0x41000..0x41170] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989946 (deleted)
2018-05-01 16:19:42 18139.18148<6> crawl_5: dst 368 [0x40000..0x40170] {0x92c5ec9a000u} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/index
2018-05-01 16:19:42 18139.18148<6> crawl_5: scan: 368 0x40000 [+] 0x40170 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/index
2018-05-01 16:19:42 18139.18141<6> crawl_5: dedup: src 8K [0x42000..0x44000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989939 (deleted)
2018-05-01 16:19:42 18139.18141<6> crawl_5: dst 8K [0x2000..0x4000] {0x92c6595e000z2000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1
2018-05-01 16:19:42 18139.18147<6> crawl_5: dedup: src 12K [0x1000..0x4000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989950 (deleted)
2018-05-01 16:19:42 18139.18147<6> crawl_5: dst 12K [0x8000..0xb000] {0x92c6595d000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_0
2018-05-01 16:19:42 18139.18141<6> crawl_5: scan: 8K 0x2000 [++] 0x4000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1
2018-05-01 16:19:42 18139.18147<6> crawl_5: scan: 12K 0x8000 [+++] 0xb000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_0
2018-05-01 16:19:42 18139.18149<6> crawl_5: dedup: src 128K [0x24000..0x44000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989945 (deleted)
2018-05-01 16:19:42 18139.18149<6> crawl_5: dst 128K [0x20000..0x40000] {0x92c3fdcb000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1
2018-05-01 16:19:42 18139.18150<6> crawl_5: dedup: src 128K [0x3000..0x23000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989949 (deleted)
2018-05-01 16:19:42 18139.18150<6> crawl_5: dst 128K [0x20000..0x40000] {0x92c3ff5a000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/index
2018-05-01 16:19:42 18139.18149<6> crawl_5: scan: 128K 0x20000 [++++++++++++++++++++++++++++++++] 0x40000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1
2018-05-01 16:19:42 18139.18150<6> crawl_5: scan: 128K 0x20000 [++++++++++++++++++++++++++++++++] 0x40000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/index
2018-05-01 16:19:42 18139.18146<6> crawl_5: dedup: src 8K [0x41000..0x43000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989944 (deleted)
2018-05-01 16:19:42 18139.18146<6> crawl_5: dst 8K [0x40000..0x42000] {0x92a81f2e000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1
2018-05-01 16:19:42 18139.18146<6> crawl_5: scan: 8K 0x40000 [++] 0x42000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/Cache/data_1
2018-05-01 16:19:42 18139.18147<6> crawl_5: copy: 8K [0x40000..0x42000) fd = 642 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/data_1'
2018-05-01 16:19:42 18139.18148<6> crawl_5: zero bbd BeesBlockData { 368 0x40000 fd = 645 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/index', address = 0x952da006000u, hash = 0x0, data[368] }
2018-05-01 16:19:42 18139.18148<6> crawl_5: in extent Extent { begin = 0x40000, end = 0x40170, physical = 0x952da006000, flags = FIEMAP_EXTENT_LAST, physical_len = 0x1000, logical_len = 0x1000 }
2018-05-01 16:19:42 18139.18148<6> crawl_5: copy: 368 [0x40000..0x40170) fd = 645 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/index'
2018-05-01 16:19:42 18139.18150<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 642 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/data_1'
2018-05-01 16:19:42 18139.18145<6> crawl_5: copy: 128K [0x20000..0x40000] fd = 645 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/index'
2018-05-01 16:19:42 18139.18148<6> crawl_5: dedup: src 368 [0x1000..0x1170] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989951 (deleted)
2018-05-01 16:19:42 18139.18148<6> crawl_5: dst 368 [0x40000..0x40170] {0x952da006000u} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/index
2018-05-01 16:19:42 18139.18147<6> crawl_5: dedup: src 8K [0x4000..0x6000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989950 (deleted)
2018-05-01 16:19:42 18139.18147<6> crawl_5: dst 8K [0x40000..0x42000] {0x92c3ffe4000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/data_1
2018-05-01 16:19:42 18139.18148<6> crawl_5: scan: 368 0x40000 [+] 0x40170 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/index
2018-05-01 16:19:42 18139.18147<6> crawl_5: scan: 8K 0x40000 [++] 0x42000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/data_1
2018-05-01 16:19:42 18139.18143<3> crawl_5: Opening src bfr 4K [0x56000..0x57000] fid = 5:960722 fd = 655 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles/.config/libreoffice/4/user/database/biblio/biblio.dbt'
2018-05-01 16:19:42 18139.18143<3> crawl_5: chase_extent_ref ino BtrfsInodeOffsetRoot { .m_inum = 960722, .m_offset = 0x40000, .m_root = 5 } bbd BeesBlockData { 4K 0x45000 fd = 653 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/libreoffice/4/user/database/biblio/biblio.dbt', data[4096] }
2018-05-01 16:19:42 18139.18143<3> crawl_5: ino_off_root BtrfsInodeOffsetRoot { .m_inum = 960722, .m_offset = 0x40000, .m_root = 5 }
2018-05-01 16:19:42 18139.18143<3> crawl_5: for_each_extent_ref BeesBlockData { 4K 0x45000 fd = 653 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/libreoffice/4/user/database/biblio/biblio.dbt', data[4096] } at 0x92c3fa69000z16000: 3 found
2018-05-01 16:19:42 18139.18143<3> crawl_5: overlap_bfr 0 (..0x0]
2018-05-01 16:19:42 18139.18143<3> crawl_5: Opening dst bfr 4K [0x45000..0x46000] fd = 653 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/libreoffice/4/user/database/biblio/biblio.dbt'
2018-05-01 16:19:42 18139.18143<3> crawl_5: replace_dst dst_bfr 4K [0x45000..0x46000] fd = 653 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/libreoffice/4/user/database/biblio/biblio.dbt'
2018-05-01 16:19:42 18139.18143<3> crawl_5: finding one match (out of 3) at 0x92c3fa69000z16000 for BeesBlockData { 4K 0x45000 fd = 653 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/libreoffice/4/user/database/biblio/biblio.dbt', address = 0x92c3fa69000z5000, hash = 0xd8d16148fa9b7339, data[4096] }
2018-05-01 16:19:42 18139.18143<3> crawl_5: resolved_addrs.size() = 1
2018-05-01 16:19:42 18139.18143<3> crawl_5: Pushing hash 0xd8d16148fa9b7339 addr 0x92c3fa69000z5000 bbd BeesBlockData { 4K 0x45000 fd = 653 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/libreoffice/4/user/database/biblio/biblio.dbt', address = 0x92c3fa69000z5000, hash = 0xd8d16148fa9b7339, data[4096] }
2018-05-01 16:19:42 18139.18143<3> crawl_5: scan bbd BeesBlockData { 4K 0x45000 fd = 653 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/libreoffice/4/user/database/biblio/biblio.dbt', address = 0x92c3fa69000z5000, hash = 0xd8d16148fa9b7339, data[4096] }
2018-05-01 16:19:42 18139.18143<3> crawl_5: Extent { begin = 0x40000, end = 0x60000, physical = 0x92c3fa69000, flags = FIEMAP_EXTENT_ENCODED, physical_len = 0x20000, logical_len = 0x20000 } block_count 32
2018-05-01 16:19:42 18139.18143<3> crawl_5: scan extent Extent { begin = 0x40000, end = 0x60000, physical = 0x92c3fa69000, flags = FIEMAP_EXTENT_ENCODED, physical_len = 0x20000, logical_len = 0x20000 }
2018-05-01 16:19:42 18139.18143<3> crawl_5:
2018-05-01 16:19:42 18139.18143<3> crawl_5:
2018-05-01 16:19:42 18139.18143<3> crawl_5: *** EXCEPTION ***
2018-05-01 16:19:42 18139.18143<3> crawl_5: exception type std::runtime_error: FIXME: bailing out here, need to fix this further up the call stack
2018-05-01 16:19:42 18139.18143<3> crawl_5: ***
2018-05-01 16:19:42 18139.18143<4> crawl_5: WORKAROUND: abandoned toxic match for hash 0x8676aa3cf9f696f9 addr NILt matching bbd BeesBlockData { 4K 0x1000 fd = 665 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/pulse/b3eb7f17c4d4487b96e2d0f02675ccfa-card-database.tdb', address = 0x9257606b000z1000, hash = 0x8676aa3cf9f696f9, data[4096] }
2018-05-01 16:19:42 18139.18146<4> crawl_5: WORKAROUND: abandoned toxic match for hash 0x8676aa3cf9f696f9 addr NILt matching bbd BeesBlockData { 4K 0x1000 fd = 666 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/pulse/b3eb7f17c4d4487b96e2d0f02675ccfa-stream-volumes.tdb', address = 0x9257606d000z1000, hash = 0x8676aa3cf9f696f9, data[4096] }
2018-05-01 16:19:42 18139.18145<6> crawl_5: dedup: src 128K [0x1000..0x21000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989952 (deleted)
2018-05-01 16:19:42 18139.18150<6> crawl_5: dedup: src 128K [0x23000..0x43000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989949 (deleted)
2018-05-01 16:19:42 18139.18145<6> crawl_5: dst 128K [0x20000..0x40000] {0x92c400ae000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/index
2018-05-01 16:19:42 18139.18150<6> crawl_5: dst 128K [0x20000..0x40000] {0x92c3ffe2000z0} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/data_1
2018-05-01 16:19:42 18139.18150<6> crawl_5: scan: 128K 0x20000 [++++++++++++++++++++++++++++++++] 0x40000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/data_1
2018-05-01 16:19:42 18139.18145<6> crawl_5: scan: 128K 0x20000 [++++++++++++++++++++++++++++++++] 0x40000 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles.bak/dotfiles/.config/Code/GPUCache/index
2018-05-01 16:19:44 18139.18148<6> crawl_5: zero bbd BeesBlockData { 4K 0x1f8000 fd = 2373 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/libdb_stl-5.3.so', address = 0x953a7a4d000, hash = 0x0, data[4096] }
2018-05-01 16:19:44 18139.18148<6> crawl_5: in extent Extent { begin = 0x0, end = 0x1fcaf0, physical = 0x953a7855000, flags = FIEMAP_EXTENT_LAST, physical_len = 0x1fd000, logical_len = 0x1fd000 }
2018-05-01 16:19:44 18139.18148<6> crawl_5: copy: 1.987M (..0x1fcaf0) fd = 2373 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/libdb_stl-5.3.so'
2018-05-01 16:19:45 18139.18143<6> crawl_5: zero bbd BeesBlockData { 2 0x1000 fd = 3914 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/lib/pacman/local/diffutils-3.6-1/mtree', address = 0x953c27c9000u, hash = 0x0, data[2] }
2018-05-01 16:19:45 18139.18143<6> crawl_5: in extent Extent { begin = 0x0, end = 0x1002, physical = 0x953c27c8000, flags = FIEMAP_EXTENT_LAST, physical_len = 0x2000, logical_len = 0x2000 }
2018-05-01 16:19:45 18139.18143<6> crawl_5: copy: 4.002K (..0x1002) fd = 3914 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/lib/pacman/local/diffutils-3.6-1/mtree'
sudo beesd 8d2b3f38-f8ac-4ab3-948b-767c1b10741f
2018-05-01 16:20:34 18139.18143<4> crawl_5: PERFORMANCE: 48.507 sec: Resizing temporary file to 0x43002
2018-05-01 16:20:34 18139.18140<4> crawl_5: PERFORMANCE: 52.536 sec: Resolving addr 0x85e7e675000 in /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f refs 34
2018-05-01 16:20:34 18139.18148<4> crawl_5: PERFORMANCE: 50.037 sec: creating temporary file in /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f
2018-05-01 16:20:34 18139.18152<7> crawl_transid: Polling 530.378s for next 10 transid RateEstimator { count = 83329, raw = 1 / 52.9795, ratio = 1 / 53.0443, rate = 0.0188522, duration(1) = 53.0443, seconds_for(1) = 52.9795 }
2018-05-01 16:20:34 18139.18143<6> crawl_5: dedup: src 4K [0x42000..0x43000] {0x7d1383ca000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989940 (deleted)
2018-05-01 16:20:34 18139.18143<6> crawl_5: dst 4K [0x0..0x1000] {0x953c27c8000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/lib/pacman/local/diffutils-3.6-1/mtree
2018-05-01 16:20:34 18139.18145<6> crawl_master: Crawl started BeesCrawlState 258:0 offset 0x0 transid 83328..83329 started 2018-05-01-16-20-34 (0s ago)
2018-05-01 16:20:34 18139.18145<6> crawl_master: Crawl finished BeesCrawlState 258:0 offset 0x0 transid 83328..83329 started 2018-05-01-16-20-34 (0s ago)
2018-05-01 16:20:34 18139.18145<6> crawl_master: Crawl started BeesCrawlState 9927:0 offset 0x0 transid 83328..83329 started 2018-05-01-16-20-34 (0s ago)
2018-05-01 16:20:34 18139.18145<6> crawl_master: Crawl finished BeesCrawlState 9927:260 offset 0x101 transid 83328..83329 started 2018-05-01-16-20-34 (0s ago)
2018-05-01 16:20:34 18139.18143<6> crawl_5: scan: 4.002K 0x0 [++] 0x1002 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var/lib/pacman/local/diffutils-3.6-1/mtree
2018-05-01 16:20:35 18139.18148<6> crawl_5: dedup: src 1.969M [0x1000..0x1f9000] {0x851045ac000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989953 (deleted)
2018-05-01 16:20:35 18139.18148<6> crawl_5: dst 1.969M [0x0..0x1f8000] {0x953a7855000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/libdb_stl-5.3.so
2018-05-01 16:20:35 18139.18148<6> crawl_5: scan: 1.987M 0x0 [+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++] 0x1fcaf0 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/libdb_stl-5.3.so
2018-05-01 16:20:35 18139.18140<6> crawl_5: dedup: src 128K [0x21000..0x41000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989943 (deleted)
2018-05-01 16:20:35 18139.18140<6> crawl_5: dst 128K [0x32e0000..0x3300000] {0x85e7e675000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/libLLVM-6.0.so
2018-05-01 16:20:36 18139.18141<6> crawl_5: zero bbd BeesBlockData { 4K 0x942000 fd = 1629 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/opencollada/libOpenCOLLADASaxFrameworkLoader.so', address = 0x953f0998000, hash = 0x0, data[4096] }
2018-05-01 16:20:36 18139.18141<6> crawl_5: in extent Extent { begin = 0x800000, end = 0xa127a0, physical = 0x953f0856000, flags = Extent::OBSCURED|FIEMAP_EXTENT_LAST, physical_len = 0xa13000, logical_len = 0x213000, offset = 0x800000 }
2018-05-01 16:20:36 18139.18141<6> crawl_5: copy: 2.072M [0x800000..0xa127a0) fd = 1629 '/run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/opencollada/libOpenCOLLADASaxFrameworkLoader.so'
2018-05-01 16:20:36 18139.18141<6> crawl_5: dedup: src 1.258M [0x44000..0x186000] {0x85105079000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989939 (deleted)
2018-05-01 16:20:36 18139.18141<6> crawl_5: dst 1.258M [0x800000..0x942000] {0x953f0856000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/opencollada/libOpenCOLLADASaxFrameworkLoader.so
2018-05-01 16:20:36 18139.18141<6> crawl_5: scan: 2.072M 0x800000 [+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++] 0xa127a0 /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib/opencollada/libOpenCOLLADASaxFrameworkLoader.so
2018-05-01 16:20:37 18139.18140<6> crawl_5: dedup: src 128K [0x21000..0x41000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989943 (deleted)
2018-05-01 16:20:37 18139.18140<6> crawl_5: dst 128K [0x31e0000..0x3200000] {0x85e7e675000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/lib32/libLLVM-6.0.so
2018-05-01 16:20:37 18139.18140<6> crawl_5: dedup: src 128K [0x21000..0x41000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989943 (deleted)
2018-05-01 16:20:37 18139.18140<6> crawl_5: dst 128K [0x20000..0x40000] {0x85e7e675000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home/atemu/repos/dotfiles/.config/discord/GPUCache/index
2018-05-01 16:20:39 18139.18140<6> crawl_5: dedup: src 128K [0x21000..0x41000] {HOLE} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/#2989943 (deleted)
2018-05-01 16:20:39 18139.18140<6> crawl_5: dst 128K [0x20000..0x40000] {0x85e7e675000} /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr/bin/exrenvmapIt seems to be running now but I now get those
exception type std::runtime_error: FIXME: bailing out here, need to fix this further up the call stack errors from time to time now.
Zygo
commented
6 years ago Interesting...so there are cases where the compress attribute doesn't work? Or maybe there is an additional flag in the attributes that gets in the way. Can you run 'lsattr' on /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/ ?
The "bailing out here" exception is a quick hack to prevent bees from looping too long for very common duplicate blocks. You can ignore that exception for now. I intend to fix it as part of a much larger change that eliminates the situation where it arises.
Atemu
commented
6 years ago [atemu@HEPHAISTOS ~]$ sudo lsattr /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/boot
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/home
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/var
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/dev
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/run
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/etc
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/tmp
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/sys
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/proc
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/usr
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/mnt
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/opt
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/root
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/srv
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/$RECYCLE.BIN
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/System Volume Information
lsattr: Operation not supported While reading flags on /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/bin
lsattr: Operation not supported While reading flags on /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/lib
lsattr: Operation not supported While reading flags on /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/lib64
lsattr: Operation not supported While reading flags on /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/sbin
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/test
/bin, /lib, /lib64 and /sbin are symlinks on Arch, so I guess the error is unrelated.
I do have +C set on some files in the filesystem, mainly a couple VM images.
Zygo
commented
6 years ago Oops sorry forgot the -d...
Please try lsattr -d /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/
though if that doesn't list the C attribute then I'm out of ideas again.
Atemu
commented
6 years ago I'll also try unsetting the +C on or removing the VM images when I get back home, I don't need them anyways.
Could you try creating a 20GiB file with random data in it with the +C attr on it somewhere in your filesystem and run bees? Maybe that's what's causing the error.
Atemu
commented
6 years ago Please try lsattr -d /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/
------------------ /run/bees/mnt/8d2b3f38-f8ac-4ab3-948b-767c1b10741f/I let bees run for a a few days because apart from the couple exceptions it throws, it seems to have been working just fine.
I don't know if this is related but since the issue is still there and I'm running bees with your suggested change, I thought I'd put it here.
Yesterday it locked up my filesystem at one point (I can give you the filename it scanned just before); no disk rw was possible and iostat told me there's ~0% User, ~40% System, and ~50% idle CPU usage
I let it run for an hour because the system must've been doing something as the fans were still running at pretty high speeds but then tried to cancel it wth C-c and after that did cancel bees but not the lockup and system CPU usage, I forced a shutdown and rebooted.
The system itself was doing completely fine, so I ran bees again to see if this was a one time issue and after it scanned a block of the same file (don't know if it's the same exact block) it locked up again.
I let it run for a few hours and beesd printed it's status updates but there was no valuable information I could read from those.
Do you have an idea what might be causing this?
Should I let it finish whatever it's doing or could this be a deadlock?
Zygo
commented
6 years ago If it's burning CPU, it's probably not a deadlock. It could be the performance issue with too many reflinks, especially if the file it got stuck on was large and if you're running a kernel older than 4.14.
You can grab kernel stack traces from the stuck processes via /proc/find_parent_nodes then it's the known reflink performance bug. Use 'ps xar' to get a list of processes that are active on IO or CPU. Or both, like this:
ps xar | while read pid rest; do head -999 /proc/$pid/task/*/stack; done
bees does record in the hash table when find_parent_nodes takes a long time, and saves the block addresses so it will not touch those blocks again; however, this only helps after bees discovers such blocks the hard way.
kakra
commented
6 years ago I had similar issues with compressed vm images before. It may be related to auto-defrag which I turned off meanwhile. But I didn't try again to boot one of those VMs again since then.
The problem always resulted in some internal structural defects of the VM images in btrfs. Bees would choke on them or throw strange error messages while btrfs itself seems to do mostly well with handling those files - except I wouldn't be able to copy or read them in their entirety. Running btrfsck then usually results in problems found, running a fix may render the btrfs unusable. Luckily, I have nightly backups so I could easily revert creating btrfs from scratch by restoring the latest snapshot. My backups are made with borgbackup, so even if something breaks within a file stored in btrfs it wouldn't store a broken copy of the file. And if it did, I can go back days, weeks, and months easily: Due to how borgbackup works, I can efficiently store daily full-backups for huge amounts of time without sacrificing much storage. For safety, I don't store borgbackup on btrfs either.
@Atemu Could you check that your btrfs is error free, especially before and after removing the VM images? If you find problems related to these files, you may have better results by disabling auto-defrag (in case you enabled it) or making those file no-cow. I think the problem I experienced may be related due to VirtualBox probably using DirectIO and bad interactions of btrfs with DirectIO, compression, and/or auto-defrag. Actually, CoW filesystems are not well suited for DirectIO as far as I can tell. I'm not even sure if btrfs supports it in parts or fully, or maybe not at all, and I've read reports of bad interaction usually resulting in the suggestion "do not use DirectIO". If btrfs supports it, it's probably stable only with no-cow files.
Zygo
commented
6 years ago There are two btrfs bugs that may be relevant:
when the dedup ioctl operates on a file with delalloc extents, it can deadlock. There are already at least two fixes for this in the kernel, but the problem remains, occurring less frequently. bees calls fsync() after making temporary copies to try to work around this bug, but bees can only make the condition happen less often, not eliminate it. I confirmed this still happens in v4.14 but haven't gotten around to trying to fix it (or even really properly report it). If you remove the call to fsync() in bees_sync it takes about 6 hours of dedup to hit the bug; with the fsync(), it's between 30 and 300 days (so far) depending on workload.
when thousands of references are made to the same extent in a large file, the runtime of various btrfs operations (balance, mmap, overwrite, delete) gets much, much slower. 4.14 made this a lot better, but bees could find millions of references in typical VM images if it was allowed to. In these cases the file should still be readable, but may take up to an hour of CPU for a few blocks (or more, but I stopped testing after a few days). bees detects when btrfs is getting slower, and bees stops processing the file to avoid making the problem worse. This has been a known issue with btrfs dedup for years.
As far as I know there are no btrfs metadata corruption bugs triggered by bees alone. I have found quite a few triggered by btrfs interactions with lvmcache, bcache, and desktop hard drives (e.g. WD Black, Seagate Barracuda) and I don't recommend using any of those with btrfs, let alone btrfs+bees. I have been expecting a btrfs-vs-bees metadata apocalypse on SATA-attached NAS or enterprise SSDs and HDDs for years, but so far it hasn't happened yet.
If the VM images are nocow, bees will completely ignore them (well, it will ignore each extent in them individually).
For first issue you might want to try inserting a call to bees_sync in BeesContext::dedup:
diff --git a/src/bees-context.cc b/src/bees-context.cc
index 360755869..ce212b398 100644
--- a/src/bees-context.cc
+++ b/src/bees-context.cc
@@ -178,6 +178,9 @@ BeesContext::dedup(const BeesRangePair &brp)
brp.first.fd(shared_from_this());
brp.second.fd(shared_from_this());
+ BEESTOOLONG("sync " << brp);
+ bees_sync(brp.first.fd());
+
BEESTOOLONG("dedup " << brp);
BeesAddress first_addr(brp.first.fd(), brp.first.begin());
Without trying to hijack this issue, it's interesting how could btrfs have bad interactions with desktop hard drives? This would be a fatal flaw because if btrfs can trigger bad behavior, any access pattern could easily do this. That would have great potential for exploits.
Theoretically, the same goes for bcache and there should be no bad interactions. But bcache is probably much more complex regarding interlacing of delayed access patterns over time. It generates much longer interlacing timelines due to its vast size compared to on-device caches. Same goes for lvmcache.
I can only imagine that it gets complicated when barriers come into play. Bcache, as far as I know, completely ignores them for the fact that it simply replays everything it has in its log during crash recovery, so write order does not matter from perspective of the lower layers. From the perspective of the upper layer it guarantees consistency (as far as no implementation bugs are involved).
Since I stopped using legacy BFQ and auto-defrag, I had no more issues. So I think problems are more likely to originate from there.
Zygo
commented
6 years ago The bad interactions on desktop drives seem to be related to not doing barriers correctly while other things go wrong. i.e. you need to have one failure (e.g. a crash, SATA disconnect, bad sector, drive reset, USB disconnect) which causes one or more writes to be reported complete when they are not, then btrfs crashes after that if you do not have redundant metadata on a separate disk that does not have the same firmware bug (even if you do, a scrub is required to repair the damage).
I stopped using desktop drives because they kept messing up my ext3 partitions to the point where I was spending 10% of my time running fsck and restoring backups on them. Desktop drives are cheap and fast(ish), but when you use one, you should always plan as if you will mkfs and start over tomorrow (note that their target market is Windows machines where reinstallation is the first response to failure).
Last time I tried bcache, it got stuck in some sort of recursive deadlock with itself. bcache crashed above the storage layer--and in the process damaged other filesystems on the host that were not using bcache at the time. I hear that's a one-off bug in 4.14, but I won't be trusting bcache outside of a disposable VM for quite some time because it's able to break unrelated devices when it goes bad.
I remember a week of terrible crash reports on IRC when BFQ hit the mainline kernel for the first time.
kakra
commented
6 years ago Ah, okay that all makes sense. So it totally depends on what level of stability I expect from my systems (in terms of uptime and downtime) and which level of stability I grant them (in terms of UPS etc). I have a proven working backup for my home system, and I do not fear to restore from it. So I'm all fine with my setup.
I installed bees via the bees-git package in AUR, copied
/etc/bees/based.conf.sample' to/etc/bees/based.conf' and added my BTRFS filesystem's UUID to the config file.Then I executed
beesdas root with the UUID as only argument but stopped it after a couple seconds because it was throwing exceptions all over the place.Here are parts of the output:
(more messages like this)
and then even more exceptions, you get the idea.
I have no idea whether I set it up right, the readme was not very clear on whether or not anything else needed to be done. It didn't even tell me to edit the config file but I assumed that was needed because the script complained about it otherwise.