Version 1.0.0!
As of this release what-the-time (wtt
) has all the functionality I want for a 1.0.0 release!
This is essentially a Rust CLI tool replacing these Ruby scripts:
- https://github.com/sdball/dotfiles/blob/main/bin/insert-time-diff
- https://github.com/sdball/dotfiles/blob/main/bin/inject-time-diff
- https://github.com/sdball/dotfiles/blob/main/bin/inject-time-total
wtt
takes JSON log lines as input via STDIN or file and calculates the time diffs between lines based on a given datetime field (defaulting to "time")
Usage
-i
: insert the milliseconds since the previous line in amillis_since_previous_line
field in a new JSON line inserted between each original line-s
: insert the milliseconds since the first line in amillis_since_start
field in a new JSON line inserted between each original line-I
: inject the milliseconds since the previous line as amillis_since_previous_line
field into each line following the first-S
: inject the milliseconds since the first line as amillis_since_start
field into each line following the first
For example say we start from this simple file of ten JSON lines
sample_data/ten-lines.json.log
{"time": "2024-06-23T00:00:00Z", "event": "start"}
{"time": "2024-06-23T00:00:01Z", "event": "processing"}
{"time": "2024-06-23T00:00:02Z", "event": "processing"}
{"time": "2024-06-23T00:00:03Z", "event": "processing"}
{"time": "2024-06-23T00:00:04Z", "event": "processing"}
{"time": "2024-06-23T00:00:05Z", "event": "processing"}
{"time": "2024-06-23T00:00:06Z", "event": "processing"}
{"time": "2024-06-23T00:00:07Z", "event": "processing"}
{"time": "2024-06-23T00:00:08Z", "event": "processing"}
{"time": "2024-06-23T00:00:09Z", "event": "end"}
Each "time" field is 1000ms apart and a total of 9000ms is presented since the first line. We can find that data using wtt
in various ways.
insert millis since previous line
$ cat sample_data/ten-lines.json.log | wtt -i
{"event":"start","time":"2024-06-23T00:00:00Z"}
{"millis_since_previous_line":1000}
{"event":"processing","time":"2024-06-23T00:00:01Z"}
{"millis_since_previous_line":1000}
{"event":"processing","time":"2024-06-23T00:00:02Z"}
{"millis_since_previous_line":1000}
{"event":"processing","time":"2024-06-23T00:00:03Z"}
{"millis_since_previous_line":1000}
{"event":"processing","time":"2024-06-23T00:00:04Z"}
{"millis_since_previous_line":1000}
{"event":"processing","time":"2024-06-23T00:00:05Z"}
{"millis_since_previous_line":1000}
{"event":"processing","time":"2024-06-23T00:00:06Z"}
{"millis_since_previous_line":1000}
{"event":"processing","time":"2024-06-23T00:00:07Z"}
{"millis_since_previous_line":1000}
{"event":"processing","time":"2024-06-23T00:00:08Z"}
{"millis_since_previous_line":1000}
{"event":"end","time":"2024-06-23T00:00:09Z"}
insert total millis since first line
$ cat sample_data/ten-lines.json.log | wtt -s
{"event":"start","time":"2024-06-23T00:00:00Z"}
{"millis_since_start":1000}
{"event":"processing","time":"2024-06-23T00:00:01Z"}
{"millis_since_start":2000}
{"event":"processing","time":"2024-06-23T00:00:02Z"}
{"millis_since_start":3000}
{"event":"processing","time":"2024-06-23T00:00:03Z"}
{"millis_since_start":4000}
{"event":"processing","time":"2024-06-23T00:00:04Z"}
{"millis_since_start":5000}
{"event":"processing","time":"2024-06-23T00:00:05Z"}
{"millis_since_start":6000}
{"event":"processing","time":"2024-06-23T00:00:06Z"}
{"millis_since_start":7000}
{"event":"processing","time":"2024-06-23T00:00:07Z"}
{"millis_since_start":8000}
{"event":"processing","time":"2024-06-23T00:00:08Z"}
{"millis_since_start":9000}
{"event":"end","time":"2024-06-23T00:00:09Z"}
inject milliseconds since the previous line
$ cat sample_data/ten-lines.json.log | wtt -I
{"event":"start","time":"2024-06-23T00:00:00Z"}
{"event":"processing","millis_since_previous_line":1000,"time":"2024-06-23T00:00:01Z"}
{"event":"processing","millis_since_previous_line":1000,"time":"2024-06-23T00:00:02Z"}
{"event":"processing","millis_since_previous_line":1000,"time":"2024-06-23T00:00:03Z"}
{"event":"processing","millis_since_previous_line":1000,"time":"2024-06-23T00:00:04Z"}
{"event":"processing","millis_since_previous_line":1000,"time":"2024-06-23T00:00:05Z"}
{"event":"processing","millis_since_previous_line":1000,"time":"2024-06-23T00:00:06Z"}
{"event":"processing","millis_since_previous_line":1000,"time":"2024-06-23T00:00:07Z"}
{"event":"processing","millis_since_previous_line":1000,"time":"2024-06-23T00:00:08Z"}
{"event":"end","millis_since_previous_line":1000,"time":"2024-06-23T00:00:09Z"}
inject total milliseconds since the first line
$ cat sample_data/ten-lines.json.log | wtt -S
{"event":"start","time":"2024-06-23T00:00:00Z"}
{"event":"processing","millis_since_start":1000,"time":"2024-06-23T00:00:01Z"}
{"event":"processing","millis_since_start":2000,"time":"2024-06-23T00:00:02Z"}
{"event":"processing","millis_since_start":3000,"time":"2024-06-23T00:00:03Z"}
{"event":"processing","millis_since_start":4000,"time":"2024-06-23T00:00:04Z"}
{"event":"processing","millis_since_start":5000,"time":"2024-06-23T00:00:05Z"}
{"event":"processing","millis_since_start":6000,"time":"2024-06-23T00:00:06Z"}
{"event":"processing","millis_since_start":7000,"time":"2024-06-23T00:00:07Z"}
{"event":"processing","millis_since_start":8000,"time":"2024-06-23T00:00:08Z"}
{"event":"end","millis_since_start":9000,"time":"2024-06-23T00:00:09Z"}
multiple flags
You can, of course, supply multiple flags for the behavior you want.
❯ cat sample_data/ten-lines.json.log | wtt -is
{"event":"start","time":"2024-06-23T00:00:00Z"}
{"millis_since_previous_line":1000,"millis_since_start":1000}
{"event":"processing","time":"2024-06-23T00:00:01Z"}
{"millis_since_previous_line":1000,"millis_since_start":2000}
{"event":"processing","time":"2024-06-23T00:00:02Z"}
{"millis_since_previous_line":1000,"millis_since_start":3000}
{"event":"processing","time":"2024-06-23T00:00:03Z"}
{"millis_since_previous_line":1000,"millis_since_start":4000}
{"event":"processing","time":"2024-06-23T00:00:04Z"}
{"millis_since_previous_line":1000,"millis_since_start":5000}
{"event":"processing","time":"2024-06-23T00:00:05Z"}
{"millis_since_previous_line":1000,"millis_since_start":6000}
{"event":"processing","time":"2024-06-23T00:00:06Z"}
{"millis_since_previous_line":1000,"millis_since_start":7000}
{"event":"processing","time":"2024-06-23T00:00:07Z"}
{"millis_since_previous_line":1000,"millis_since_start":8000}
{"event":"processing","time":"2024-06-23T00:00:08Z"}
{"millis_since_previous_line":1000,"millis_since_start":9000}
{"event":"end","time":"2024-06-23T00:00:09Z"}
Tips
If you have some sparse events in your JSON log lines it's nice to filter down to those lines and then calculate the timing between them
$ cat sample_data/ten-lines.json.log | rg '(start|end)' | wtt -is
{"event":"start","time":"2024-06-23T00:00:00Z"}
{"millis_since_previous_line":9000,"millis_since_start":9000}
{"event":"end","time":"2024-06-23T00:00:09Z"}