search

cloudius-systems / osv

OSv, a new operating system for the cloud.
osv.io
Other
4.12k stars 605 forks source link

Add strace functionality #1262

Closed wkozaczuk closed 1 year ago

wkozaczuk commented 1 year ago

This PR implements a simple strace-like mechanism described by https://github.com/cloudius-systems/osv/issues/1263.

In essence, it adds a new structure trace_log that holds a fixed size (64K) an array of pointers to trace_records and acts as a ring buffer between threads capturing active tracepoints (producers) and new thread strace (single consumer) that prints them to the console. The write pointer - write_offset - is atomic that rolls over every 64K and the strace thread follows it and tries to print each trace (see print_trace).

The strace can be activated by adding "--strace" kernel command line argument.

./scripts/firecracker.py -e '--trace=vfs* --strace /hello'
OSv v0.57.0-75-gb7150705
init              0  0.001666500 vfs_mkdir("/dev" 0755)
init              0  0.001685758 vfs_mkdir_ret()
init              0  0.001698722 vfs_dup(0)
init              0  0.001699344 vfs_dup_ret(1)
init              0  0.001699520 vfs_dup(0)
init              0  0.001699644 vfs_dup_ret(2)
>init             0  0.006818073 vfs_mkdir("/rofs" 0755)
>init             0  0.006821609 vfs_mkdir_ret()
Booted up in 13.77 ms
Cmdline: /hello
>init             0  0.008424749 vfs_open("/usr/lib/fs" 0x0 00)
Hello from C code
>init             0  0.008429978 vfs_open_err(2)
>init             0  0.008435063 vfs_open("/etc/fstab" 0x0 00)
>init             0  0.008438018 vfs_open_ret(3)
>init             0  0.008531832 vfs_open("/dev" 0x0 00)
>init             0  0.008534193 vfs_open_ret(4)
>init             0  0.008534456 vfs_close(4)
>init             0  0.008537971 vfs_close_ret()
>init             0  0.008554489 vfs_open("/proc" 0x0 00)
>init             0  0.008556158 vfs_open_ret(4)
>init             0  0.008556252 vfs_close(4)
>init             0  0.008556763 vfs_close_ret()
>init             0  0.008583356 vfs_open("/sys" 0x0 00)
>init             0  0.008585037 vfs_open_ret(4)
>init             0  0.008585171 vfs_close(4)
>init             0  0.008585676 vfs_close_ret()
>init             0  0.008605026 vfs_open("/tmp" 0x0 00)
>init             0  0.008606443 vfs_open_ret(4)
>init             0  0.008606579 vfs_close(4)
>init             0  0.008607093 vfs_close_ret()
>init             0  0.008619345 vfs_close(3)
>init             0  0.008620198 vfs_close_ret()
>init             0  0.008634389 vfs_ioctl(1 0x5401)
>init             0  0.008634974 vfs_ioctl_ret()
>init             0  0.008635317 vfs_pwritev(1 0x200000501690 0x2 0xffffffff)
>init             0  0.008953023 vfs_pwritev_ret(0x16)
>init             0  0.008954858 vfs_pwritev(1 0x200000501660 0x2 0xffffffff)
>init             0  0.009209918 vfs_pwritev_ret(0x11)
>init             0  0.009235297 vfs_open("/init" 0x0 00)
>init             0  0.009237413 vfs_open_err(2)
>init             0  0.009259309 vfs_lstat(pathname=/hello, stat=0x2000004fe5e0)
>init             0  0.009265126 vfs_lstat_ret()
>init             0  0.009265804 vfs_open("/hello" 0x0 00)
>init             0  0.009267528 vfs_open_ret(3)
>init             0  0.009267772 vfs_close(3)
>init             0  0.009268057 vfs_close_ret()
/hello            0  0.009949201 vfs_pwritev(1 0x200000601e90 0x2 0xffffffff)
/hello            0  0.011528630 vfs_pwritev_ret(0x12)

This PR also adds another kernel command line parameter to list all available tracepoints.

Fixes https://github.com/cloudius-systems/osv/issues/1263