We read every piece of feedback, and take your input very seriously.
To see all available qualifiers, see our documentation.
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Tring to delete an empty directory, rm -r print "Invalid argument", and rm -rf returns with exit code 0, but actually do not remove target directory.
rm -r
rm -rf
What I do:
make example
docker exec
toda
io-inject-example.json
/var/run/test
root@e8dc36e9bb98:/var/run/test# mkdir dir lsroot@e8dc36e9bb98:/var/run/test# ls -alh ls: .: Input/output error ls: test: Input/output error total 4.0K drwxr-xr-x. 1 root root 14 Dec 31 06:42 . drwxr-xr-x. 1 root root 42 Dec 31 06:42 .. drwxr-xr-x. 1 root root 0 Dec 31 06:42 dir -rw-r--r--. 1 root root 1.0K Dec 31 06:41 test root@e8dc36e9bb98:/var/run/test# rm -r dir rm: cannot remove 'dir': Invalid argument root@e8dc36e9bb98:/var/run/test# rm -rf dir root@e8dc36e9bb98:/var/run/test# ls -alh total 4.0K drwxr-xr-x. 1 root root 14 Dec 31 06:42 . drwxr-xr-x. 1 root root 42 Dec 31 06:42 .. drwxr-xr-x. 1 root root 0 Dec 31 06:42 dir -rw-r--r--. 1 root root 1.0K Dec 31 06:41 test root@e8dc36e9bb98:/var/run/test#
toda logs:
[2020-12-31 06:42:53.911846 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 44) ino 0x0000000000000001: GETATTR [2020-12-31 06:42:53.911951 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(44) [2020-12-31 06:42:53.911996 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:42:53.912008 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:42:53.912023 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:53.912033 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:53.912039 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:53.912047 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:53.912055 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:54.012839 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:54.012895 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:42:54.013155 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.013255 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.013290 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.013308 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.301693ms, attr: FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:54.013331 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.301693ms, attr: FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:54.013357 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(44) [2020-12-31 06:42:54.015354 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 46) ino 0x0000000000000001: LOOKUP name "dir" [2020-12-31 06:42:54.015457 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(46) [2020-12-31 06:42:54.015499 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:42:54.015512 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:42:54.015527 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:54.015537 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:54.015545 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:54.015552 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:54.015559 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:54.116827 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:54.116881 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:42:54.117127 +00:00] DEBUG [toda::hookfs::reply] src/hookfs/reply.rs:184: err. reply with errno ENOENT: No such file or directory for request (46) [2020-12-31 06:42:54.117284 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 48) ino 0x0000000000000001: GETATTR [2020-12-31 06:42:54.117459 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(48) [2020-12-31 06:42:54.117595 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:42:54.117665 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:42:54.117730 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:54.117760 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:54.117808 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:54.117832 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:54.117842 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:54.218802 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:54.218856 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:42:54.219027 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.219107 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.219171 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.219236 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.575959ms, attr: FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:54.219304 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.575959ms, attr: FileAttr { ino: 2946438, size: 8, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, ctime: SystemTime { tv_sec: 1609396960, tv_nsec: 278761680 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:54.219337 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(48) [2020-12-31 06:42:54.219518 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 50) ino 0x0000000000000001: MKDIR name "dir", mode 0o755 [2020-12-31 06:42:54.219626 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(50) [2020-12-31 06:42:54.219667 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:511: mkdir [2020-12-31 06:42:54.219715 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:54.219743 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:54.219753 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:54.219759 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:54.219767 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:54.320806 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:54.320858 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:521: create directory with mode: S_IRWXU | S_IRUSR | S_IWUSR | S_IXUSR | S_IRGRP | S_IXGRP | S_IROTH | S_IXOTH [2020-12-31 06:42:54.321167 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:523: setting owner 0:0 [2020-12-31 06:42:54.321386 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:42:54.321463 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:42:54.321490 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:54.321556 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:54.321582 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:54.321595 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:54.321606 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:54.422617 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:54.422658 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:42:54.422804 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.422854 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.422864 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:42:54.422879 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:54.422889 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.431387ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:42:54.422919 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.431387ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:42:54.422930 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(50) [2020-12-31 06:42:55.655318 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 52) ino 0x0000000000000001: GETATTR [2020-12-31 06:42:55.655398 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(52) [2020-12-31 06:42:55.655449 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:42:55.655458 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:42:55.655466 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:55.655473 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:55.655478 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:55.655483 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:55.655487 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:55.755831 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:55.755886 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:42:55.756053 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:55.756099 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:55.756116 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:55.756139 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 100.682342ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:55.756162 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 100.682342ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:55.756181 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(52) [2020-12-31 06:42:55.756363 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 54) ino 0x0000000000000001: OPENDIR flags 0x18800 [2020-12-31 06:42:55.756500 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(54) [2020-12-31 06:42:55.756547 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:820: opendir [2020-12-31 06:42:55.756571 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:55.756589 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:55.756601 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:55.756613 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:55.756629 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:55.857834 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:55.858103 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:838: return with fh: 0, flags: 100352 [2020-12-31 06:42:55.858159 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:841: before inject Open { fh: 0, flags: 100352 } [2020-12-31 06:42:55.858179 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:843: after inject Open { fh: 0, flags: 100352 } [2020-12-31 06:42:55.858190 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(54) [2020-12-31 06:42:55.858318 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 56) ino 0x0000000000000001: GETATTR [2020-12-31 06:42:55.858482 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(56) [2020-12-31 06:42:55.858526 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:42:55.858554 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:42:55.858575 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:55.858591 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:55.858604 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:55.858616 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:55.858625 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:55.959879 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:55.959935 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:42:55.960150 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:55.960226 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:55.960246 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:55.960286 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.734568ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:55.960309 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.734568ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396961, tv_nsec: 725740367 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:55.960330 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(56) [2020-12-31 06:42:55.960533 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 58) ino 0x0000000000000001: READDIR fh 0, offset 0, size 4096 [2020-12-31 06:42:55.960781 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:848: readdir [2020-12-31 06:42:55.960850 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:55.960867 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:55.960878 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:55.960890 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:55.960904 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.061815 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.061923 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (2946438, /var/run/__chaosfs__test__/.) into inode_map [2020-12-31 06:42:56.061947 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 2946438, d_off: 1, d_reclen: 24, d_type: 4 }) [2020-12-31 06:42:56.061964 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (2946437, /var/run/__chaosfs__test__/..) into inode_map [2020-12-31 06:42:56.061978 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 2946437, d_off: 2, d_reclen: 24, d_type: 4 }) [2020-12-31 06:42:56.061992 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (2946501, /var/run/__chaosfs__test__/test) into inode_map [2020-12-31 06:42:56.062006 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 2946501, d_off: 12, d_reclen: 24, d_type: 8 }) [2020-12-31 06:42:56.062023 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:42:56.062042 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 3026313, d_off: 2147483647, d_reclen: 24, d_type: 4 }) [2020-12-31 06:42:56.062059 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:927: iterated all files [2020-12-31 06:42:56.062250 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 60) ino 0x0000000000000001: GETATTR [2020-12-31 06:42:56.062379 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(60) [2020-12-31 06:42:56.062482 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:42:56.062502 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:42:56.062524 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.062545 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.062611 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.062663 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.062720 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.163814 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.163868 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:42:56.163998 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.164052 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.164073 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.164098 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.600054ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:56.164126 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.600054ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:56.164148 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(60) [2020-12-31 06:42:56.164647 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 62) ino 0x0000000000000001: GETXATTR name "system.posix_acl_access", size 0 [2020-12-31 06:42:56.164754 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(62) [2020-12-31 06:42:56.164789 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1019: getxattr [2020-12-31 06:42:56.164806 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.164819 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.164832 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.164844 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.164854 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.265840 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.266044 +00:00] DEBUG [toda::hookfs::reply] src/hookfs/reply.rs:184: err. reply with errno UnknownErrno: Unknown errno for request (62) [2020-12-31 06:42:56.266101 +00:00] ERROR [fuser::channel] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/channel.rs:194: Failed to send FUSE reply: Invalid argument (os error 22) [2020-12-31 06:42:56.266747 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 64) ino 0x0000000000000001: GETATTR [2020-12-31 06:42:56.266884 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(64) [2020-12-31 06:42:56.266992 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:42:56.267023 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:42:56.267091 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.267109 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.267125 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.267139 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.267154 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.367811 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.367866 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:42:56.368007 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.368054 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.368107 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.368169 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.152023ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:56.368239 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.152023ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:56.368304 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(64) [2020-12-31 06:42:56.368574 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 66) ino 0x0000000000000001: LOOKUP name "test" [2020-12-31 06:42:56.368657 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(66) [2020-12-31 06:42:56.368690 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:42:56.368707 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/test [2020-12-31 06:42:56.368723 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.368737 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.368749 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.368764 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.368775 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.469589 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.469646 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/test [2020-12-31 06:42:56.469841 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.469930 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.469964 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (2946501, /var/run/__chaosfs__test__/test) into inode_map [2020-12-31 06:42:56.469986 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.470052 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.347578ms, stat: FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:42:56.470100 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.347578ms, stat: FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:42:56.470122 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(66) [2020-12-31 06:42:56.470338 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 68) ino 0x00000000002cf5c5: GETXATTR name "system.posix_acl_access", size 0 [2020-12-31 06:42:56.470473 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(68) [2020-12-31 06:42:56.470502 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1019: getxattr [2020-12-31 06:42:56.470545 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.470562 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.470574 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.470585 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.470600 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.571825 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.572076 +00:00] DEBUG [toda::hookfs::reply] src/hookfs/reply.rs:184: err. reply with errno UnknownErrno: Unknown errno for request (68) [2020-12-31 06:42:56.572158 +00:00] ERROR [fuser::channel] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/channel.rs:194: Failed to send FUSE reply: Invalid argument (os error 22) [2020-12-31 06:42:56.572343 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 70) ino 0x0000000000000001: GETATTR [2020-12-31 06:42:56.572515 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(70) [2020-12-31 06:42:56.572575 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:42:56.572594 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:42:56.572613 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.572627 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.572636 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.572647 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.572659 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.673842 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.673898 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:42:56.674060 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.674224 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.674265 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.674292 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.702301ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:56.674319 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.702301ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:42:56.674339 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(70) [2020-12-31 06:42:56.674566 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 72) ino 0x0000000000000001: LOOKUP name "dir" [2020-12-31 06:42:56.674676 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(72) [2020-12-31 06:42:56.674713 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:42:56.674732 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:42:56.674751 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.674766 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.674777 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.674786 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.674797 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.775805 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.775859 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:42:56.776003 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.776072 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.776093 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:42:56.776111 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:42:56.776132 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.403451ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:42:56.776155 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.403451ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:42:56.776175 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(72) [2020-12-31 06:42:56.776311 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 74) ino 0x00000000002e2d89: GETXATTR name "system.posix_acl_access", size 0 [2020-12-31 06:42:56.776518 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(74) [2020-12-31 06:42:56.776549 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1019: getxattr [2020-12-31 06:42:56.776568 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.776583 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.776593 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.776605 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.776617 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.877833 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.878087 +00:00] DEBUG [toda::hookfs::reply] src/hookfs/reply.rs:184: err. reply with errno EINVAL: Invalid argument for request (74) [2020-12-31 06:42:56.878320 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 76) ino 0x0000000000000001: READDIR fh 0, offset 4, size 4096 [2020-12-31 06:42:56.878468 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:848: readdir [2020-12-31 06:42:56.878509 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:42:56.878529 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:42:56.878541 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:42:56.878554 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:42:56.878569 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:42:56.979827 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:42:56.979912 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:884: empty reply [2020-12-31 06:42:56.980061 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 78) ino 0x0000000000000001: RELEASEDIR fh 0, flags 0x18800, release flags 0x0, lock owner 0 [2020-12-31 06:42:56.980180 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(78) [2020-12-31 06:42:56.980211 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:932: releasedir [2020-12-31 06:42:56.980234 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(78) [2020-12-31 06:43:06.814954 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 80) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:06.815066 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(80) [2020-12-31 06:43:06.815105 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:06.815122 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:06.815148 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:06.815160 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:06.815172 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:06.815212 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:06.815226 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:06.915838 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:06.915894 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:06.916171 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:06.916245 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:06.916270 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:06.916291 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.173116ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:06.916321 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.173116ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:06.916387 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(80) [2020-12-31 06:43:06.916588 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 82) ino 0x0000000000000001: LOOKUP name "dir" [2020-12-31 06:43:06.916689 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(82) [2020-12-31 06:43:06.916718 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:43:06.916768 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:43:06.916804 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:06.916821 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:06.916870 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:06.916920 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:06.916948 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:07.017826 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:07.017881 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:43:07.018112 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.018226 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.018250 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:43:07.018269 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.018291 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.528816ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:07.018312 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.528816ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:07.018334 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(82) [2020-12-31 06:43:07.018500 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 84) ino 0x00000000002e2d89: OPENDIR flags 0x38800 [2020-12-31 06:43:07.018675 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(84) [2020-12-31 06:43:07.018709 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:820: opendir [2020-12-31 06:43:07.018728 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:07.018745 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:07.018762 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:07.018777 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:07.018790 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:07.119841 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:07.120120 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:838: return with fh: 0, flags: 231424 [2020-12-31 06:43:07.120186 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:841: before inject Open { fh: 0, flags: 231424 } [2020-12-31 06:43:07.120214 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:843: after inject Open { fh: 0, flags: 231424 } [2020-12-31 06:43:07.120271 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(84) [2020-12-31 06:43:07.120459 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 86) ino 0x00000000002e2d89: READDIR fh 0, offset 0, size 4096 [2020-12-31 06:43:07.120573 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:848: readdir [2020-12-31 06:43:07.120612 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:07.120618 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:07.120622 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:07.120625 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:07.120632 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:07.221584 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:07.221664 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (3026313, /var/run/__chaosfs__test__/dir/.) into inode_map [2020-12-31 06:43:07.221689 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 3026313, d_off: 1, d_reclen: 24, d_type: 4 }) [2020-12-31 06:43:07.221706 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (2946438, /var/run/__chaosfs__test__/dir/..) into inode_map [2020-12-31 06:43:07.221722 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 2946438, d_off: 2147483647, d_reclen: 24, d_type: 4 }) [2020-12-31 06:43:07.221736 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:927: iterated all files [2020-12-31 06:43:07.221851 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 88) ino 0x00000000002e2d89: READDIR fh 0, offset 2, size 4096 [2020-12-31 06:43:07.221983 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:848: readdir [2020-12-31 06:43:07.222078 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:07.222102 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:07.222111 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:07.222119 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:07.222127 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:07.322832 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:07.322915 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:884: empty reply [2020-12-31 06:43:07.323058 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 90) ino 0x00000000002e2d89: RELEASEDIR fh 0, flags 0x38800, release flags 0x0, lock owner 0 [2020-12-31 06:43:07.323140 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 92) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:07.323275 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(92) [2020-12-31 06:43:07.323328 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:07.323353 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:07.323371 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:07.323386 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:07.323175 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(90) [2020-12-31 06:43:07.323402 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:07.323471 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:07.323464 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:932: releasedir [2020-12-31 06:43:07.323486 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:07.323588 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(90) [2020-12-31 06:43:07.424853 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:07.424911 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:07.425066 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.425122 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.425148 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.425178 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.829692ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:07.425250 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.829692ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:07.425324 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(92) [2020-12-31 06:43:07.425515 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 94) ino 0x0000000000000001: LOOKUP name "dir" [2020-12-31 06:43:07.425627 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(94) [2020-12-31 06:43:07.425665 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:43:07.425685 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:43:07.425706 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:07.425729 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:07.425741 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:07.425751 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:07.425763 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:07.526647 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:07.526703 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:43:07.527335 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.527442 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.527530 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:43:07.527615 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:07.527680 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.971888ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:07.527730 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.971888ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:07.527750 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(94) [2020-12-31 06:43:07.527889 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 96) ino 0x0000000000000001: RMDIR name "dir" [2020-12-31 06:43:07.528056 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(96) [2020-12-31 06:43:07.528163 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:549: rmdir [2020-12-31 06:43:07.528199 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:07.528214 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:07.528226 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:07.528236 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:07.528246 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:07.628795 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:07.629037 +00:00] DEBUG [toda::hookfs::reply] src/hookfs/reply.rs:184: err. reply with errno EINVAL: Invalid argument for request (96) [2020-12-31 06:43:13.165282 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE( 98) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:13.165431 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(98) [2020-12-31 06:43:13.165477 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:13.165493 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:13.165507 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:13.165517 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:13.165525 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:13.165533 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:13.165542 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:13.266995 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:13.267050 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:13.267267 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.267343 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.267365 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.267387 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.897297ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:13.267438 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.897297ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:13.267466 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(98) [2020-12-31 06:43:13.267617 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(100) ino 0x0000000000000001: LOOKUP name "dir" [2020-12-31 06:43:13.267783 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(100) [2020-12-31 06:43:13.267823 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:43:13.267844 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:43:13.267866 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:13.267884 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:13.267896 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:13.267906 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:13.267915 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:13.368651 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:13.368703 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:43:13.368939 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.369012 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.369035 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:43:13.369057 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.369079 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.241769ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:13.369108 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.241769ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:13.369134 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(100) [2020-12-31 06:43:13.369448 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(102) ino 0x00000000002e2d89: OPENDIR flags 0x38800 [2020-12-31 06:43:13.369585 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(102) [2020-12-31 06:43:13.369641 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:820: opendir [2020-12-31 06:43:13.369663 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:13.369679 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:13.369691 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:13.369700 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:13.369712 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:13.470637 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:13.470887 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:838: return with fh: 0, flags: 231424 [2020-12-31 06:43:13.470935 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:841: before inject Open { fh: 0, flags: 231424 } [2020-12-31 06:43:13.470962 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:843: after inject Open { fh: 0, flags: 231424 } [2020-12-31 06:43:13.471029 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(102) [2020-12-31 06:43:13.471246 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(104) ino 0x00000000002e2d89: READDIR fh 0, offset 0, size 4096 [2020-12-31 06:43:13.471396 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:848: readdir [2020-12-31 06:43:13.471496 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:13.471583 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:13.471614 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:13.471629 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:13.471643 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:13.572831 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:13.572911 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (3026313, /var/run/__chaosfs__test__/dir/.) into inode_map [2020-12-31 06:43:13.572937 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 3026313, d_off: 1, d_reclen: 24, d_type: 4 }) [2020-12-31 06:43:13.572955 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (2946438, /var/run/__chaosfs__test__/dir/..) into inode_map [2020-12-31 06:43:13.572970 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 2946438, d_off: 2147483647, d_reclen: 24, d_type: 4 }) [2020-12-31 06:43:13.572984 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:927: iterated all files [2020-12-31 06:43:13.573131 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(106) ino 0x00000000002e2d89: READDIR fh 0, offset 2, size 4096 [2020-12-31 06:43:13.573241 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:848: readdir [2020-12-31 06:43:13.573277 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:13.573293 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:13.573305 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:13.573317 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:13.573328 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:13.673632 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:13.673727 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:884: empty reply [2020-12-31 06:43:13.674058 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(108) ino 0x00000000002e2d89: RELEASEDIR fh 0, flags 0x38800, release flags 0x0, lock owner 0 [2020-12-31 06:43:13.674142 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(110) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:13.674172 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(108) [2020-12-31 06:43:13.674253 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:932: releasedir [2020-12-31 06:43:13.674289 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(108) [2020-12-31 06:43:13.674253 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(110) [2020-12-31 06:43:13.674535 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:13.674567 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:13.674637 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:13.674668 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:13.674681 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:13.674696 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:13.674713 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:13.775972 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:13.776027 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:13.776249 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.776332 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.776360 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.776392 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.830879ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:13.776507 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.830879ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:13.776558 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(110) [2020-12-31 06:43:13.776727 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(112) ino 0x0000000000000001: LOOKUP name "dir" [2020-12-31 06:43:13.776852 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(112) [2020-12-31 06:43:13.776988 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:43:13.777037 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:43:13.777061 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:13.777153 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:13.777190 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:13.777202 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:13.777216 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:13.877591 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:13.877646 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:43:13.877872 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.877947 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.877965 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:43:13.877991 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:13.878012 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 100.982449ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:13.878039 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 100.982449ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:13.878068 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(112) [2020-12-31 06:43:13.878206 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(114) ino 0x0000000000000001: RMDIR name "dir" [2020-12-31 06:43:13.878360 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(114) [2020-12-31 06:43:13.878444 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:549: rmdir [2020-12-31 06:43:13.878467 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:13.878482 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:13.878493 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:13.878504 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:13.878513 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:13.979807 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:13.979974 +00:00] DEBUG [toda::hookfs::reply] src/hookfs/reply.rs:184: err. reply with errno EINVAL: Invalid argument for request (114) [2020-12-31 06:43:24.939076 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(116) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:24.939160 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(116) [2020-12-31 06:43:24.939200 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:24.939208 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:24.939218 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:24.939224 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:24.939230 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:24.939232 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:24.939237 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.039691 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.039743 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.040001 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.040070 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.040097 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.040118 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 100.912049ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.040141 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 100.912049ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.040159 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(116) [2020-12-31 06:43:25.040280 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(118) ino 0x0000000000000001: OPENDIR flags 0x18800 [2020-12-31 06:43:25.040474 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(118) [2020-12-31 06:43:25.040563 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:820: opendir [2020-12-31 06:43:25.040604 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.040628 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.040649 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.040662 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.040681 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.141589 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.141852 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:838: return with fh: 0, flags: 100352 [2020-12-31 06:43:25.141950 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:841: before inject Open { fh: 0, flags: 100352 } [2020-12-31 06:43:25.141973 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:843: after inject Open { fh: 0, flags: 100352 } [2020-12-31 06:43:25.141994 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(118) [2020-12-31 06:43:25.142085 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(120) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:25.142368 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(120) [2020-12-31 06:43:25.142447 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:25.142472 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.142584 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.142615 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.142703 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.142722 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.142735 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.243638 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.243728 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.243938 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.244058 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.244091 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.244115 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.648105ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.244139 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.648105ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.244166 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(120) [2020-12-31 06:43:25.244347 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(122) ino 0x0000000000000001: READDIR fh 0, offset 0, size 4096 [2020-12-31 06:43:25.244522 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:848: readdir [2020-12-31 06:43:25.244619 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.244644 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.244656 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.244673 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.244688 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.345785 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.345896 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (2946438, /var/run/__chaosfs__test__/.) into inode_map [2020-12-31 06:43:25.345931 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 2946438, d_off: 1, d_reclen: 24, d_type: 4 }) [2020-12-31 06:43:25.345949 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (2946437, /var/run/__chaosfs__test__/..) into inode_map [2020-12-31 06:43:25.345963 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 2946437, d_off: 2, d_reclen: 24, d_type: 4 }) [2020-12-31 06:43:25.345974 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (2946501, /var/run/__chaosfs__test__/test) into inode_map [2020-12-31 06:43:25.345988 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 2946501, d_off: 12, d_reclen: 24, d_type: 8 }) [2020-12-31 06:43:25.346001 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:912: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:43:25.346013 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:920: add file Entry(dirent64 { d_ino: 3026313, d_off: 2147483647, d_reclen: 24, d_type: 4 }) [2020-12-31 06:43:25.346027 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:927: iterated all files [2020-12-31 06:43:25.346186 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(124) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:25.346277 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(124) [2020-12-31 06:43:25.346321 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:25.346347 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.346369 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.346384 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.346393 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.346466 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.346481 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.446822 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.446874 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.447042 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.447120 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.447158 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.447181 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 100.838855ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.447209 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 100.838855ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.447230 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(124) [2020-12-31 06:43:25.447500 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(126) ino 0x0000000000000001: GETXATTR name "system.posix_acl_access", size 0 [2020-12-31 06:43:25.447599 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(126) [2020-12-31 06:43:25.447640 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1019: getxattr [2020-12-31 06:43:25.447659 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.447676 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.447691 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.447706 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.447723 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.548828 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.549084 +00:00] DEBUG [toda::hookfs::reply] src/hookfs/reply.rs:184: err. reply with errno EINVAL: Invalid argument for request (126) [2020-12-31 06:43:25.549961 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(128) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:25.550109 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(128) [2020-12-31 06:43:25.550161 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:25.550185 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.550204 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.550218 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.550229 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.550239 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.550249 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.650825 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.650882 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.651109 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.651217 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.651248 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.651269 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.088817ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.651294 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.088817ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.651320 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(128) [2020-12-31 06:43:25.651626 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(130) ino 0x0000000000000001: LOOKUP name "test" [2020-12-31 06:43:25.651780 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(130) [2020-12-31 06:43:25.651828 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:43:25.651849 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/test [2020-12-31 06:43:25.651868 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.651889 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.651903 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.651951 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.651996 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.752864 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.752922 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/test [2020-12-31 06:43:25.753128 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.753202 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.753221 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (2946501, /var/run/__chaosfs__test__/test) into inode_map [2020-12-31 06:43:25.753240 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.753260 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.41735ms, stat: FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:25.753289 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.41735ms, stat: FileAttr { ino: 2946501, size: 1024, blocks: 8, atime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, mtime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, ctime: SystemTime { tv_sec: 1609396879, tv_nsec: 502951441 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: RegularFile, perm: 420, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:25.753314 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(130) [2020-12-31 06:43:25.753511 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(132) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:25.753725 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(132) [2020-12-31 06:43:25.753781 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:25.753806 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.753825 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.753839 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.753851 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.753862 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.753873 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.854824 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.854881 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.855069 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.855152 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.855179 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.855262 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.457858ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.855302 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.457858ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:25.855323 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(132) [2020-12-31 06:43:25.855486 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(134) ino 0x0000000000000001: LOOKUP name "dir" [2020-12-31 06:43:25.855613 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(134) [2020-12-31 06:43:25.855658 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:43:25.855727 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:43:25.855754 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.855776 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.855790 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.855806 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.855823 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:25.956843 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:25.956899 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:43:25.957117 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.957191 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.957210 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:43:25.957229 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:25.957249 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.529864ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:25.957274 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.529864ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:25.957291 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(134) [2020-12-31 06:43:25.957517 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(136) ino 0x0000000000000001: GETATTR [2020-12-31 06:43:25.957642 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(136) [2020-12-31 06:43:25.957660 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:367: getattr [2020-12-31 06:43:25.957679 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:374: getting attr from path /var/run/__chaosfs__test__ [2020-12-31 06:43:25.957702 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:25.957783 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:25.957808 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:25.957821 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:25.957835 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:26.058645 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:26.058696 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__ [2020-12-31 06:43:26.058975 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:26.059058 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:26.059089 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:379: return with FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:26.059180 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:383: before inject Attr { time: 101.504861ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:26.059223 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:385: after inject Attr { time: 101.504861ms, attr: FileAttr { ino: 2946438, size: 14, blocks: 0, atime: SystemTime { tv_sec: 1609396976, tv_nsec: 61529213 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } } [2020-12-31 06:43:26.059250 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(136) [2020-12-31 06:43:26.059558 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(138) ino 0x0000000000000001: LOOKUP name "dir" [2020-12-31 06:43:26.059712 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(138) [2020-12-31 06:43:26.059787 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:329: lookup [2020-12-31 06:43:26.059820 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:337: lookup in /var/run/__chaosfs__test__/dir [2020-12-31 06:43:26.059844 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:26.059864 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:26.059876 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:26.059887 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:26.059897 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:26.160837 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:26.160893 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:1239: async read stat from path /var/run/__chaosfs__test__/dir [2020-12-31 06:43:26.161083 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:308: before inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:26.161133 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:310: after inject attr FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:26.161153 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:343: insert (3026313, /var/run/__chaosfs__test__/dir) into inode_map [2020-12-31 06:43:26.161171 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:350: return with FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 } [2020-12-31 06:43:26.161190 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:354: before inject Entry { time: 101.376772ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:26.161212 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:356: after inject Entry { time: 101.376772ms, stat: FileAttr { ino: 3026313, size: 0, blocks: 0, atime: SystemTime { tv_sec: 1609396987, tv_nsec: 221364838 }, mtime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, ctime: SystemTime { tv_sec: 1609396974, tv_nsec: 320554856 }, crtime: SystemTime { tv_sec: 0, tv_nsec: 0 }, kind: Directory, perm: 493, nlink: 1, uid: 0, gid: 0, rdev: 0, blksize: 4096, padding: 0, flags: 0 }, generation: 0 } [2020-12-31 06:43:26.161233 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(138) [2020-12-31 06:43:26.161448 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(140) ino 0x0000000000000001: READDIR fh 0, offset 4, size 4096 [2020-12-31 06:43:26.161609 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:848: readdir [2020-12-31 06:43:26.161678 +00:00] TRACE [toda::injector::latency_injector] src/injector/latency_injector.rs:23: test for filter [2020-12-31 06:43:26.161701 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:146: path filter: true [2020-12-31 06:43:26.161718 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:147: method filter: true [2020-12-31 06:43:26.161734 +00:00] TRACE [toda::injector::filter] src/injector/filter.rs:148: probability: true [2020-12-31 06:43:26.161748 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:25: inject io delay 100ms [2020-12-31 06:43:26.262850 +00:00] DEBUG [toda::injector::latency_injector] src/injector/latency_injector.rs:27: latency finished [2020-12-31 06:43:26.262948 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:884: empty reply [2020-12-31 06:43:26.263133 +00:00] DEBUG [fuser::request] /root/.cargo/registry/src/github.com-1ecc6299db9ec823/fuser-0.6.0/src/request.rs:63: FUSE(142) ino 0x0000000000000001: RELEASEDIR fh 0, flags 0x18800, release flags 0x0, lock owner 0 [2020-12-31 06:43:26.263253 +00:00] TRACE [toda::hookfs::async_fs] src/hookfs/async_fs.rs:25: reply to request(142) [2020-12-31 06:43:26.263308 +00:00] TRACE [toda::hookfs] src/hookfs/mod.rs:932: releasedir [2020-12-31 06:43:26.263335 +00:00] TRACE [toda::hookfs::reply] src/hookfs/reply.rs:180: ok. reply for request(142)
The text was updated successfully, but these errors were encountered:
No branches or pull requests
Tring to delete an empty directory,
rm -r
print "Invalid argument", andrm -rf
returns with exit code 0, but actually do not remove target directory.What I do:
make example
docker exec
with target containertoda
withio-inject-example.json
/var/run/test
, then execute following commands:toda logs:
The text was updated successfully, but these errors were encountered: