got crashes reported in ALF UI, but there is no .c exists in 'log directory'

[uestcmahone]

Hi Seulbae Kim,
I’m using hydra (based on commit id: e7f0c5f) for Linux-4.19 FS fuzzing. I encountered the following problems during the test, hope you can give pointers:

1. In EXPERIMENTS.md, you mentioned "Test cases that trigger crash consistency bugs are stored under the specified log directory.",
   Is the ‘log directory’ refers to /tmp/mosbench/tmpfs-separate/4/log as below, and if so, I got crashes reported in ALF UI, but there is no .c exists?
   Current, my approach is referring to Janus's utils/afl-parse tool for out-ext4-1/fuzzer_ext4-cpu1log1grp1/crashes/id: 000000, sig: 12, src: 000000, op: fs-havoc-generate, rep: 32,
   after parsing, I got three files, .c/.c.raw/.img. Am I doing this correctly?

~/hydra/src$ cat out-ext4-4/fuzzer_ext4-cpu4log4grp4/crashes/README.txt
Command line used to find this crash:

./combined/afl-image-syscall/afl-fuzz -S fuzzer_ext4-cpu4log4grp4 -b shm_ext4-4 -s fs/ext4/ext4_wrapper.so -e samples/oracle/ext4-10.image -y seed_ext4-10 -i in-ext4-4 -o out-ext4-4 -u 4 -- lkl/tools/lkl/ext4-combined-consistency -t ext4 -i samples/oracle/ext4-10.image -e emulator/emulator.py -l /tmp/mosbench/tmpfs-separate/4/log -d /tmp/mosbench/tmpfs-separate/4/ -r -p @@

~/hydra/src$ ./utils/afl-parse_janus -i samples/oracle/ext4-10.image -t ext4 -f out-ext4-4/fuzzer_ext4-cpu4log4grp4/crashes/id\:000000\,sig\:12\,src\:000002\,op\:fs-havoc-generate\,rep\:64 -o poc_id\:000000

output 3 files as below:
poc_id:000000.c
poc_id:000000.c.raw
poc_id:000000.img

[squizz617]

Could you confirm that after running prepare_fuzzing.sh with root permission, tmpfs directory /tmp/mosbench/tmpfs-separate/ is properly created? If so, the log files including the .c file should have been stored under /tmp/mosbench/tmpfs-separate/{CPUID}/log.
You can also get the reproducible test case by the way you did (running utils/afl-parse).

[uestcmahone]

Yes, I ran "sudo sh prepare_fuzzing.sh" as mafeng with root permission, and there are 26956 fileXXXXXX-xxxxx and fileXXXXXX-xxxxx-prog in /tmp/mosbench/tmpfs-separate/{CPUID}/log as below:

ls -lh /tmp/mosbench/tmpfs-separate/1/log/ | grep -v total | wc -l
26956
$ ls -lh /tmp/mosbench/tmpfs-separate/1/log/ | grep -v total | tail -8
-rw-rw-r-- 1 mafeng mafeng 9.1K Mar 28 05:54 fileZzXPJ9-5364
-rw-r--r-- 1 mafeng mafeng 4.9K Mar 28 05:54 fileZzXPJ9-5364-prog
-rw-rw-r-- 1 mafeng mafeng 5.2K Mar 27 21:12 filezzZ3NK-17747
-rw-r--r-- 1 mafeng mafeng 2.4K Mar 27 21:12 filezzZ3NK-17747-prog
-rw-rw-r-- 1 mafeng mafeng 8.4K Mar 28 09:40 fileZZZqsv-9858
-rw-r--r-- 1 mafeng mafeng 4.1K Mar 28 09:40 fileZZZqsv-9858-prog
-rw-rw-r-- 1 mafeng mafeng 4.3K Mar 26 05:42 fileZzZX0a-25559
-rw-r--r-- 1 mafeng mafeng 2.2K Mar 26 05:42 fileZzZX0a-25559-prog
$ file /tmp/mosbench/tmpfs-separate/1/log/fileZzXPJ9-5364
/tmp/mosbench/tmpfs-separate/1/log/fileZzXPJ9-5364: data
$ file /tmp/mosbench/tmpfs-separate/1/log/fileZzXPJ9-5364-prog
/tmp/mosbench/tmpfs-separate/1/log/fileZzXPJ9-5364-prog: data

