Merge Parallel strace Logs into a Readable Timeline

By the end of this guide, you will have one chronologically sorted view of a process tree captured by strace -ff. That makes concurrent children easier to follow than opening one PID log at a time. The examples use strace 6.8, supplied by the Ubuntu package strace 6.8-0ubuntu2.

Allow about 10 minutes. You need strace and strace-log-merge installed, a shell, and a command that is safe to observe. Tracing a command does not normally require elevated privileges, but attaching to an existing process often does. This guide only starts a new command.

1. Check the installed command

First, confirm that the helper is on your path and read its local usage text. This is a read-only check.

$ command -v strace-log-merge
/usr/bin/strace-log-merge
$ strace-log-merge --help
Usage: strace-log-merge STRACE_LOG

Finds all STRACE_LOG.PID files, adds PID prefix to every line,
then combines and sorts them, and prints result to standard output.

The argument is a file name prefix, not one complete log name. If the prefix is trace, the helper reads files matching trace.*. It adds the PID from each suffix to every output line, then sorts using the timestamp in the trace.

2. Capture a small process tree

Choose an output prefix that is private to this run. The -ff option gives each traced process its own file, while -tt adds a time-of-day timestamp with microseconds. The trace filter below keeps the demonstration short.

$ mkdir -p "$HOME/strace-merge-demo"
$ cd "$HOME/strace-merge-demo"
$ strace -o sleepy -ff -tt -e trace=execve,nanosleep \
    sh -c 'sleep 0.1 & sleep 0.2 & sleep 0.3'
$ ls -1 sleepy.*
sleepy.12340
sleepy.12341
sleepy.12342
sleepy.12343

Your numeric suffixes will differ. The shell and each background sleep can receive different PIDs, so do not copy the names from the example into a later command. The command writes trace files in the current directory and does not alter the traced program's files.

Checkpoint: confirm the input files

Before merging, make sure the prefix points at this session and not at an older capture.

$ printf '%s\n' sleepy.*
sleepy.12340
sleepy.12341
sleepy.12342
sleepy.12343

A stale file with the same prefix will be included. Use a new directory or a new prefix for each capture. If these logs contain command arguments or environment-derived data, treat them as sensitive and set their permissions or remove them after checking. Do not upload them casually.

3. Merge and inspect the timeline

Pass only the prefix to strace-log-merge. It writes the combined result to standard output, so redirect it if you want a durable report.

$ strace-log-merge sleepy | head -12
12340 21:13:52.040837 execve("/bin/sh", ["sh", "-c", "sleep 0.1 & sleep 0.2 & sleep 0.3"], ...) = 0
12343 21:13:52.044050 execve("/bin/sleep", ["sleep", "0.3"], ...) = 0
12341 21:13:52.044269 execve("/bin/sleep", ["sleep", "0.1"], ...) = 0
12342 21:13:52.044389 execve("/bin/sleep", ["sleep", "0.2"], ...) = 0
12343 21:13:52.046207 nanosleep({tv_sec=0, tv_nsec=300000000}, NULL) = 0
12341 21:13:52.046303 nanosleep({tv_sec=0, tv_nsec=100000000}, NULL) = 0

The PIDs and exact timestamps vary. The useful property is the order: lines from different files are interleaved by their trace timestamps, while the PID at the beginning identifies the process that made each call.

Save the complete merge when you need to search it later:

$ strace-log-merge sleepy > merged.log
$ grep -E 'execve|nanosleep|exited|SIGCHLD' merged.log | head

The second command is ordinary inspection. It does not change the trace.

4. Use absolute timestamps when a run can cross midnight

With -tt, the timestamp contains only the time of day. The manpage warns that sorting becomes unreliable when one run passes midnight, because the date is missing. Capture with -ttt instead; it records seconds since the Unix epoch and preserves ordering across midnight.

$ strace -o overnight -ff -ttt -e trace=execve,nanosleep \
    sh -c 'sleep 0.1' >/dev/null 2>&1
$ strace-log-merge overnight | head -4
12350 1790479678.986258 execve("/usr/bin/sh", ["sh", "-c", "sleep 0.1"], ...) = 0
12351 1790479678.987814 execve("/usr/bin/sleep", ["sleep", "0.1"], ...) = 0
12351 1790479679.000574 +++ exited with 0 +++
12350 1790479679.000621 --- SIGCHLD ...

Do not mix old trace.* files with a new trace.* set. The helper assumes that every matching file came from one strace session and does not check the file format.

5. Diagnose failures without guessing

A missing argument prints usage and exits non-zero. A prefix with no matching trace files also fails; it does not silently produce an empty report.

$ strace-log-merge no-such-prefix
strace-log-merge: no-such-prefix: strace output not found
$ echo $?
1

If this happens, check the current directory, the exact prefix, and the files produced by -ff. Remember that -o sleepy produces names such as sleepy.12340; passing sleepy.12340 as the helper argument would make it search for sleepy.12340.*.

If the output is not in chronological order, check that the trace was made with -tt or -ttt, and that all matching files belong to the same run. The helper does not validate those assumptions.