Skip to content

Instantly share code, notes, and snippets.

@waddles

waddles/Command line

Created January 22, 2020 00:05
Download ZIP
Dtrace output of tracing calls from fuse2fs (part of e2fsprogs) to osxfuse
Raw
Command line
# dtrace -s macfuse_u_fuse_fs.d -c "fuse2fs /dev/disk2s1 /tmp/mnt -o rw,uid=$(id -u),gid=$(id -g),allow_other,debug -f"
and in another shell:
bash-5.0# cd /tmp/mnt/foo
bash-5.0# ls
bar.txt foo.txt zip.txt
bash-5.0# cat zip.txt
zip
bash-5.0# echo zip > zip.txt
Raw
dtrace_fuse2fs.txt
bash-5.0# dtrace -s macfuse_u_fuse_fs.d -c "fuse2fs /dev/disk2s1 /tmp/mnt -o rw,uid=$(id -u),gid=$(id -g),allow_other,debug -f"
FUSE library version: 2.9.7
nullpath_ok: 0
nopath: 0
utime_omit_ok: 0
unique: 2, opcode: INIT (26), nodeid: 0, insize: 56, pid: 4719
INIT: 7.19
flags=0xf8000008
max_readahead=0x00100000
INIT: 7.19
flags=0x00000010
max_readahead=0x00100000
max_write=0x02000000
max_background=0
congestion_threshold=0
unique: 2, success, outsize: 40
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 0
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: ACCESS (34), nodeid: 1, insize: 48, pid: 146
access / 00
unique: 2, success, outsize: 16
dtrace: error on enabled probe ID 63 (ID 384780: pid4717:libosxfuse.2.dylib:fuse_fs_new:return): invalid address (0x1d0) in action #7 at DIF offset 12
dtrace: error on enabled probe ID 63 (ID 384780: pid4717:libosxfuse.2.dylib:fuse_fs_new:return): invalid address (0x1d0) in action #7 at DIF offset 12
+473430 14.367 -475744040init
+473535 0.002 0 statfs /
+513357 1.520 0 access /
unique: 2, opcode: ACCESS (34), nodeid: 1, insize: 48, pid: 4705
access / 00
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 4705
getattr /
unique: 2, success, outsize: 136
unique: 2, opcode: LOOKUP (1), nodeid: 1, insize: 44, pid: 4705
LOOKUP /foo
getattr /foo
NODEID: 2
unique: 2, success, outsize: 160
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4705
access /foo 00
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4705
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4705
access /foo 01
unique: 2, success, outsize: 16
+21845374 0.006 0 access /
+21845478 0.008 0 getattr / (st_size=0)
+21846826 1.216 0 getattr /foo (st_size=0)
+21846955 0.004 0 access /foo
+21847004 0.005 0 getattr /foo (st_size=0)
+21847127 0.016 0 access /foo
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4723
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4723
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4723
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4725
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4725
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4725
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4727
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4727
statfs /
unique: 2, success, outsize: 96
unique: 2, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4727
statfs /
unique: 2, success, outsize: 96
+22239607 0.003 0 statfs /
+22239662 0.001 0 statfs /
+22239698 0.001 0 statfs /
+22240873 0.001 0 statfs /
+22240990 0.038 0 statfs /
+22241064 0.001 0 statfs /
+22245066 0.002 0 statfs /
+22245123 0.001 0 statfs /
+22245167 0.001 0 statfs /
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4705
access /foo 01
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4705
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4705
access /foo 00
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4705
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4732
access /foo 01
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4732
access /foo 00
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4732
access /foo 04
unique: 2, success, outsize: 16
unique: 2, opcode: OPENDIR (27), nodeid: 2, insize: 48, pid: 4732
opendir flags: 0x0 /foo
opendir[140340955710848] flags: 0x0 /foo
unique: 2, success, outsize: 32
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4732
access /foo 04
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4732
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4732
access /foo 04
unique: 2, success, outsize: 16
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4732
access /foo 05
unique: 2, success, outsize: 16
unique: 2, opcode: READDIR (28), nodeid: 2, insize: 80, pid: 4732
readdir[140340955710848] from 0
unique: 2, success, outsize: 176
unique: 2, opcode: LOOKUP (1), nodeid: 2, insize: 48, pid: 4732
LOOKUP /foo/bar.txt
getattr /foo/bar.txt
NODEID: 3
unique: 2, success, outsize: 160
unique: 2, opcode: ACCESS (34), nodeid: 3, insize: 48, pid: 4732
access /foo/bar.txt 00
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 3, insize: 56, pid: 4732
getattr /foo/bar.txt
unique: 2, success, outsize: 136
unique: 2, opcode: LOOKUP (1), nodeid: 2, insize: 48, pid: 4732
LOOKUP /foo/foo.txt
getattr /foo/foo.txt
NODEID: 4
unique: 2, success, outsize: 160
unique: 2, opcode: ACCESS (34), nodeid: 4, insize: 48, pid: 4732
access /foo/foo.txt 00
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 4, insize: 56, pid: 4732
getattr /foo/foo.txt
unique: 2, success, outsize: 136
unique: 2, opcode: LOOKUP (1), nodeid: 2, insize: 48, pid: 4732
LOOKUP /foo/zip.txt
getattr /foo/zip.txt
NODEID: 5
unique: 2, success, outsize: 160
unique: 2, opcode: ACCESS (34), nodeid: 5, insize: 48, pid: 4732
access /foo/zip.txt 00
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4732
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: READDIR (28), nodeid: 2, insize: 80, pid: 4732
unique: 2, success, outsize: 16
unique: 2, opcode: READDIR (28), nodeid: 2, insize: 80, pid: 4732
unique: 2, success, outsize: 16
unique: 2, opcode: READDIR (28), nodeid: 2, insize: 80, pid: 4732
unique: 2, success, outsize: 16
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4732
access /foo 05
unique: 2, success, outsize: 16
unique: 2, opcode: RELEASEDIR (29), nodeid: 2, insize: 64, pid: 4732
releasedir[140340955710848] flags: 0x0
unique: 2, success, outsize: 16
+34948457 0.014 0 access /foo
+34948544 0.007 0 getattr /foo (st_size=0)
+34948599 0.003 0 access /foo
+34948642 0.004 0 getattr /foo (st_size=0)
+34952483 0.014 0 access /foo
+34952555 0.009 0 getattr /foo (st_size=0)
+34952614 0.003 0 access /foo
+34952683 0.015 0 getattr /foo (st_size=0)
+34952755 0.006 0 getattr /foo (st_size=0)
+34952808 0.005 0 getattr /foo (st_size=0)
+34952875 0.004 0 getattr /foo (st_size=0)
+34952943 0.005 0 access /foo
+34952992 0.008 0 opendir /foo
+34953045 0.004 0 getattr /foo (st_size=0)
+34953119 0.017 0 getattr /foo (st_size=0)
+34953975 0.018 0 getattr /foo (st_size=0)
+34954054 0.005 0 access /foo
+34954117 0.006 0 getattr /foo (st_size=0)
+34954168 0.006 0 getattr /foo (st_size=0)
+34954234 0.006 0 getattr /foo (st_size=0)
+34954295 0.003 0 access /foo
+34954348 0.004 0 access /foo
+34955862 1.472 0 readdir /foo
+34955923 0.007 0 getattr /foo/bar.txt (st_size=0)
+34955995 0.004 0 access /foo/bar.txt
+34956050 0.007 0 getattr /foo/bar.txt (st_size=0)
+34956102 0.005 0 getattr /foo/foo.txt (st_size=0)
+34956166 0.004 0 access /foo/foo.txt
+34956214 0.006 0 getattr /foo/foo.txt (st_size=0)
+34956267 0.005 0 getattr /foo/zip.txt (st_size=0)
+34956347 0.005 0 access /foo/zip.txt
+34956389 0.005 0 getattr /foo/zip.txt (st_size=0)
+34956506 0.003 0 access /foo
+34956606 0.002 0 releasedir /foo
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4705
access /foo 01
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4705
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4705
access /foo 00
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 4705
getattr /foo
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4735
access /foo 01
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4735
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4735
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4735
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 5, insize: 48, pid: 4735
access /foo/zip.txt 04
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4735
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: OPEN (14), nodeid: 5, insize: 48, pid: 4735
open flags: 0x0 /foo/zip.txt
open[140340957807088] flags: 0x0 /foo/zip.txt
unique: 2, success, outsize: 32
unique: 2, opcode: READ (15), nodeid: 5, insize: 80, pid: 4735
read[140340957807088] 4 bytes from 0 flags: 0x0
read[140340957807088] 4 bytes from 0
unique: 2, success, outsize: 20
unique: 2, opcode: FLUSH (25), nodeid: 5, insize: 64, pid: 4735
flush[140340957807088]
lock[140340957807088] F_SETLK F_UNLCK start: 0 len: 0 pid: 0
unique: 2, error: -78 (Function not implemented), outsize: 16
unique: 2, opcode: RELEASE (18), nodeid: 5, insize: 64, pid: 4735
release[140340957807088] flags: 0x0
unique: 2, success, outsize: 16
+46981493 0.013 0 access /foo
+46981573 0.008 0 getattr /foo (st_size=0)
+46981658 0.007 0 access /foo
+46981746 0.012 0 getattr /foo (st_size=0)
+46985596 0.008 0 access /foo
+46985671 0.010 0 getattr /foo/zip.txt (st_size=0)
+46985726 0.005 0 getattr /foo/zip.txt (st_size=0)
+46985805 0.007 0 getattr /foo/zip.txt (st_size=0)
+46985868 0.004 0 access /foo/zip.txt
+46985928 0.009 0 getattr /foo/zip.txt (st_size=0)
+46985984 0.005 0 open /foo/zip.txt
+46987232 1.181 0 read_buf /foo/zip.txt
+46987322 0.002 -78 flush /foo/zip.txt
+46987339 0.001 -78 lock /foo/zip.txt
+46987401 0.002 0 release /foo/zip.txt
unique: 2, opcode: ACCESS (34), nodeid: 2, insize: 48, pid: 4705
access /foo 01
unique: 2, success, outsize: 16
unique: 2, opcode: LOOKUP (1), nodeid: 2, insize: 48, pid: 4705
LOOKUP /foo/zip.txt
getattr /foo/zip.txt
NODEID: 5
unique: 2, success, outsize: 160
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4705
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: ACCESS (34), nodeid: 5, insize: 48, pid: 4705
access /foo/zip.txt 02
unique: 2, success, outsize: 16
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4705
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: OPEN (14), nodeid: 5, insize: 48, pid: 4705
open flags: 0x1 /foo/zip.txt
open[140340992411200] flags: 0x1 /foo/zip.txt
unique: 2, success, outsize: 32
unique: 2, opcode: SETATTR (4), nodeid: 5, insize: 168, pid: 4705
fsetattr_x[140340992411200] /foo/zip.txt
ftruncate[140340992411200] 0
fgetattr[140340992411200] /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4705
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: WRITE (16), nodeid: 5, insize: 84, pid: 4705
write[140340992411200] 4 bytes to 0 flags: 0x1
write[140340992411200] 4 bytes to 0
unique: 2, success, outsize: 24
unique: 2, opcode: GETATTR (3), nodeid: 5, insize: 56, pid: 4705
getattr /foo/zip.txt
unique: 2, success, outsize: 136
unique: 2, opcode: RELEASE (18), nodeid: 5, insize: 64, pid: 4705
release[140340992411200] flags: 0x1
unique: 3, opcode: ACCESS (34), nodeid: 1, insize: 48, pid: 146
access / 01
+66429461 0.010 0 access /foo
+66429544 0.009 0 getattr /foo/zip.txt (st_size=0)
+66429649 0.012 0 getattr /foo/zip.txt (st_size=0)
+66429790 0.009 0 access /foo/zip.txt
+66429876 0.008 0 getattr /foo/zip.txt (st_size=0)
+66430008 0.020 0 open /foo/zip.txt
+66430115 0.002 -78 fsetattr_x /foo/zip.txt
+66430165 0.030 0 ftruncate /foo/zip.txt
+66430185 0.002 0 fgetattr /foo/zip.txt
+66430253 0.008 0 getattr /foo/zip.txt (st_size=0)
+66430462 0.032 4 write_buf /foo/zip.txt
+66430585 0.011 0 getattr /foo/zip.txt (st_size=0)
unique: 4, opcode: INTERRUPT (36), nodeid: 0, insize: 48, pid: 4705
INTERRUPT: 2
unique: 5, opcode: INTERRUPT (36), nodeid: 0, insize: 48, pid: 146
INTERRUPT: 3
unique: 6, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4743
statfs /
unique: 6, success, outsize: 96
unique: 7, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4741
statfs /
unique: 6, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4743
unique: 7, success, outsize: 96
statfs /
unique: 6, success, outsize: 96
unique: 7, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4741
statfs /
unique: 6, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4743
unique: 7, success, outsize: 96
statfs /
unique: 6, success, outsize: 96
unique: 7, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4741
statfs /
unique: 7, success, outsize: 96
unique: 6, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4745
statfs /
unique: 6, success, outsize: 96
unique: 7, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4745
statfs /
unique: 7, success, outsize: 96
unique: 6, opcode: STATFS (17), nodeid: 1, insize: 40, pid: 4745
statfs /
unique: 6, success, outsize: 96
+154057065 0.003 0 statfs /
+154057128 0.001 0 statfs /
+154057147 0.001 0 statfs /
+154057178 0.001 0 statfs /
+154057223 0.008 0 statfs /
+154057261 0.001 0 statfs /
+154064722 0.002 0 statfs /
+154064773 0.001 0 statfs /
+154064815 0.001 0 statfs /
unique: 2, success, outsize: 16
unique: 3, success, outsize: 16
+308296426 241865.777 0 release /foo/zip.txt
+308296482 241855.423 0 access /
+346313851 38012.536 1035 destroy
dtrace: error on enabled probe ID 110 (ID 384682: pid4717:libosxfuse.2.dylib:fuse_fs_destroy:return): invalid address (0x1d0) in action #7 at DIF offset 12
dtrace: error on enabled probe ID 110 (ID 384682: pid4717:libosxfuse.2.dylib:fuse_fs_destroy:return): invalid address (0x1d0) in action #7 at DIF offset 12
Raw
macfuse_u_fuse_fs.d
#! /usr/sbin/dtrace -s
#pragma D option quiet
BEGIN
{
begints = timestamp;
}
pid$target:libosxfuse*dylib:fuse_fs_init:entry,
pid$target:libosxfuse*dylib:fuse_fs_destroy:entry
{
self->begints = timestamp;
self->init_destroy = 1;
}
pid$target:libosxfuse*dylib:fuse_fs_init:return,
pid$target:libosxfuse*dylib:fuse_fs_destroy:return
/ self->init_destroy /
{
this->elapsed = timestamp - self->begints;
printf("+%-12d %3d.%03d %-8d%-16s\n", (timestamp - begints) / 1000,
this->elapsed / 1000000, (this->elapsed / 1000) % 1000,
(int)arg1, probefunc + 8);
self->begints = 0;
self->init_destroy = 0;
}
pid$target:libosxfuse*dylib:fuse_fs*:entry
/ !self->init_destroy /
{
self->traceme = 1;
self->pathptr = arg1;
self->begints = timestamp;
self->arg2 = arg2;
}
pid$target:libosxfuse*dylib:fuse_fs*:return
/ self->traceme && probefunc != "fuse_fs_getattr" /
{
this->elapsed = timestamp - self->begints;
printf("+%-12d %3d.%03d %-8d%-16s%s\n", (timestamp - begints) / 1000,
this->elapsed / 1000000, (this->elapsed / 1000) % 1000,
(int)arg1, probefunc + 8, copyinstr(self->pathptr));
self->traceme = 0;
self->pathptr = 0;
self->begints = 0;
}
pid$target:libosxfuse*dylib:fuse_fs*:return
/ self->traceme && probefunc == "fuse_fs_getattr" /
{
this->elapsed = timestamp - self->begints;
this->st = (struct stat *)copyin(self->arg2, sizeof(struct stat));
printf("+%-12d %3d.%03d %-8d%-16s%s (st_size=%lld)\n", (timestamp - begints) / 1000,
this->elapsed / 1000000, (this->elapsed / 1000) % 1000,
(int)arg1, probefunc + 8, copyinstr(self->pathptr), this->st->st_size);
self->traceme = 0;
self->pathptr = 0;
self->begints = 0;
}
@waddles
Copy link
Author