mafeng@ubuntu:/tmp/mosbench/tmpfs-separate/1/log$file fileZzXPJ9-5364
fileZzXPJ9-5364: data
mafeng@ubuntu:/tmp/mosbench/tmpfs-separate/1/log$ file fileZzXPJ9-5364-prog
fileZzXPJ9-5364-prog: data
mafeng@ubuntu:/tmp/mosbench/tmpfs-separate/1/log$ file fileZzZX0a-25559
fileZzZX0a-25559: C source, UTF-8 Unicode text, with very long lines 

[squizz617]

These files include the test case as source code inside. Try opening fileZzXPJ9-5364 with any text editor of your choice. You'll see the dump of inodes in the recovered image, the PoC, and the description of the bug.

[uestcmahone]

So you mean all 26956/2 cases in this directory should be further triage to determine the uniqueness, I currently just parse the files like ‘id:000000,sig:12,src:000001,op:fs-havoc-generate,rep:8’ in directory ‘hydra/src/out-ext4-2/fuzzer_ext4-cpu2log2grp2/crashes’，could you please help me explain their relationship?

[squizz617]

Files stored under crashes are auto-generated test case by AFL, and each one of them have one-to-one relationship with the files under your_tmpfs/log, which are bug reports created by the crash consistency checker.
So, assuming you start from a clean state, meaning that directories hydra/src/out-ext4-2 and /tmp/mosbench/tmpfs-separate/2/log are both clear, then if you run hydra/src/run.py -t ext4 -c 2 -l 2 -g 2, the number of files under crashes will be equal to the number of files under /tmp/..../log divided by two.

[uestcmahone]

Thank you very much for your comments, Dr. Kim!
Currently, based on my understanding of hydra, I only use utils/afl-pasre to parse file like ‘id:000000,sig:12,src:000001,op:fs-havoc-generate,rep:8’ in directory hydra/src/out-ext4-2/fuzzer_ext4-cpu2log2grp2/crashes，getting poc.c, according to the WIKI in EXPERIMENTS.md, add "echo b> / proc / sysrq-trigger"); " after sync, compile poc.c in a VM with the same kernel, mount the original samples/oracle/ext4-10.image, and run ./poc / mnt. After VM reboot, I don’t know how to find the Crash Inconsistency. I fsck crashed image, but reports no errors, Am I doing correctly? Maybe I should study the principle of SymC3 seriously.

[squizz617]

I'm not Dr yet, though. Please just call me Seulbae :)

The crash inconsistency can be observed after you mount the crashed image.
Let me take an example of a buggy test case I've got from fuzzing F2FS.

$ cat /tmp/mosbench/tmpfs-separate/2/log/fileWF38Iw-28858
./foo	2	4	3	3488	4096	7	755	0		
./foo/bar	2	5	2	3488	4096	7	755	0		
./foo/bar/baz	1	6	1	12	4096	1	644	2936552237		
./foo/bar/acl	1	8	1	0	4096	0	0	0		system.posix_acl_access: ��������������������� ����, 
./foo/bar/æøå	1	9	1	4	4096	1	644	3790240978		
./foo/bar/sln	3	11	1	15	4096	0	777	0	mnt/foo/bar/baz	
./foo/bar/hln	1	7	1	0	4096	0	644	0		user.mime_type: text/plain, 
./3JSMTy3r	1	10	1	0	4096	0	644	0		
=====
#include <sys/types.h>
#include <sys/mount.h>
#include <sys/mman.h>
#include <sys/stat.h>
#include <sys/xattr.h>
#include <sys/syscall.h>

#include <dirent.h>
#include <errno.h>
#include <error.h>
#include <fcntl.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>

