Can not interacting with folder mounted on dm-writeboost? Version 2.2.10

[nhocchi007]

Dear akira,
After 13 days running dm-writeboost on my disk something wrong happen,
i cannot interact with the folder /data/ anymore using ls, mkdir, add file....
dmesg log fault:
[3341551.692063] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341552.701259] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341553.339575] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341554.576510] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341653.508665] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm bash: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341653.731893] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm bash: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341663.437200] EXT4-fs error (device dm-5): ext4_find_dest_de:1653: inode #2: block 14654: comm mkdir: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341665.889757] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341666.823193] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341671.900039] EXT4-fs error (device dm-5): ext4_find_dest_de:1653: inode #2: block 14654: comm mkdir: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341742.492629] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341953.555294] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341977.426021] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341981.320515] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3341983.834547] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342035.975328] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm lsof: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342038.377535] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm lsof: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342045.639684] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm lsof: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342046.804830] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm lsof: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342047.532793] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm lsof: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342194.645129] EXT4-fs (dm-5): warning: mounting fs with errors, running e2fsck is recommended
[3342195.055847] EXT4-fs (dm-5): mounted filesystem with ordered data mode. Opts: (null)
[3342199.564925] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342200.426116] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342203.563006] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342221.592676] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342226.812250] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342229.270561] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342242.942348] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4
[3342254.850072] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm find: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=677963375, rec_len=28910, name_len=4

but dm -writeboost block still running with lsblock:
NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
sda 8:0 0 2.6T 0 disk
└─sda1 8:1 0 2.6T 0 part
└─ssddisk-ssd 253:4 0 2.6T 0 lvm
└─wbdev 253:5 0 98.2T 0 dm /data
sdb 8:16 0 98.2T 0 disk
└─sdb1 8:17 0 98.2T 0 part
└─hdddisk-hdd 253:3 0 98.2T 0 lvm
└─wbdev 253:5 0 98.2T 0 dm /data
sdd 8:48 0 447.1G 0 disk
├─sdd1 8:49 0 200M 0 part /boot/efi
├─sdd2 8:50 0 1G 0 part /boot
└─sdd3 8:51 0 445.9G 0 part
├─centos-root 253:0 0 217.9G 0 lvm /
├─centos-swap 253:1 0 128G 0 lvm [SWAP]
└─centos-home 253:2 0 100G 0 lvm /home
I'm afraid that when writeback threshold is meet something glitch or bug between my software and dm-writeboost. Is that possible?
I have try umount and mount that data folder again but nothing changed, still can not interact with the folder.
Then i use fsck trying to fix file system, lost+found folder created but all the other folder and data had been removed.
I know it's not your responsibility to this fault but can you tell me how can i debug it to the root cause?
Thank you akira

[akiradeveloper]

I am afaid after you fsck the filesystem and change the state, we can't track the root cause any more but I wish you used this tool to check whether the dm-writeboost is broken or not.

https://github.com/akiradeveloper/dm-writeboost-tools

And of course you should have checked the dmesg if there is some message from dm-writeboost. At least, the configuration must be shared.

About flawlessness of the software, in my opinion, dm-writeboost will not be broken in a usual operation because there are users that operate more harder more longer days. So the typical situation, dm-writeboost may go insane is that you shut down the system in unusual manner. I design the dm-writeboost so it survives even in this situation but I can't prove that the isn't anything wrong in code.

When dm-writeboost is broken, it is typically seen that the checksum is broken. The tool wbcheck is the one to check this. (checksum is broken means writing the segment is ended in unanticipated consequence)

If you ever deconstructed the dm-writeboost device after your system went wrong and the device was rebuilt and then sawthe dmesg, there were chances we could check if the checksums are not broken because the kernel code check all the segments. This code means, dm-writeboost discards segments after failure (e.g. partial writes)

		/*
		 * Compare the checksum
		 * if they don't match we discard the subsequent logs.
		 */
		actual = calc_checksum(rambuf, header->length);
		expected = le32_to_cpu(header->checksum);
		if (actual != expected) {
			DMWARN("Checksum incorrect id:%llu checksum: %u != %u",
			       (long long unsigned int) le64_to_cpu(header->id),
			       actual, expected);
			break;
		}

However, since you are telling that most of the data are gone, I don't believe only the some final writes have failed but the entire data is broken. I don't know it is due to dm-writeboost or ext4 or your operation.

[akiradeveloper]

Please check the hardware (memory, disk), if I remember correctly, there was a case that the cause is the broken memory. It can be possible that your system is running half correctly while writing something crazy data to the disk and then suddenly go crazy after few days. In this case, both storage softwares are to be blamed.

[nhocchi007]

