case studies

A Crashed Writer Left Three Broken Lines in a 1 GiB Log and jq Stopped at the First

Logs written by real services aren’t always valid JSON Lines. A process killed mid-write leaves half a line. The restarted process appends its first event straight after it, on the same line. Disk-full conditions, log shippers that split long lines and two writers sharing one file all do something similar. The file is 99.9999% fine and has a few lines that no parser will accept.

jq treats the input as one stream of JSON, so the first bad line ends the run. This worked example shows what that looks like and what jvqq does instead. We took 1 GiB of generated logs, 3,073,492 lines, and cut three lines in half, each followed by the next line on the same line, the way a crashed writer leaves them. In the broken file they’re lines 812,345, 1,604,990 and 2,949,998. The commands below ran with jq 1.7.1 and jvqq 0.1.0 on a two-core cloud VM.

jq stops at line 812,345 after 101,260 error lines. jvqq skips three broken lines, reports where the first one was and prints 383,944. jq with fromjson? also gets 383,944 but takes 41.8 seconds. jvqq –strict stops at the same line jq did.

All four commands select the error lines and count them.

jq: a Quarter of the Answer

jq -c 'select(.level == "error")' crash.jsonl | wc -l
jq: parse error: Invalid literal at line 812345, column 191
101260

jq printed the error lines from the first 812,344 lines, reported the parse error and exited with code 5. The pipe still counted what came through, so the result is 101,260 and looks like an answer. Unless someone reads standard error, it’s the wrong one.

jvqq: the Whole File, and a Note

jvqq -c 'select(.level == "error")' crash.jsonl | wc -l
jvqq: skipped 3 lines that aren't valid JSON (first at crash.jsonl:812345: Expected separator between values at column 189)
383944

jvqq skipped the three broken lines, kept going, and said at the end how many it skipped and where the first one was. The exit code was 0, because skipped lines are reported and not treated as failure. 2.2 seconds.

383,944 is the right count here. The same filter on the original file, before we broke it, gives 383,944 too. None of the six events caught up in the three broken lines happened to be errors. On another file they might be, and the note at the end tells you that something was lost and where to look.

The jq Workaround

jq can be made to skip bad lines: read each line as a string with -R and parse it with fromjson?, which drops the ones that fail.

jq -cR 'fromjson? | select(.level == "error")' crash.jsonl | wc -l

That gives 383,944 as well, in 41.8 seconds. It also skips silently. Nothing tells you three lines were dropped, or where.

When You Want It to Stop

Sometimes a broken line means the file can’t be trusted and the job should fail. That’s --strict:

jvqq --strict -c 'select(.level == "error")' crash.jsonl | wc -l
jvqq: error: crash.jsonl:812345: Expected separator between values at column 189 (stopped, --strict)
101260

It stops at the same line jq did, prints everything before it, and exits with code 2. Use it in pipelines where the data has to be complete. Leave it off when you’re reading production logs to answer a question.

The reference has the input rules, including the \r\n line endings and pretty-printed files jvqq also reads.

jvqq is an independent tool, not a fork of jq and not affiliated with the jq project. It reads the jq language and is tested against jq 1.7.1’s output.