Skip to content

Commit

Permalink
tools/syncsnoop: Add more syscalls support
Browse files Browse the repository at this point in the history 
Add fsync(),fdatasync(),syncfs(),sync_file_range(),msync() syscalls to
trace. For example:

    $ sudo ./syncsnoop.py
    TIME(s)            COMM             CALL
    1173253.856512000  worker           fdatasync
    1173260.193706000  sync             sync
    1173261.478894000  syncfs           syncfs
    1173264.231075000  fsync            fsync
    1173264.297788000  fsync            fdatasync
    1173284.063700000  worker           fdatasync
    1173288.229822000  mkfs.ext4        fsync
    1173304.818227000  worker           fdatasync
    1173315.065319000  journal-offline  fsync

Signed-off-by: Rong Tao <[email protected]>
  • Loading branch information
@Rtoax @yonghong-song
Rtoax authored and yonghong-song committed Jul 19, 2024
1 parent e465189 commit a9661e9
Show file tree
Hide file tree
Showing 2 changed files with 132 additions and 12 deletions.
82 changes: 79 additions & 3 deletions tools/syncsnoop.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,35 +12,111 @@
#
# 13-Aug-2015 Brendan Gregg Created this.
# 19-Feb-2016 Allan McAleavy migrated to BPF_PERF_OUTPUT
# 17-Jul-2024 Rong Tao Support more sync syscalls.

from __future__ import print_function
from bcc import BPF
from bcc.utils import printb
import sys

# load BPF program
b = BPF(text="""
#include <linux/sched.h>
enum sync_syscalls {
SYS_T_MIN,
SYS_SYNC,
SYS_FSYNC,
SYS_FDATASYNC,
SYS_MSYNC,
SYS_SYNC_FILE_RANGE,
SYS_SYNCFS,
SYS_T_MAX,
};
struct data_t {
char comm[TASK_COMM_LEN];
u32 sys;
u64 ts;
};
BPF_PERF_OUTPUT(events);
void syscall__sync(void *ctx) {
static void __syscall(void *ctx, enum sync_syscalls sys) {
struct data_t data = {};
bpf_get_current_comm(data.comm, sizeof(data.comm));
data.ts = bpf_ktime_get_ns() / 1000;
data.sys = sys;
events.perf_submit(ctx, &data, sizeof(data));
};
void syscall__sync(void *ctx) {
return __syscall(ctx, SYS_SYNC);
}
void syscall__fsync(void *ctx) {
return __syscall(ctx, SYS_FSYNC);
}
void syscall__fdatasync(void *ctx) {
return __syscall(ctx, SYS_FDATASYNC);
}
void syscall__msync(void *ctx) {
return __syscall(ctx, SYS_MSYNC);
}
void syscall__sync_file_range(void *ctx) {
return __syscall(ctx, SYS_SYNC_FILE_RANGE);
}
void syscall__syncfs(void *ctx) {
return __syscall(ctx, SYS_SYNCFS);
}
""")

class EventType(object):
SYS_SYNC = 1,
SYS_FSYNC = 2,
SYS_FDATASYNC = 3,
SYS_MSYNC = 4,
SYS_SYNC_FILE_RANGE = 5,
SYS_SYNCFS = 6,

sys_names = (
"N/A",
"sync",
"fsync",
"fdatasync",
"msync",
"sync_file_range",
"syncfs",
"N/A",
)

b.attach_kprobe(event=b.get_syscall_fnname("sync"),
fn_name="syscall__sync")
b.attach_kprobe(event=b.get_syscall_fnname("fsync"),
fn_name="syscall__fsync")
b.attach_kprobe(event=b.get_syscall_fnname("fdatasync"),
fn_name="syscall__fdatasync")
b.attach_kprobe(event=b.get_syscall_fnname("msync"),
fn_name="syscall__msync")
b.attach_kprobe(event=b.get_syscall_fnname("sync_file_range"),
fn_name="syscall__sync_file_range")
b.attach_kprobe(event=b.get_syscall_fnname("syncfs"),
fn_name="syscall__syncfs")

# header
print("%-18s %s" % ("TIME(s)", "CALL"))
print("%-18s %-16s %-16s" % ("TIME(s)", "COMM", "CALL"))

# process event
def print_event(cpu, data, size):
event = b["events"].event(data)
print("%-18.9f sync()" % (float(event.ts) / 1000000))
printb(b"%-18.9f %-16s" % (float(event.ts) / 1000000, event.comm), nl="")
print(" %-16s" % sys_names[event.sys])
sys.stdout.flush()

# loop with callback to print_event
Expand Down
62 changes: 53 additions & 9 deletions tools/syncsnoop_example.txt
View file
Original file line number Diff line number Diff line change
@@ -1,14 +1,58 @@
Demonstrations of syncsnoop, the Linux eBPF/bcc version.

This program traces calls to the kernel sync(),fsync(),fdatasync(),syncfs(),
sync_file_range(),msync() routine, with basic timestamps:

This program traces calls to the kernel sync() routine, with basic timestamps:

# ./syncsnoop
TIME(s) CALL
16458148.611952 sync()
16458151.533709 sync()
$ sudo ./syncsnoop.py
TIME(s) COMM CALL
1173253.856512000 worker fdatasync
1173253.858791000 worker fdatasync
1173260.193706000 sync sync
1173261.478894000 syncfs syncfs
1173264.231075000 fsync fsync
1173264.297788000 fsync fdatasync
1173266.303600000 fdatasync fsync
1173266.372047000 fdatasync fdatasync
1173284.063700000 worker fdatasync
1173284.089607000 worker fdatasync
1173288.229822000 mkfs.ext4 fsync
1173288.304501000 mkfs.ext4 fsync
1173288.308225000 mkfs.ext4 fsync
1173288.315048000 mkfs.ext4 fsync
1173304.818227000 worker fdatasync
1173304.885796000 worker fdatasync
1173304.890055000 worker fdatasync
1173304.893487000 worker fdatasync
1173305.351074000 worker fdatasync
1173305.359278000 worker fdatasync
1173314.272416000 worker fdatasync
1173314.301972000 worker fdatasync
1173315.065319000 journal-offline fsync
1173315.065367000 journal-offline fsync
1173315.107918000 journal-offline fsync
1173315.117972000 journal-offline fsync
1173330.613072000 vim fsync
1173337.763989000 vim fsync
1173343.513054000 vim fsync
1173344.479574000 worker fdatasync
1173344.484815000 worker fdatasync
1173345.040061000 systemd-journal fsync
1173374.477736000 vim fsync
1173374.688049000 worker fdatasync
1173374.696112000 worker fdatasync
1173391.717910000 vim fsync
1173400.458152000 vim fsync
1173404.895497000 worker fdatasync
1173404.920379000 worker fdatasync
1173404.946869000 worker fdatasync
1173416.849539000 vim fsync
1173422.885377000 vim fsync
1173427.481849000 sync_file_range sync_file_range
1173435.104840000 worker fdatasync
1173435.131895000 worker fdatasync
1173435.158102000 worker fdatasync
1173449.246568000 vim fsync
^C

While tracing, the "sync" command was executed in another server session.

This can be useful to identify that sync() is being called, and its frequency.
This can be useful to identify that sync(),fsync(),fdatasync(),syncfs(),
sync_file_range(),msync() is being called, and its frequency.

0 comments on commit a9661e9

Please sign in to comment.