Lookup root 256 ino xxx failed: Bad address

[bugsyb]

Hi,

Running bees on filesystem results in "Bad address" error for each and every inode.
I've to admit I've no clue why it happens and how to start any troubleshooting to get to root cause.

Environment is as following:

• BTRFS sits on LUKS volume (shouldn't matter),
• host system is Armel (v7)
• hardware side Raspberry Pi with OSMC (Debian:bullseye)
• bees is compile with container (docker run arm32v7/debian)

All data is in subvolumes - could this be the issue?
For tests created couple of folders with same large 800MB file in these and rerun Bees - no juice.

In short something is odd.

Have anyone seen anything similar? I've had Bees compiled in docker on amd64 system (Ubuntu) and it worked fine. Given OSMC is Debian:bullseye based it should all work fine, though it is not the case here even if logs do not suggest anything to be related to compilation.
Same issue happens with Bees compiled on the host system (not in container).

INFO: Find 00000000-xxxx-xxxx-xxxx-000000000000 in /etc/bees//beesd-btrfs-storage.conf, use as conf
INFO: Check: Disk exists
INFO: Check: Disk with btrfs
INFO: WORK DIR: /run/bees/
INFO: MOUNT DIR: /run/bees//mnt/00000000-xxxx-xxxx-xxxx-000000000000
bees version v0.10
2024-01-12 21:02:01 17073.17073<7> bees: Masking signals
2024-01-12 21:02:01 17073.17073<7> bees: context constructed
2024-01-12 21:02:01 17073.17073<7> bees: Parsing option 'c'
2024-01-12 21:02:01 17073.17073<6> bees: setting rlimit NOFILE to 10340
2024-01-12 21:02:01 17073.17073<5> bees: setting worker thread pool maximum size to 1
2024-01-12 21:02:01 17073.17073<5> bees: setting root path to '/run/bees/mnt/00000000-xxxx-xxxx-xxxx-000000000000'
2024-01-12 21:02:01 17073.17073<6> bees: set_root_path /run/bees/mnt/00000000-xxxx-xxxx-xxxx-000000000000
2024-01-12 21:02:01 17073.17073<6> bees: set_root_fd /run/bees/mnt/00000000-xxxx-xxxx-xxxx-000000000000
2024-01-12 21:02:01 17073.17073<6> bees: BeesStringFile /run/bees/mnt/00000000-xxxx-xxxx-xxxx-000000000000/.beeshome/beescrawl.dat max size 16M
2024-01-12 21:02:01 17073.17073<6> bees: btrfs send workaround disabled
2024-01-12 21:02:01 17073.17073<6> bees: Scan mode set to 1 (INDEPENDENT)
2024-01-12 21:02:01 17073.17073<5> bees: Starting bees main loop...
2024-01-12 21:02:01 17073.17073<7> bees: Thread progress_report no thread ptr
2024-01-12 21:02:01 17073.17073<7> bees: BeesThread exec progress_report
2024-01-12 21:02:01 17073.17073<7> bees: BeesThread exec status_report
2024-01-12 21:02:01 17073.17101<7> status_report: Starting thread status_report
2024-01-12 21:02:01 17073.17101<6> status_report: Writing status to file '/run/bees//00000000-xxxx-xxxx-xxxx-000000000000.status' every 1 sec
2024-01-12 21:02:01 17073.17100<7> progress_report: Starting thread progress_report
2024-01-12 21:02:01 17073.17073<6> bees: BeesStringFile /run/bees/mnt/00000000-xxxx-xxxx-xxxx-000000000000/.beeshome/beesstats.txt max size 16M
2024-01-12 21:02:01 17073.17073<6> bees: opened hash table filename 'beeshash.dat' length 1879048192
2024-01-12 21:02:01 17073.17073<6> bees: 	cells 117440512, buckets 458752, extents 14336
2024-01-12 21:02:01 17073.17073<6> bees: 	flush rate limit 131072
2024-01-12 21:02:01 17073.17073<6> bees: mapping hash table size 1879048192 with flags MAP_PRIVATE|MAP_ANONYMOUS
2024-01-12 21:02:01 17073.17073<6> bees: mmap done in 0.001 sec
2024-01-12 21:02:01 17073.17073<4> bees: madvise(..., MADV_HUGEPAGE): Invalid argument (ignored)
2024-01-12 21:02:01 17073.17073<7> bees: BeesThread exec hash_writeback
2024-01-12 21:02:01 17073.17073<7> bees: BeesThread exec hash_prefetch
2024-01-12 21:02:01 17073.17103<7> hash_prefetch: Starting thread hash_prefetch
2024-01-12 21:02:01 17073.17073<7> bees: Adding 1609:267 to blacklist
2024-01-12 21:02:01 17073.17073<7> bees: BeesThread exec crawl_transid
2024-01-12 21:02:01 17073.17102<7> hash_writeback: Starting thread hash_writeback
2024-01-12 21:02:01 17073.17073<7> bees: Waiting for signals...
2024-01-12 21:02:01 17073.17104<7> crawl_transid: Starting thread crawl_transid
2024-01-12 21:02:01 17073.17104<6> crawl_transid: loading crawl state
2024-01-12 21:02:01 17073.17104<7> crawl_transid: BeesThread exec crawl_writeback
2024-01-12 21:02:01 17073.17104<7> crawl_transid: Clearing root FD cache with size 0 to enable subvol delete
2024-01-12 21:02:01 17073.17104<7> crawl_transid: Clearing open FD cache with size 0 to enable file delete
2024-01-12 21:02:01 17073.17104<7> crawl_transid: Clearing resolve cache with size 0
2024-01-12 21:02:01 17073.17104<7> crawl_transid: Polling 30s for next transid RateEstimator { count = 2733, raw = 0 / 0.035082, ratio = 1 / 1, rate = 1, duration(1) = 1, seconds_for(1) = 1 }
2024-01-12 21:02:01 17073.17105<7> crawl_writeback: Starting thread crawl_writeback
2024-01-12 21:02:01 17073.17105<6> crawl_writeback: Saving crawl state
2024-01-12 21:02:01 17073.17105<6> crawl_writeback: Nothing to save
2024-01-12 21:02:01 17073.17102<6> hash_writeback: Flushed 0 of 14336 hash table extents
2024-01-12 21:02:01 17073.17099<6> crawl_new: Crawl finished BeesCrawlState 5:0 offset 0x0 transid 0..2733 started 2024-01-12-21-02-01 (0s ago)
2024-01-12 21:02:01 17073.17099<6> crawl_more: Crawl finished BeesCrawlState 1609:268 offset 0xffffffffffff0000 transid 0..2733 started 2024-01-12-21-02-01 (0s ago)
2024-01-12 21:02:01 17073.17099<6> crawl_256_293: Lookup root 256 ino 293 failed: Bad address
2024-01-12 21:02:01 17073.17099<6> crawl_256_294: Lookup root 256 ino 294 failed: Bad address
2024-01-12 21:02:01 17073.17099<6> crawl_256_310: Lookup root 256 ino 310 failed: Bad address
2024-01-12 21:02:01 17073.17099<6> crawl_256_317: Lookup root 256 ino 317 failed: Bad address
2024-01-12 21:02:01 17073.17099<6> crawl_256_1487: Lookup root 256 ino 1487 failed: Bad address
2024-01-12 21:02:01 17073.17099<6> crawl_256_1504: Lookup root 256 ino 1504 failed: Bad address
2024-01-12 21:02:01 17073.17099<6> crawl_256_1825: Lookup root 256 ino 1825 failed: Bad address
2024-01-12 21:02:02 17073.17099<6> crawl_256_2218: Lookup root 256 ino 2218 failed: Bad address
2024-01-12 21:02:02 17073.17099<6> crawl_256_2225: Lookup root 256 ino 2225 failed: Bad address
2024-01-12 21:02:02 17073.17099<6> crawl_256_2226: Lookup root 256 ino 2226 failed: Bad address
2024-01-12 21:02:02 17073.17099<6> crawl_256_2247: Lookup root 256 ino 2247 failed: Bad address
2024-01-12 21:02:02 17073.17099<6> crawl_256_2268: Lookup root 256 ino 2268 failed: Bad address
2024-01-12 21:02:02 17073.17099<6> crawl_256_2270: Lookup root 256 ino 2270 failed: Bad address
2024-01-12 21:02:02 17073.17099<6> crawl_256_2271: Lookup root 256 ino 2271 failed: Bad address
...
# same till the end and all inodes exist

Effectively nothing gets identified.

[kakra]

Probably a duplicate of #186