waddles commented Jan 22, 2020

/dev/disk2 is a generic USB thumbdrive attached to my Acer XR341CK monitor's USB hub, attached via an ALOGIC dock to my MacBook Pro running macOS Catalina

/dev/disk2s1 is an Ext2 formatted filesystem on a MBR partition

bash-5.0# diskutil list /dev/disk2
/dev/disk2 (external, physical):
   #:                       TYPE NAME                    SIZE       IDENTIFIER
   0:     FDisk_partition_scheme                        *15.6 GB    disk2
   1:                      Linux                         15.6 GB    disk2s1

@waddles
Copy link
Author

waddles commented Jan 22, 2020

Using a local file on the hard drive formatted as Ext2 and mounted over Fuse, this is what calls are made when I do echo bar > bar.txt

Start_Time  Time_In_Call  Return_code  Function  Path

+41111337       0.009 0       access          /foo
+41111436       0.009 -2      getattr         /foo/bar.txt (st_size=0)
+41111542       0.010 0       getattr         /foo (st_size=0)
+41111633       0.004 0       access          /foo
+41111735       0.008 0       getattr         /foo (st_size=0)
+41111819       0.018 0       create          /foo/bar.txt
+41111842       0.002 0       fgetattr        /foo/bar.txt
+41111933       0.009 -2      getattr         /foo/._bar.txt (st_size=0)
+41111989       0.007 0       getattr         /foo/bar.txt (st_size=0)
+41112048       0.006 0       getattr         /foo/bar.txt (st_size=0)
+41112108       0.007 0       getattr         /foo/bar.txt (st_size=0)
+41112246       0.023 4       write_buf       /foo/bar.txt
+41113200       0.008 0       getattr         /foo/bar.txt (st_size=0)
+41113254       0.001 -78     flush           /foo/bar.txt
+41113269       0.001 -78     lock            /foo/bar.txt
+41113598       0.283 0       release         /foo/bar.txt
+41113665       0.014 0       getattr         /foo/bar.txt (st_size=0)
+41122239       0.004 0       access          /foo
+41122290       0.006 0       getattr         /foo (st_size=0)
+41339430       0.029 0       access          /foo
+41339550       0.007 0       access          /foo/bar.txt
+41339703       0.019 0       getattr         /foo/bar.txt (st_size=0)