I think it's my fault when i try this:
Daily i will try to move some file in this data folder to tmp folder also in this data folder and use perl unlink $_; cause there are milion files, reference to this article: https://www.slashroot.in/which-is-the-fastest-method-to-delete-files-in-linux
But maybe some other process is using this file causing this file system failure :(
So if this situation happened again, what should i do along with checking with dm-writeboost-tools?
Ps:
dmesg when i try to suspend and then resume dm writeboost when this happened
[835082.723180] device-mapper: writeboost: Checksum incorrect id:1463972724 checksum: 143703573 != 0
[3341439.144832] device-mapper: writeboost: Superblock Header: Magic number invalid
[3341439.148175] device-mapper: writeboost: zeroing_full_superblock failed
[3341439.151006] device-mapper: writeboost: format_cache_device failed
[3341439.154214] device-mapper: table: 253:5: writeboost: resume_cache failed
[3341482.298718] device-mapper: writeboost: Superblock Header: Magic number invalid

[akiradeveloper]

Such operations in the userland will not cause data corruption in kernel level.

The error message tells us that the segment has a checksum of 0 on the data but the recomputed value is 143703573. This means the segment was written badly due to some serious system failure (cpu/memory/disk or power failure)

You should use wbcheck tool to check all the segments on the cache device and count how many of them are corrupted. Especially, it is important to know if the neighbours (id 1463972723 and 1463972725) are ok.

[nhocchi007]

Thank you for response i will close this topic for now

[nhocchi007]

Hi akira after 12 days, this happen again.
Dmesg:
[Tue Nov 12 16:08:00 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 10976, block bitmap and bg descriptor inconsistent: 16578 vs 30688 free clusters
[Tue Nov 12 17:03:32 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 10992, block bitmap and bg descriptor inconsistent: 16412 vs 30688 free clusters
[Tue Nov 12 18:03:13 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11008, block bitmap and bg descriptor inconsistent: 16267 vs 30688 free clusters
[Tue Nov 12 19:00:05 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11024, block bitmap and bg descriptor inconsistent: 16568 vs 30688 free clusters
[Tue Nov 12 19:43:22 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11040, block bitmap and bg descriptor inconsistent: 16343 vs 30688 free clusters
[Tue Nov 12 20:27:03 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11056, block bitmap and bg descriptor inconsistent: 16330 vs 30688 free clusters
[Tue Nov 12 21:08:46 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11072, block bitmap and bg descriptor inconsistent: 16175 vs 30688 free clusters
[Tue Nov 12 21:52:08 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11088, block bitmap and bg descriptor inconsistent: 16320 vs 30688 free clusters
[Tue Nov 12 22:35:35 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11104, block bitmap and bg descriptor inconsistent: 16193 vs 30688 free clusters
[Tue Nov 12 23:19:07 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11120, block bitmap and bg descriptor inconsistent: 16368 vs 30688 free clusters
[Wed Nov 13 00:03:00 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11136, block bitmap and bg descriptor inconsistent: 16386 vs 30688 free clusters
[Wed Nov 13 00:46:37 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11152, block bitmap and bg descriptor inconsistent: 16350 vs 30688 free clusters
[Wed Nov 13 01:30:54 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11168, block bitmap and bg descriptor inconsistent: 16285 vs 30688 free clusters
[Wed Nov 13 02:14:36 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11184, block bitmap and bg descriptor inconsistent: 16364 vs 30688 free clusters
[Wed Nov 13 02:58:03 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11200, block bitmap and bg descriptor inconsistent: 16440 vs 30688 free clusters
[Wed Nov 13 03:41:40 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11216, block bitmap and bg descriptor inconsistent: 16425 vs 30688 free clusters
[Wed Nov 13 04:24:13 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11232, block bitmap and bg descriptor inconsistent: 16351 vs 30688 free clusters
[Wed Nov 13 05:07:36 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11248, block bitmap and bg descriptor inconsistent: 16384 vs 30688 free clusters
[Wed Nov 13 06:19:28 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11264, block bitmap and bg descriptor inconsistent: 16423 vs 30688 free clusters
[Wed Nov 13 07:37:19 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11280, block bitmap and bg descriptor inconsistent: 16406 vs 30688 free clusters
[Wed Nov 13 08:40:01 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11296, block bitmap and bg descriptor inconsistent: 16429 vs 30688 free clusters
[Wed Nov 13 09:45:42 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11312, block bitmap and bg descriptor inconsistent: 16452 vs 30688 free clusters
[Wed Nov 13 10:25:39 2019] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #248381444: block 3974105123: comm python: bad entry in directory: directory entry across range - offset=0(0), inode=447583694, rec_len=41892, name_len=55
[Wed Nov 13 10:25:39 2019] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #248381442: block 3974105121: comm python: bad entry in directory: rec_len % 4 != 0 - offset=0(0), inode=3381612806, rec_len=13515, name_len=246
[Wed Nov 13 11:03:49 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11328, block bitmap and bg descriptor inconsistent: 16257 vs 30688 free clusters
[Wed Nov 13 12:21:10 2019] EXT4-fs error (device dm-5): ext4_mb_generate_buddy:757: group 11344, block bitmap and bg descriptor inconsistent: 16496 vs 30688 free clusters
[Wed Nov 13 12:50:52 2019] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len is smaller than minimal - offset=0(0), inode=0, rec_len=0, name_len=0
[Wed Nov 13 12:50:52 2019] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len is smaller than minimal - offset=0(0), inode=0, rec_len=0, name_len=0
[Wed Nov 13 12:50:55 2019] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len is smaller than minimal - offset=0(0), inode=0, rec_len=0, name_len=0
[Wed Nov 13 12:52:05 2019] EXT4-fs error (device dm-5): htree_dirblock_to_tree:914: inode #2: block 14654: comm ls: bad entry in directory: rec_len is smaller than minimal - offset=0(0), inode=0, rec_len=0, name_len=0

lsblk still have mountpoint:
NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
sda 8:0 0 2.6T 0 disk
└─sda1 8:1 0 2.6T 0 part
└─ssddisk-ssd 253:2 0 2.6T 0 lvm
└─wbdev 253:5 0 98.2T 0 dm /data
sdb 8:16 0 98.2T 0 disk
└─sdb1 8:17 0 98.2T 0 part
└─hdddisk-hdd 253:4 0 98.2T 0 lvm
└─wbdev 253:5 0 98.2T 0 dm /data
sdd 8:48 0 447.1G 0 disk
├─sdd1 8:49 0 200M 0 part /boot/efi
├─sdd2 8:50 0 1G 0 part /boot
└─sdd3 8:51 0 445.9G 0 part
├─centos-root 253:0 0 217.9G 0 lvm /
├─centos-swap 253:1 0 128G 0 lvm [SWAP]
└─centos-home 253:3 0 100G 0 lvm /home

I have use:
wbcheck /dev/mapper/ssddisk-ssd 1
Return nothing
Is this means all the log was written successfully?

wbcheck /dev/mapper/ssddisk-ssd 447583694
thread 'main' panicked at 'called Result::unwrap() on an Err value: Error { repr: Os { code: 22, message: "Invalid argument" } }', src/libcore/result.rs:868
note: Run with RUST_BACKTRACE=1 for a backtrace.

wbcheck /dev/mapper/ssddisk-ssd 3381612806
thread 'main' panicked at 'Segment id should be int: ParseIntError { kind: Overflow }', src/libcore/result.rs:868
note: Run with RUST_BACKTRACE=1 for a backtrace.

wbcheck /dev/mapper/ssddisk-ssd 3381612806
thread 'main' panicked at 'Segment id should be int: ParseIntError { kind: Overflow }', src/libcore/result.rs:868
note: Run with RUST_BACKTRACE=1 for a backtrace.

wbmeta /dev/mapper/ssddisk-ssd 0
[superblock header]
magic = 4194303 (unformatted)
[superblock record]
last writeback id = 12216299028037412756
What is this mean exactly?
I haven't use fschk yet, so can we trace this root cause together?
Thank you for your time

[akiradeveloper]

Please give segment ID as the parameter, not the inode number.

magic = 4194303 (unformatted)

This means you haven't formatted the caching device.

[nhocchi007]

I use 'ls' it show nothing but i still can access directory and file inside it. Where can i find these segment ID? i can only see block and inode.
dmsetup status wbdev | wbstatus
cursor pos = 554932469

of cache blocks = 697748922

of segments = 5494086

current id = 4369548
last flushed id = 4369547
last writeback id = 4369547

of dirty cache blocks = 0

of partial flushes = 674322

write? hit? on_buffer? fullsize?
0 0 0 0 0
0 0 0 1 428
0 0 1 0 0
0 0 1 1 0
0 1 0 0 1
0 1 0 1 2280880
0 1 1 0 0
0 1 1 1 3
1 0 0 0 0
1 0 0 1 388014592
1 0 1 0 0
1 0 1 1 0
1 1 0 0 0
1 1 0 1 4886139
1 1 1 0 0
1 1 1 1 46002

[akiradeveloper]

You have to understand how dm-writeboost segments the caching device before using it.

My guess is that, as I mentioned earlier, your system is broken. Don't know the disk, memory or cpu. Because dm-writeboost formats the caching device when it is not formatted (so erasing all the cache blocks is done by zeroing the first sector of the caching device). Then, that the superblock is unformatted is just an error.

[nhocchi007]

After erasing all the cache blocks is done by zeroing the first sector of the caching device, the directory is working normal again. So as you said the caching device is not formatted probably causing by system error (Disk, memory, cpu )Right? But i have checked monitor system at error momment happen nothing unsual happens :(

[akiradeveloper]

Really? I didn't tell you should zero the first sector but okay if it works.

Actually, the most of the dirty blocks have been done write-back

current id = 4369548
last flushed id = 4369547
last writeback id = 4369547

then it would probably be ok to discard the caches.

But i have checked monitor system at error momment happen nothing unsual happens :(

Additionally you had better run memory check and badblock if you can. It is very very weird to see that the super block is broken. It is so unusual.

[nhocchi007]

wbcheck /dev/mapper/ssddisk-ssd 4369547 also return nothing so i assume it had been write successfully also.
I will try to check memory and badblock now.

[akiradeveloper]

If you can. Yes.

I don't precisely remember what issue number it was but I remember a user report was finally resolved after the memory was found broken.