log file too verbose

[Peter Baumann]

log level INFO reports several lines on a single query:

[INFO] - 26/05/2016 07:52:57.25815: Request: 'select version()'…
[INFO] - 26/05/2016 07:52:57.26682: parsing…
[INFO] - 26/05/2016 07:52:57.27143: checking semantics…
[INFO] - 26/05/2016 07:52:57.27149: evaluating…
[INFO] - 26/05/2016 07:52:57.28003: ok, result type 'set <marray <char, [0:98]>>', 1 element(s).
[INFO] - 26/05/2016 07:52:57.28028: ok

This used to be a single line earlier, and it should be one again, like that:

[INFO] - 26/05/2016 07:52:57.25815: Request: 'select version()'…parsing…checking semantics…evaluating…ok, result type 'set <marray <char, [0:98]>>', 1 element(s).

Reasons:

• log file congestion
• a simple grep should get full query info
• keep log file format stable as users run evaluations on it

[Dimitar Misev]

Why single line? I think it's more useful broken like this as we see the timestamp of each part.

Not sure if there's a debug macro in easylogging that doesn't automatically put a new line.

[Dimitar Misev]

a simple grep should get full query info

grep -A5 ..

keep log file format stable as users run evaluations on it

this format has been in use for months now, nobody has complained.

[Dimitar Misev]

I would close this as wontfix, it will be quite hard to fix; and what happens in debug mode, when there is extra output between each part?

[Peter Baumann]

in debug mode you want this. But running a server for a long time in _operational_mode should not flood the file system. This indeed can be a problem, as past experience shows.

Options coming to my mind:

• use NewLineForContainer to not have newline chars all over
• in the final printing methods, go over the string and strip final (our double) newline
• there is a low-level function log() which might be used when lines should continue
• define an extra macro TRACECONT() or so (for "trace output of a continuation line") which relies on the easylogging++.h code

PS: this shows 2 problems:

• there is tacit knowledge in the code which unfortunately is not documented (turns out you simply cannot document all)
• lightheartedly changing has the danger of loosing important properties of the code

[Dimitar Misev]

The current log has less than 2x the characters of the ideal version we want, this will not cause flooding of the system. If it does then I'd say it means the ideal version will also flood the system, if we think in big Oh terms

Personally I actually prefer the slightly more verbose version, it tells me when the request was received and when the result was returned. The stuff in between (parsing, checking semantics) are not worth a special line though and we could conflate them somehow perhaps.

Btw, I don't see the last line in the logs:

[INFO] - 26/05/2016 07:52:57.28028: ok

This is what I get:

 [INFO] - 15/11/2016 19:01:54.116450: Request: 'select version()'...
 [INFO] - 15/11/2016 19:01:54.116474: parsing...
 [INFO] - 15/11/2016 19:01:54.116490: checking semantics...
 [INFO] - 15/11/2016 19:01:54.116497: evaluating...
 [INFO] - 15/11/2016 19:01:54.116533: ok, result type 'set <marray <char, [0:107]>>', 1 element(s), total size 108 bytes.

[Dimitar Misev]

What about this:

 [INFO] - 15/11/2016 19:01:54.116450: Request: 'select version()'...parsing...checking semantics...evaluating...
 [INFO] - 15/11/2016 19:01:54.116533: ok, result type 'set <marray <char, [0:107]>>', 1 element(s), total size 108 bytes.

[Peter Baumann]

just to wrap up: yes, the 2-liner looks better indeed.