int main(int argc, char *argv[])
{
	unsigned char v0[8192] = { 0, };
	unsigned char v1[8192] = { 0, };
	char v2[] = ".";
	char v3[] = "foo";
	char v4[] = "foo/bar";
	char v5[] = "foo/bar/baz";
	char v6[] = "foo/bar/xattr";
	char v7[] = "foo/bar/acl";
	char v8[] = "foo/bar/æøå";
	char v9[] = "foo/bar/fifo";
	char v10[] = "foo/bar/sln";
	char v11[] = "foo/bar/hln";
	long v12;
	char v13[] = "./3JSMTy3r";
	v12 = syscall(SYS_open, (long)v3, 65536, 0);
	syscall(SYS_chmod, (long)v7, 3072);
	syscall(SYS_fsync, (long)v12);
	syscall(SYS_rename, (long)v9, (long)v13);
	syscall(SYS_chmod, (long)v3, 3072);
	syscall(SYS_chmod, (long)v2, 3072);
	syscall(SYS_rename, (long)v6, (long)v11);
	syscall(SYS_fsync, (long)v12);

	close(v12);
	return 0;
}
/* Active fds: v12 */
/* Files
Path: .
Type: dir
Xattrs: 
Path: foo/bar/æøå
Type: file
Xattrs: 
Path: ./3JSMTy3r
Type: file
Xattrs: 
Path: foo/bar/baz
Type: file
Xattrs: 
Path: foo/bar
Type: dir
Xattrs: 
Path: foo/bar/acl
Type: file
Xattrs: 
name: system.posix_acl_access
Path: foo/bar/hln
Type: file
Xattrs: 
name: user.mime_type
Path: foo
Type: dir
Xattrs: 
Path: foo/bar/hln
Type: file
Xattrs: 
Path: foo/bar/sln
Type: symlink
Xattrs: 
*/

=====
*** [META] Mode mismatch in directory ['foo']: em 06000 vs ex 0755

