Skip to content

Instantly share code, notes, and snippets.

@sirupsen
Last active July 17, 2020 07:37
Show Gist options
  • Save sirupsen/9fd5fe9466e82df073ed8a13ed1f661f to your computer and use it in GitHub Desktop.
Save sirupsen/9fd5fe9466e82df073ed8a13ed1f661f to your computer and use it in GitHub Desktop.
tracepoint:syscalls:sys_exit_fsync,tracepoint:syscalls:sys_exit_fdatasync
/comm == str($1)/
{
@bytes = lhist((nsecs - @start[tid]) / 1000, 0, 1500, 100);
delete(@start[tid]);
}
tracepoint:syscalls:sys_enter_fsync,tracepoint:syscalls:sys_enter_fdatasync
/comm == str($1)/
{
@start[tid] = nsecs;
@fsyncs[args->fd] = count();
if (@fd_to_filename[args->fd]) {
} else {
@fd_to_filename[args->fd] = 1;
system("echo -n 'fd %d -> ' &1>&2 | readlink /proc/%d/fd/%d", args->fd, pid, args->fd);
}
}
END {
clear(@fd_to_filename);
}
$ RUSTFLAGS='-C target-cpu=native' cargo run --release -- -e mysql
# 32 threads, 1000 records per thread
Executing mysql_write..
Elapsed: 3813ms
Records: 32000
Insertions/second: 10666
# In another terminal..
personal@napkin:~$ sudo bpftrace --unsafe fsync_count_by_fd.d mysqld
Attaching 5 probes...
fd 5 -> /var/lib/mysql/ib_logfile0
fd 99 -> /var/lib/mysql/binlog.000019
fd 34 -> /var/lib/mysql/napkin/products.ibd
fd 11 -> /var/lib/mysql/#ib_16384_0.dblwr
fd 27 -> /var/lib/mysql/mysql.ibd
fd 15 -> /var/lib/mysql/undo_002
fd 13 -> /var/lib/mysql/undo_001
fd 9 -> /var/lib/mysql/ibdata1
fd 12 -> /var/lib/mysql/#ib_16384_1.dblwr
^C
@bytes:
[0, 100) 386 |@@@@@@@@@@ |
[100, 200) 11 | |
[200, 300) 739 |@@@@@@@@@@@@@@@@@@@ |
[300, 400) 1953 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[400, 500) 418 |@@@@@@@@@@@ |
[500, 600) 400 |@@@@@@@@@@ |
[600, 700) 264 |@@@@@@@ |
[700, 800) 224 |@@@@@ |
[800, 900) 855 |@@@@@@@@@@@@@@@@@@@@@@ |
[900, 1000) 1346 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[1000, 1100) 590 |@@@@@@@@@@@@@@@ |
[1100, 1200) 215 |@@@@@ |
[1200, 1300) 165 |@@@@ |
[1300, 1400) 118 |@@@ |
[1400, 1500) 111 |@@ |
[1500, ...) 399 |@@@@@@@@@@ |
@fsyncs[9]: 2
@fsyncs[12]: 2
@fsyncs[27]: 12
@fsyncs[34]: 47
@fsyncs[13]: 86
@fsyncs[15]: 93
@fsyncs[11]: 103
@fsyncs[99]: 2962
@fsyncs[5]: 4887
$ target/release/base-rates -e disk_write_sequential_fsync
Executing disk_write_sequential_fsync..
[Sequential Disk Write, Fsync <8 KiB>] Iterations in 5007 miliseconds, no overhead: 5,559
[Sequential Disk Write, Fsync <8 KiB>] Iterations / second: 1,110
[Sequential Disk Write, Fsync <8 KiB>] Bytes handled per iteration: 8192 bytes
[Sequential Disk Write, Fsync <8 KiB>] Total bytes processed: 43.430 MiB
[Sequential Disk Write, Fsync <8 KiB>] Throughput: 8.674 MiB/s
[Sequential Disk Write, Fsync <8 KiB>] Avg single iteration: 900 μs
[Sequential Disk Write, Fsync <8 KiB>] Avg single iteration cycles: 2792570.90
[Sequential Disk Write, Fsync <8 KiB>] Time to process 1 MiB: 115 ms
[Sequential Disk Write, Fsync <8 KiB>] Time to process 1 GiB: 118.07 s
[Sequential Disk Write, Fsync <8 KiB>] Time to process 1 TiB: 33.59 hours
# in other terminal
personal@napkin:~$ sudo bpftrace --unsafe fsync_count_by_fd.d base-rates
Attaching 5 probes...
fd 3 -> /tmp/napkin.txt
fd 4 -> /tmp/napkin.txt
^C
@bytes:
[700, 800) 153 |@@ |
[800, 900) 3385 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[900, 1000) 2004 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[1000, 1100) 71 |@ |
[1100, 1200) 17 | |
[1200, 1300) 17 | |
[1300, 1400) 7 | |
[1400, 1500) 3 | |
[1500, ...) 11 | |
@fsyncs[3]: 109
@fsyncs[4]: 5559
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment