ETrace is a syscall tracing utility powered by eBPF.
This is (yet another) strace implementation with a twist:
- ETrace figures out dynamically the parameters of each syscall by parsing the tracepoint format files in the
/sys/kernel/debug/tracing/events/syscalls/*directories - ETrace fetches dynamically the size of each structure of each syscall parameter by parsing the BTF information of the kernel. Once the data is retrieved from kernel space, it uses the same BTF information to parse and format the captured data.
In addition to normal syscall parameters, ETrace also collects process context data on each syscall entry and exit. This context includes:
- The process cgroups
- The process namespaces
- The process credentials
- The process comm
This project was developed on a Ubuntu Hirsute machine (Linux Kernel 5.11).
- golang 1.16+
- (optional) Kernel headers are expected to be installed in
lib/modules/$(uname -r), update theMakefilewith their location otherwise. - (optional) clang & llvm 11.0.1+
- (optional) libbpf-dev
Optional fields are required to recompile the eBPF programs.
- Since ETrace was built using CORE, you shouldn't need to rebuild the eBPF programs. That said, if you want to rebuild the eBPF programs, you can use the following command:
# ~ make build-ebpf- To build ETrace and the custom handler demo, run:
# ~ make build- To install ETrace (copy to /usr/bin/etrace) run:
# ~ make installETrace needs to run as root. Run sudo etrace -h to get help.
# ~ etrace -h
Usage:
etrace [flags]
Flags:
--bytes int amount of bytes shown to the screen when --stdout is provided (default 8)
-c, --comm stringArray list of process comms to filter, leave empty to capture everything
-h, --help help for etrace
--input string input file to parse data from
--json parse and dump the data retrieved from kernel space in the JSON format. This option might lead to more lost events than the --raw option and more CPU usage
-l, --log-level string log level, options: panic, fatal, error, warn, info, debug or trace (default "info")
--raw dump the data retrieved from kernel space without parsing it, use this option instead of the --json option to reduce the amount of lost events, and reduce the CPU usage of ETrace. You can ask ETrace to parse a --raw dump using the --input option
--stats show syscall statistics (default true)
--stdout parse and dump the data retrieved from kernel space to the console. This option might lead to more lost events than the --raw option and more CPU usage.
-s, --syscall stringArray list of syscalls to filter, leave empty to capture everything# ~ sudo etrace --comm cat --stdout
INFO[2021-09-25T21:54:11Z] Tracing started ... (Ctrl + C to stop)
cat(10609) | SysBrk(unsigned long brk: 0) = 93940710199296
cat(10609) | SysArchPrctl(int option: 12289, unsigned long arg2: 140727494090368) = -22
cat(10609) | SysAccess(const char * filename: /etc/ld.so.preload, int mode: 4) = -2
cat(10609) | SysOpenat(int dfd: 4294967196, const char * filename: /etc/ld.so.cache, int flags: 524288, umode_t mode: 0) = 3
cat(10609) | SysNewfstatat(int dfd: 3, const char * filename: NULL, struct stat * statbuf: {uint st_dev: 2049, uint st_ino: 1988, uint st_nlink: 1, uint st_mode: 33188, uint st_uid: 0, uint st_gid: 0, uint __pad0: 0, uint st_rdev: 0, int st_size: 34082, int st_blksize: 4096, int st_blocks: 72, uint st_atime: 1632575756, uint st_atime_nsec: 340000086, uint st_mtime: 1632478351, uint st_mtime_nsec: 721952010, uint st_ctime: 1632478351, uint st_ctime_nsec: 721952010, array __unused: {int 0: 0, int 1: 0, int 2: 0}}, int flag: 4096) = 0
cat(10609) | SysMmap(unsigned long addr: 0, unsigned long len: 34082, unsigned long prot: 1, unsigned long flags: 2, unsigned long fd: 3, unsigned long off: 0) = 140402711691264
cat(10609) | SysClose(unsigned int fd: 3) = 0
cat(10609) | SysOpenat(int dfd: 4294967196, const char * filename: /lib/x86_64-linux-gnu/libc.so.6, int flags: 524288, umode_t mode: 0) = 3
cat(10609) | SysRead(unsigned int fd: 3, char * buf: 0x7f454c4602010103..., size_t count: 832) = 832
cat(10609) | SysPread64(unsigned int fd: 3, char * buf: 0x0600000004000000..., size_t count: 784, loff_t pos: 64) = 784
cat(10609) | SysPread64(unsigned int fd: 3, char * buf: 0x0400000020000000..., size_t count: 48, loff_t pos: 848) = 48
cat(10609) | SysPread64(unsigned int fd: 3, char * buf: 0x0400000014000000..., size_t count: 68, loff_t pos: 896) = 68
[...]
cat(10609) | SysOpenat(int dfd: 4294967196, const char * filename: /etc/hosts, int flags: 0, umode_t mode: 0) = 3
cat(10609) | SysFstat(unsigned int fd: 3, struct stat * statbuf: {uint st_dev: 2049, uint st_ino: 44, uint st_nlink: 1, uint st_mode: 33188, uint st_uid: 0, uint st_gid: 0, uint __pad0: 0, uint st_rdev: 0, int st_size: 262, int st_blksize: 4096, int st_blocks: 8, uint st_atime: 1632575760, uint st_atime_nsec: 904000225, uint st_mtime: 1627389290, uint st_mtime_nsec: 284000207, uint st_ctime: 1627389290, uint st_ctime_nsec: 284000207, array __unused: {int 0: 0, int 1: 0, int 2: 0}}) = 0
cat(10609) | SysFadvise64(int fd: 3, loff_t offset: 0, size_t len: 0, int advice: 2) = 0
cat(10609) | SysMmap(unsigned long addr: 0, unsigned long len: 139264, unsigned long prot: 3, unsigned long flags: 34, unsigned long fd: 4294967295, unsigned long off: 0) = 140402704576512
cat(10609) | SysRead(unsigned int fd: 3, char * buf: 127.0.0.1 localhost
# The following lines are desirable for IPv6 capable hosts
::1 ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
ff02::3 ip6-allhosts
127.0.1.1 ubuntu-hirsute ubuntu-hirsute
, size_t count: 131072) = 262
cat(10609) | SysWrite(unsigned int fd: 1, const char * buf: 127.0.0.1 localhost
# The following lines are desirable for IPv6 capable hosts
::1 ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
ff02::3 ip6-allhosts
127.0.1.1 ubuntu-hirsute ubuntu-hirsute
, size_t count: 262) = 262
cat(10609) | SysRead(unsigned int fd: 3, char * buf: NULL, size_t count: 131072) = 0
cat(10609) | SysMunmap(unsigned long addr: 140402704576512, size_t len: 139264) = 0
cat(10609) | SysClose(unsigned int fd: 3) = 0
cat(10609) | SysClose(unsigned int fd: 1) = 0
cat(10609) | SysClose(unsigned int fd: 2) = 0# ~ sudo etrace --comm postgres --json
INFO[2021-09-25T21:54:11Z] Tracing started ... (Ctrl + C to stop)
INFO[2023-02-25T19:59:32Z] output file: /tmp/etrace-225206860.json
^C
INFO[2023-02-25T19:59:38Z]
INFO[2023-02-25T19:59:38Z] Syscall Name | Sent | Lost
INFO[2023-02-25T19:59:38Z] SysClose | 10 | 5
INFO[2023-02-25T19:59:38Z] SysEpollCtl | 20 | 5
INFO[2023-02-25T19:59:38Z] SysEpollCreate1 | 1 | 0
INFO[2023-02-25T19:59:38Z]
INFO[2023-02-25T19:59:38Z] Total events: 31
INFO[2023-02-25T19:59:38Z] Total lost: 10If you see too many lost events, you can switch to the raw output format and then ask etrace to deserialize the raw file to json.
See the command below for an example.
# ~ sudo etrace --comm postgres --raw
INFO[2021-09-25T21:54:11Z] Tracing started ... (Ctrl + C to stop)
INFO[2023-02-25T19:59:32Z] output file: /tmp/etrace-950342369.raw
^C
INFO[2023-02-25T19:59:38Z]
INFO[2023-02-25T19:59:38Z] Syscall Name | Sent | Lost
INFO[2023-02-25T19:59:38Z] SysClose | 11 | 0
INFO[2023-02-25T19:59:38Z] SysEpollCtl | 22 | 0
INFO[2023-02-25T19:59:38Z] SysEpollCreate1 | 11 | 0
INFO[2023-02-25T19:59:38Z]
INFO[2023-02-25T19:59:38Z] Total events: 44
INFO[2023-02-25T19:59:38Z] Total lost: 0
# ~ sudo etrace --input /tmp/etrace-950342369.raw --json
INFO[2023-02-25T20:02:35Z] Parsing /tmp/etrace-950342369.raw ...
INFO[2023-02-25T20:02:46Z] done ! Output file: /tmp/etrace-801484115.jsonThe script below showcases how you can import ETrace into your projects and stream the kernel events directly to your own handler.
package main
import (
"fmt"
"os"
"os/signal"
"github.com/sirupsen/logrus"
"github.com/Gui774ume/etrace/pkg/etrace"
)
// et is the global etrace tracer
var et *etrace.ETrace
// eventZero is used to reset the event used for parsing in a memory efficient way
var eventZero = etrace.NewSyscallEvent()
// event is used to parse events
var event = etrace.NewSyscallEvent()
// zeroEvent provides an empty event
func zeroEvent() {
*event = *eventZero
}
func main() {
// Set log level
logrus.SetLevel(logrus.TraceLevel)
// create a new ETrace instance
var err error
et, err = etrace.NewETrace(etrace.Options{
EventHandler: myCustomEventHandler,
})
if err != nil {
logrus.Errorf("couldn't instantiate etrace: %v\n", err)
return
}
// start ETrace
if err = et.Start(); err != nil {
logrus.Errorf("couldn't start etrace: %v\n", err)
return
}
logrus.Infoln("Tracing started ... (Ctrl + C to stop)\n")
wait()
if err = et.Stop(); err != nil {
logrus.Errorf("couldn't stop etrace: %v\n", err)
}
}
// wait stops the main goroutine until an interrupt or kill signal is sent
func wait() {
sig := make(chan os.Signal, 1)
signal.Notify(sig, os.Interrupt, os.Kill)
<-sig
fmt.Println()
}
func myCustomEventHandler(data []byte) {
// reset event
zeroEvent()
// parse syscall type
read, err := event.Syscall.UnmarshalSyscall(data)
if err != nil {
logrus.Errorf("failed to decode syscall type: %v", err)
return
}
// find arguments definition
syscallDefinition, ok := et.SyscallDefinitions[event.Syscall]
if ok {
for i := range syscallDefinition.Arguments {
event.Args[i] = etrace.SyscallArgumentValue{
Argument: &syscallDefinition.Arguments[i],
}
}
} else {
logrus.Errorf("couldn't find the syscall definition of %s", event.Syscall)
return
}
// parse the binary data according to the syscall definition
err = event.UnmarshalBinary(data, read, et)
if err != nil {
logrus.Errorf("failed to decode event: %v", err)
return
}
// print the output to the screen
fmt.Printf("%s\n", event.String(50))
}- The golang code is under Apache 2.0 License.
- The eBPF programs are under the GPL v2 License.