What I do for verifying the case is, I copy the source code from this log (starting from #include <sys/types.h> to the end of main function, and append echo b> / proc / sysrq-trigger"); after the last fsync. Then like what you did, compile it in a VM, mount the image, (say, ext4-10.image) and run the compiled test case. The VM will reboot immediately. Here, you have to mount ext4-10.image again, and then check the mode of directory foo. As the last part of log reports, foo's permission should have been 06000, but you will see it as 0755 because of the crash consistency bug.

I actually demonstrated this during my SOSP'19 presentation by starting the fuzzer in the beginning of the talk and checking and verifying the found test case at the end. You might find the video of the talk useful: https://sosp19.rcs.uwaterloo.ca/videos/D1-S3-P3.mp4 .

[uestcmahone]

Thanks Seulbae! I got it, and will have a try.

[uestcmahone]

Hi Seulbae:
Refer to your comment, I pick some cases from /tmp/mosbench/tmpfs-separate/2/log/

-rw-rw-r-- 1 m00292095 m00292095 2.6K Apr  2 20:58 fileAka6v7-12317
-rw-r--r-- 1 m00292095 m00292095  896 Apr  2 20:58 fileAka6v7-12317-prog
-rw-rw-r-- 1 m00292095 m00292095 2.3K Apr  2 21:05 fileDRYgUP-15910
-rw-r--r-- 1 m00292095 m00292095  729 Apr  2 21:05 fileDRYgUP-15910-prog

fileAka6v7-12317 : *** [META] Missing file: ./foo/bar/baz
fileDRYgUP-15910 : *** [META] Link count mismatch in regular file ['fifo']: em 1 vs ex 2
The last part of log reports as above, and I reproduce in VM as you commented, but the bug can not be reproduced.
Can hydra report Crash Inconsistency by mistake, so many crashes reported on ext4 in about 1 hour! I doubt that I'm not using hydra incorrectly, I use the lkl backported to linux-4.19 by myself instead of the origin lkl, at the same time, I checked the compiling process, no errors reported, anything else I need to check again?

[root@localhost mnt]# ls -lh foo/bar/
total 5.0K
-rw-r--r--+ 1 root root  0 Feb 12  2019 acl
-rw-r--r--  1 root root  4 Feb 12  2019 æøå
-rw-r--r--  2 root root 12 Feb 12  2019 baz   // baz still exists
-rw-r--r--  1 root root  0 Feb 12  2019 fifo
-rw-r--r--  2 root root 12 Feb 12  2019 hln
lrwxrwxrwx  1 root root 15 Feb 12  2019 sln -> mnt/foo/bar/baz
-rw-r--r--  1 root root  0 Feb 12  2019 xattr

[root@localhost mnt]# ls -lh foo/bar/
total 5.0K
-rw-r--r--+ 1 root root  0 Feb 12  2019 acl
-rw-r--r--  1 root root  4 Feb 12  2019 æøå
-rw-r--r--  2 root root 12 Feb 12  2019 baz
-rw-r--r--  1 root root  0 Feb 12  2019 fifo  //Link count = 1 
-rw-r--r--  2 root root 12 Feb 12  2019 hln
lrwxrwxrwx  1 root root 15 Feb 12  2019 sln -> mnt/foo/bar/baz
-rw-r--r--  1 root root  0 Feb 12  2019 xattr

BTW, I found that filexxxxxx-xxxxxxs in /tmp/mosbench/tmpfs-separate/2/log/ have one-to-one relationship with files in hydra/src/out-ext4-2/fuzzer_ext4-10-cpu2log2grp2/crashes/ at the beginning，but as time goes on, they are no longer one-to-one relationship.

** begin **

ls -lh /tmp/mosbench/tmpfs-separate/2/log/
total 52K
-rw-rw-r-- 1 m00292095 m00292095 2.6K Apr  2 20:58 fileAka6v7-12317
-rw-r--r-- 1 m00292095 m00292095  896 Apr  2 20:58 fileAka6v7-12317-prog
-rw-rw-r-- 1 m00292095 m00292095 5.3K Apr  2 21:00 filedVVRHs-8626
-rw-r--r-- 1 m00292095 m00292095 2.4K Apr  2 21:00 filedVVRHs-8626-prog
-rw-rw-r-- 1 m00292095 m00292095 4.6K Apr  2 20:58 filefcqcr1-12218
-rw-r--r-- 1 m00292095 m00292095 2.2K Apr  2 20:58 filefcqcr1-12218-prog
-rw-rw-r-- 1 m00292095 m00292095 6.3K Apr  2 20:58 fileJhoAxQ-12152
-rw-r--r-- 1 m00292095 m00292095 2.8K Apr  2 20:58 fileJhoAxQ-12152-prog
-rw-rw-r-- 1 m00292095 m00292095 3.1K Apr  2 20:59 fileu7kqOx-19461
-rw-r--r-- 1 m00292095 m00292095 1.3K Apr  2 20:59 fileu7kqOx-19461-prog

ls -lh ~/git_repo/hydra/src/out-ext4-2/fuzzer_ext4-10-cpu2log2grp2/crashes/
total 1004K
-rw------- 1 m00292095 m00292095 200K Apr  2 20:58 id:000000,sig:12,src:000002,op:fs-havoc-generate,rep:16
-rw------- 1 m00292095 m00292095 200K Apr  2 20:58 id:000001,sig:12,src:000002,op:fs-havoc-generate,rep:16
-rw------- 1 m00292095 m00292095 198K Apr  2 20:58 id:000002,sig:12,src:000002,op:fs-havoc-generate,rep:16
-rw------- 1 m00292095 m00292095 199K Apr  2 20:59 id:000003,sig:12,src:000002,op:fs-havoc-generate,rep:16
-rw------- 1 m00292095 m00292095 200K Apr  2 21:00 id:000004,sig:12,src:000002,op:fs-havoc-generate,rep:16
-rw------- 1 m00292095 m00292095  945 Apr  2 20:58 README.txt

** about 1 hour later **

ls -lh /tmp/mosbench/tmpfs-separate/2/log/ | grep -v total | wc -l
826

ls -lh  ~/git_repo/hydra/src/out-ext4-2/fuzzer_ext4-10-cpu2log2grp2/crashes/ | grep -v total | wc -l
188

[uestcmahone]

Hi Seulbae:
I've got 3413 files in tmpfs totally, but when I try to reproduce them randomly in VM with the same kernel version, I found all consistencies reported by SymC3 can not be found in VM. Can you give me some advise to debug the situation?
Looking forward to your reply! @squizz617