See how it's different to the calls over USB:

+66429461       0.010 0       access          /foo
+66429544       0.009 0       getattr         /foo/zip.txt (st_size=0)
+66429649       0.012 0       getattr         /foo/zip.txt (st_size=0)
+66429790       0.009 0       access          /foo/zip.txt
+66429876       0.008 0       getattr         /foo/zip.txt (st_size=0)
+66430008       0.020 0       open            /foo/zip.txt
+66430115       0.002 -78     fsetattr_x      /foo/zip.txt
+66430165       0.030 0       ftruncate       /foo/zip.txt
+66430185       0.002 0       fgetattr        /foo/zip.txt
+66430253       0.008 0       getattr         /foo/zip.txt (st_size=0)
+66430462       0.032 4       write_buf       /foo/zip.txt
+66430585       0.011 0       getattr         /foo/zip.txt (st_size=0)
+154057065      0.003 0       statfs          /                     <<<< echo command completes at this point
+154057128      0.001 0       statfs          /
+154057147      0.001 0       statfs          /
+154057178      0.001 0       statfs          /
+154057223      0.008 0       statfs          /
+154057261      0.001 0       statfs          /
+154064722      0.002 0       statfs          /
+154064773      0.001 0       statfs          /
+154064815      0.001 0       statfs          /
+308296426    241865.777 0       release         /foo/zip.txt
+308296482    241855.423 0       access          /

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment