Lukas Jezek authored 3 years ago and Tomas Krizek committed 3 years ago

logging

Vladimír Čunát authored 3 years ago and Tomas Krizek committed 3 years ago

The main problem there was ignoring the log groups,
and VERBOSE_STATUS also ignores trace-logging.
Typically the new kr_log_is_debug*() are the best choice.

In a couple places with heavy WITH_VERBOSE usage it's
instead locally redefined to consider the right group.

Vladimír Čunát authored 3 years ago and Tomas Krizek committed 3 years ago

... so we can use it for more precise logging.  Some calls get simpler.
In particular, without the associated request, we can't produce anything
into trace-logs, which could be confusing.  Normal logs will benefit, too.
(more precise replacement of WITH_VERBOSE will come in a subsequent commit)

Vladimír Čunát authored 3 years ago and Tomas Krizek committed 3 years ago

... and optimize a suspect hot path (through VERBOSE_MSG)

Vladimír Čunát authored 3 years ago and Tomas Krizek committed 3 years ago

I think it's an old issue, but why not fix it now.
I believe it's better when these two are "independent".

Removed comment: once upon a time it belonged to auto_free
and similar macros, but somehow it survived various moves.

Vladimír Čunát authored 3 years ago and Tomas Krizek committed 3 years ago

- unify interactive mode to stdout
- use its own logging group
- elevated log level when the command throws an exception
- don't try detecting that the logs go back into the same console
  (yes, in that case you can see some lines twice)
- don't make the binary mode turn off logging

Vladimír Čunát authored 3 years ago and Tomas Krizek committed 3 years ago

It would be yet another condition to check; overall I think the
necessary checks would get too complex to be done in a macro
and therefore copied all over the place.

Note: it's interesting that such a change reduces binary size
by about 3% (on master), and I suspect that speed won't suffer at all
(after that TODO is done).

Vladimír Čunát authored 3 years ago and Tomas Krizek committed 3 years ago

- const for names of log groups
- enum kr_log_group for a single log group
- the kr_log_groups bitmap doesn't need to be exposed or even exported
- return bool instead of int

- ensure gnutls logging can be turned on/off by using GNUTLS log group
- keep TLS / TLSCLIENT as log groups for our TLS logs and use GNUTLS
  instead

It's better to use separate log group, to separate between logs that
come from the lua module vs native C implementation. It is also more
descriptive, since http modules is used for other stuff besides its
deprecated DoH.

Plural makes more sense to me here, since it can take a table with
multiple entries as input.

Besides testing the API, running this test also ensures all log groups
have been properly defined (as long as kr_assertions are turned on).

To ensure all log groups have been properly defined, iterate over the
entire enum. If a value is missing, assert will be triggered.

Also fixes groups with number >=32 (32bit value was used to test
whether group is set before).

This serves two purposes:

1. As a utility logger during development.
2. As the last entry in enum - to make iteration over the values
   possible. Changing the value of LOG_GRP_DEVEL shouldn't be an issue,
   since it shouldn't be used in production code.

Add space padding when printing the group name to allow usage of
regular group names in lua code (e.g. "io" instead of "io    ").

The function returns a table where key is the group name and the value
is either true (when logging selected group), or nil (when group isn't
selected).

This replaces the list_log_group() which didn't really work.

Ensure both these functions return string that represents the log level.

Also avoid using printf - it'd probably break API when using map().

I think notice is a good default - it should be used for scarce messages
that the user should see, while info level provides more low level info.

It could make sense to increase the log level to info if running with
journalctl (but it might be overkill).