iovisor / iovisor/bcc

execsnoop: long timestamps unintentionally merge columns

Open Beginner friendly
#4,916 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
C
Stars
22.7k
Forks
4.1k
Avg merge
5d 13h
Merged PRs (30d)
3

Description

I was trying to debug an issue by running `execsnoop-bpfcc -t | tee execsnoop.log`, and later on using `awk` to follow the process chains (ie. search for a specific process, get its PPID, search for the parent, get its PPID, ...). This works as long as the timestamps are < 1000s, because here there is whitespace between the first two columns:

```
971.495 sh 3220534 3220523 0 /bin/sh -c curl -fSs http://localhost:8008/health || exit 1
```

Unfortunately, as soon as the timestamps grow >1000s, the separating whitespace is gone:

```
1001.659sh 3220634 3220624 0 /bin/sh -c curl -fSs http://localhost:8008/health || exit 1
```

This makes it hard to parse the log with tools like `awk`, because it changes the offsets of all further columns.

From what I can tell from the code, all values are printed with a fixed width, without explicit whitespace between the columns: https://github.com/iovisor/bcc/blob/f7986688f8a6119fe0337612e6fec674114002cd/tools/execsnoop.py#L298-L309

The expectation is apparently that the columns will never take up the complete width, so that the remaining whitespace separates the columns.

I think someone might've just misunderstood the width for the printf `%f` type in the `%-8.3f` format string here - maybe the expectation was to reserve 8 characters for the integer part, and an additional 4 characters for the fractional part? As the 8 characters are used for the whole number and the whitespace between the columns, only 8 - 4 (fractional part) - 1 (whitespace) = 3 characters remain for the integer part.

I would suggest:

- either add explicit whitespace between the columns, regardless of the column width. If the columns weren't fixed width and just separated by `\t`, users could pipe the output through `column -t` to get fixed-width formatting.
- or increase the `%f` width to 8 + 4 + 1 = 13. That way, the problem would only occur when `execsnoop` had been running continuously for >3 years.

Contributor guide

No contributing guide indexed for this repository

Research direction

Start in tools/execsnoop.py around lines 298-309, where the output columns are formatted, and reproduce the issue with timestamps above 1000 seconds. Check the chosen column-separation change against both sample outputs; done means the timestamp and command fields remain separately parseable with awk as timestamps grow.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
cli, observability
Issue type
Bug
Difficulty
2/5
Estimated time
1-3 hours
Activity status
Stale
Clarity
Clearly specified
Newbie friendliness
76/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.