Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
jage opened this issue Feb 13, 2025 · 9 comments
Open

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

jage opened this issue Feb 13, 2025 · 9 comments

Comments

@jage
Copy link
Member

jage commented Feb 13, 2025

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

We set correct level/priority for the log row (3 = ERROR):

Log.error(exception: ex) { "Failed to load vhosts" }

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
Copy link
Member

spuun commented Feb 13, 2025

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
Copy link
Member Author

jage commented Feb 13, 2025

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

@spuun
Copy link
Member

spuun commented Feb 13, 2025

WDYT about making it single line?

baelter added a commit that referenced this issue Feb 13, 2025
@baelter
Copy link
Member

baelter commented Feb 13, 2025

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

@baelter
Copy link
Member

baelter commented Feb 14, 2025

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
Copy link
Member

spuun commented Feb 14, 2025

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
Copy link
Member

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

@baelter
Copy link
Member

baelter commented Feb 14, 2025

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

@spuun
Copy link
Member

spuun commented Feb 14, 2025

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.

baelter added a commit that referenced this issue Feb 16, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants