Project

General

Profile

Actions

Feature #2497

open

error messages usability improvement

Added by Victor Julien over 3 years ago. Updated 8 months ago.

Status:
In Review
Priority:
Normal
Assignee:
Target version:
Effort:
high
Difficulty:
low
Label:

Description

Many error messages have been written with very minimal context. Often they only make sense if the file name and function name are logged as well, which is not enabled by default in RELEASE-mode.

Maybe it would be useful to add a new set of SCLogError/SCLogWarning calls that include:
- subsystem name (e.g. stream-tcp, log-pcap)
- affected config options name, if applicable (e.g. stream.midstream)

In output this could be used to give more context to the user.


Related issues

Related to Optimization #3160: clean up error codesNewOISF DevActions
Actions #1

Updated by Andreas Herz over 3 years ago

  • Assignee set to OISF Dev
  • Target version set to TBD

Do you have some examples how you want them to look like in detail?

Actions #2

Updated by Jason Ish over 3 years ago

Victor Julien wrote:

Many error messages have been written with very minimal context. Often they only make sense if the file name and function name are logged as well, which is not enabled by default in RELEASE-mode.

Yes, I agree. Just some thoughts on it...

Maybe it would be useful to add a new set of SCLogError/SCLogWarning calls that include:
- subsystem name (e.g. stream-tcp, log-pcap)

I like this. Its a pretty common idiom in other loggers, primarily from other languages, like Python and Java where I module might do something like:

myLogger = logger.getLogger("tcp")

Now everything with that logger would get the prefix TCP. Or in our case, or used in replacement of filename/function names when not enabled.

- affected config options name, if applicable (e.g. stream.midstream)

This could probably be expressed in the message rather than having special support for it I think. The devops world has started to use structured logging, either straight up JSON, or something like:

- <timestamp> - File to open file: filename=unified2.log, subsystem=eve, option=stream.midstream, key=val...

In output this could be used to give more context to the user.

Actions #3

Updated by Jason Ish over 3 years ago

  • Effort set to high
  • Difficulty set to low
Actions #4

Updated by Victor Julien over 2 years ago

  • Status changed from New to Assigned
  • Assignee changed from OISF Dev to Jeff Lucovsky
  • Target version changed from TBD to 5.0beta1
Actions #5

Updated by Victor Julien over 2 years ago

  • Target version changed from 5.0beta1 to 5.0rc1
Actions #6

Updated by Victor Julien about 2 years ago

  • Target version changed from 5.0rc1 to 6.0.0beta1
Actions #7

Updated by Victor Julien over 1 year ago

  • Status changed from Assigned to In Review
Actions #8

Updated by Victor Julien about 1 year ago

  • Target version changed from 6.0.0beta1 to 7.0rc1
Actions #9

Updated by Jason Ish 8 months ago

Why not log the filename in non-release mode? Could pretty it up a little removing the "src/" and the extension. Logging is already complicated for Error and Warn, I don't think we should add much more complexity to it.

Actions #10

Updated by Jason Ish 8 months ago

Actions #11

Updated by Jason Ish 8 months ago

I think this is very related to 3160 (cleanup error codes). Taking a look at an error here:

[47999] 12/1/2021 -- 11:36:10 - (output-json-dns.c:572) <Warning> (JsonDnsParseVersion) -- [ERRCODE: SC_WARN_DEPRECATED(203)] - DNS EVE v1 style logs have been deprecated and will be removed by May 2022

I'd rather see something like:

[47999] 12/1/2021 -- 11:36:10 - (output-json-dns) <Warning> -- DNS EVE v1 style logs have been deprecated and will be removed by May 2022

Here the "module" name is "output-json-dns".. Maybe we could add line numbers/function names when in a debug mode, but for production use I think the above is all thats needed. The message should be distinct enough to figure out where it occurred in the file.

I also removed the errcode. I don't see much value in having it. I'd much rather see some pretty printing of the error that occurred, more along the lines of errno/strerror handling, or I've seen functions that take a "**errstr" and set it to some static string on error that can be printed. So if a file failed to open or something...

[47999] 12/1/2021 -- 11:36:10 - (output-json) <Error> -- Failed to open /var/log/suricata/eve.json for writing: permission denied

We might run into places where logging needs to be cleaned up. For example, one "module" may call out to a utility function, and that utility function may print an error. This can then make it unclear what system is having the error. The solution is that utility functions just return errors, and the caller logs it, or ripples it back.

Actions

Also available in: Atom PDF