Set journald priority level to 3 (ERROR) for exception backtrace

[jage]

Further enhancement once #950 is in, example output here is based on #950.

We set correct level/priority for the log row (3 = ERROR): https://github.com/cloudamqp/lavinmq/blob/7f85d321ad2631b719c61703bccfd9b5cd9b2065/src/lavinmq/vhost_store.cr#L94

But then we print out the exception backtrace, all with default priority (6 = INFO). It would be great to get that with the same priority as the log message (or always ERROR).

$ journalctl -u lavinmq -o json | jq -r '.PRIORITY + " " + .MESSAGE'
3  lmq.vhost_store Failed to load vhosts
6 Unexpected char 'b' at line 6, column 5 (JSON::ParseException)
6   from usr/share/crystal/src/json/lexer.cr:116 in 'raise'
6   from usr/share/crystal/src/json/lexer.cr:330 in 'unexpected_char'
6   from usr/share/crystal/src/json/lexer.cr:326 in 'unexpected_char'
6   from usr/share/crystal/src/json/lexer/io_based.cr:11:21 in 'consume_number'
6   from usr/share/crystal/src/json/lexer.cr:63:7 in 'next_token'
6   from usr/share/crystal/src/json/lexer.cr:75:5 in 'parse_object'
6   from usr/share/crystal/src/json/parser.cr:37:7 in 'parse_value'
6   from usr/share/crystal/src/json/parser.cr:49:18 in 'parse_array'
6   from usr/share/crystal/src/json/parser.cr:37:7 in 'parse_value'
6   from usr/share/crystal/src/json/parser.cr:117:29 in 'parse'
6   from usr/share/crystal/src/json/any.cr:259:3 in 'initialize'
6   from usr/share/crystal/src/gc/boehm.cr:184:7 in 'start'
6   from usr/src/lavinmq_2.1.0-34-gad237d9a/src/lavinmq/launcher.cr:76:9 in '__crystal_main'
6   from usr/share/crystal/src/crystal/main.cr:118:5 in 'main'
6   from usr/share/crystal/src/crystal/system/unix/main.cr:10:3 in 'main'
6   from /lib/aarch64-linux-gnu/libc.so.6 in '??'
6   from /lib/aarch64-linux-gnu/libc.so.6 in '__libc_start_main'
6   from /usr/bin/lavinmq in '_start'
6   from ???
6 Unhandled exception: Unexpected char 'b' at line 6, column 5 (JSON::ParseException)
6   from usr/share/crystal/src/json/lexer.cr:116 in 'raise'
6   from usr/share/crystal/src/json/lexer.cr:330 in 'unexpected_char'
6   from usr/share/crystal/src/json/lexer.cr:326 in 'unexpected_char'
6   from usr/share/crystal/src/json/lexer/io_based.cr:11:21 in 'consume_number'
6   from usr/share/crystal/src/json/lexer.cr:63:7 in 'next_token'
6   from usr/share/crystal/src/json/lexer.cr:75:5 in 'parse_object'
6   from usr/share/crystal/src/json/parser.cr:37:7 in 'parse_value'
6   from usr/share/crystal/src/json/parser.cr:49:18 in 'parse_array'
6   from usr/share/crystal/src/json/parser.cr:37:7 in 'parse_value'
6   from usr/share/crystal/src/json/parser.cr:117:29 in 'parse'
6   from usr/share/crystal/src/json/any.cr:259:3 in 'initialize'
6   from usr/share/crystal/src/gc/boehm.cr:184:7 in 'start'
6   from usr/src/lavinmq_2.1.0-34-gad237d9a/src/lavinmq/launcher.cr:76:9 in '__crystal_main'
6   from usr/share/crystal/src/crystal/main.cr:118:5 in 'main'
6   from usr/share/crystal/src/crystal/system/unix/main.cr:10:3 in 'main'
6   from /lib/aarch64-linux-gnu/libc.so.6 in '??'
6   from /lib/aarch64-linux-gnu/libc.so.6 in '__libc_start_main'
6   from /usr/bin/lavinmq in '_start'
6   from ???

[spuun]

Could it be journald that's adding that 6 if the line doesn't have a priority? I don't think it's added by us/Log. Maybe we should make it single line?

[jage]

Yes, I think you’re right. It’s probably default value for everything coming from stdout.

[spuun]

WDYT about making it single line?

[baelter]

Sorted it in the open PR. apart from "Unhandled exception", where is that logged?

[baelter]

Found it: https://github.com/crystal-lang/crystal/blob/8e02a4202a507d5b1a70b9c8c1e80dd4a3df5155/src/spec/dsl.cr#L223

Not sure if we can do anything with that?

@spuun what do you mean making it a single line?

[spuun]

Found it: https://github.com/crystal-lang/crystal/blob/8e02a4202a507d5b1a70b9c8c1e80dd4a3df5155/src/spec/dsl.cr#L223

Not sure if we can do anything with that?

IMO we can live with that. We should make sure to handle all exceptions.

@spuun what do you mean making it a single line?

Make log entries single line, i.e. not having line breaks in the backtrace.

[kickster97]

I'm a bit sceptical to single line backtrace.. Maybe if we have a way to make it as readable

[baelter]

I found a way of handling it for STDERR as well. PR updated

[spuun]

I'm a bit sceptical to single line backtrace.. Maybe if we have a way to make it as readable

Yes, but for a log aggregating service it may be worse. If you want to count errors or something a multi-line error will be counted as multiple errors.