8000 Print full date and time in logs by PaulWay · Pull Request #618 · coturn/coturn · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

Print full date and time in logs #618

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

Merged
merged 7 commits into from
Dec 8, 2020
Merged

Conversation

PaulWay
Copy link
Contributor
@PaulWay PaulWay commented Aug 25, 2020

The 'number of seconds since the daemon was started' is amusing and compact, but it hinders debugging and correlation with other events. This implements logs that use a complete YYYY-MM-DDTHH:MM:SS output which is easy to read and correlate.

Signed-off-by: Paul Wayper paulway@mabula.net

Signed-off-by: Paul Wayper <paulway@mabula.net>
@PaulWay
Copy link
Contributor Author
PaulWay commented Aug 25, 2020

Haven't checked if this compiles or not yet, and haven't removed the old log_start_time and log_time() code.

One possibility I though of was implementing this as an option that could be turned on or off, say by a command-line or configuration option. Haven't investigated how to do that yet.

Signed-off-by: Paul Wayper <paulway@mabula.net>
@PaulWay PaulWay mentioned this pull request Aug 26, 2020
@misi
Copy link
Contributor
misi commented Aug 27, 2020

Please add flag / config option for that to avoid breaking changes

@PaulWay
Copy link
Contributor Author
PaulWay commented Aug 31, 2020

OK - do you want a flag to turn on the new log format, or a flag to turn on the old log format? I.e. which log format should be the preferred? I'm curious to know what value you see in the old format?

I'm happy to avoid a 'breaking' change in a significant feature or piece of functionality, but I'm not sure I see the utility of the old functionality. I suppose I see it as a bug to be fixed rather than a feature that needs to be preserved. Help me understand the significance of the old relative timestamp.

@PaulWay
Copy link
Contributor Author
PaulWay commented Aug 31, 2020

And would you prefer that flag, e.g. int use_new_log_timestamp format, to be in apps/common/ns_turn_utils.h or somewhere else?

@PaulWay
Copy link
Contributor Author
PaulWay commented Aug 31, 2020

This whole log printing is really puzzling me.

There's two separate places which format log lines. One is in turn_log_func_default, which then calls the other in vrtpprintf. This seems to do the whole process of reading the varargs and formatting the log line twice, before printing it to different locations (stdout in turn_log_func_default, syslog or the log file in vrtpprintf). This seems to waste time doing the same job twice.

Is there a particular reason it's done this way?

What I'd propose to do here is to format the log line once and then print that to stdout, the log file and syslog as required by the relevant flags. This would all be handled in the one function turn_log_func_default, with the vrtpprintf function being effectively folded into it. One buffer would be allocated to format the log line, and this would reduce the code size and give more consistency.

But I won't go ahead with that if there's strong opposition to it, or if there's a particular reason for doing it the current way which I don't understand. So please let me know what you'd prefer me to do here.

This provides the 'use_new_timestamp_log_format' variable in `ns_turn_utils.h`.  By
default it is set to 0 and the old 'seconds since daemon was started' timestamp will
be emitted.  However, if it is set to 1 or any 'true' number the new date and time
timestamp format will be used instead.

This has also resulted in a small clean-up of some of the string length handling.

Signed-off-by: Paul Wayper <paulway@mabula.net>
The function `turn_log_func_default` calls the function `vrtpprintf` to print to syslog
or the log file.  The latter does exactly the same string formatting as the former, so
here we merge the two functions into one to do the string formatting once.  This also
makes sure that the log line is consistent on all outputs.

Signed-off-by: Paul Wayper <paulway@mabula.net>
This allows the timestamp format in log output to be set by a function.

Signed-off-by: Paul Wayper <paulway@mabula.net>
Signed-off-by: Paul Wayper <paulway@mabula.net>
This adds the `--new-log-timestamp` and `--new-timestamp-format <value>` options
to the `turnserver` program.

Setting `--new-log-timestamp` on the command line, or `new-log-timestamp` in the
configuration file, will cause all logs to be written with an ISI-8601 timestamp
(`YYYY-MM-DDTHH:MM:SSZZZZZ` with `T` being literal and `ZZZZZ` being `+` or `-`
and the hour and minute offset from GMT for the local timezone).  This replaces
the 'number of seconds since daemon was started' format.

Setting the `--new-timestamp-format <format>` option with a given format, or
`new-log-timestamp=<format>` in the configuration file, will use this instead
of the standard timestamp format.  Timestamp format strings up to 48 characters
can be accommodated; more will be truncated.  This will only be used when the
`--new-log-timestamp` option (above) is set.

Thanks to Hendrik Huels <hendrik.huels@outlook.de> for the idea and some of the
code for setting the log timestamp string.

Signed-off-by: Paul Wayper <paulway@mabula.net>
@PaulWay PaulWay force-pushed the paulway_log_real_time branch from ac4883c to c315c28 Compare September 1, 2020 11:08
@PaulWay
Copy link
Contributor Author
PaulWay commented Sep 2, 2020

So I've merged the log printing into one function, and allowed users to set the timestamp as well. Still trying to test the code to see if it actually works.

@PaulWay
Copy link
Contributor Author
PaulWay commented Sep 7, 2020

@misi Any thoughts?

@misi
Copy link
Contributor
misi commented Dec 7, 2020

@PaulWay Sorry for my late reply!

OK - do you want a flag to turn on the new log format, or a flag to turn on the old log format? I.e. which log format should be the preferred? I'm curious to know what value you see in the old format?

I want a flag for the new to be backward compatible.

I'm happy to avoid a 'breaking' change in a significant feature or piece of functionality, but I'm not sure I see the utility of the old functionality. I suppose I see it as a bug to be fixed rather than a feature that needs to be preserved. Help me understand the significance of the old relative timestamp.

I believe we need smooth transition. It could be someone built systems on it, so I propose to have new flag and indicate in the docs that it will flipped in the next version and your will be the default, and after one version iteration the default behavior will change to the new, to give time to prepare for the change.

@misi
Copy link
Contributor
misi commented Dec 7, 2020

This whole log printing is really puzzling me.

There's two separate places which format log lines. One is in turn_log_func_default, which then calls the other in vrtpprintf. This seems to do the whole process of reading the varargs and formatting the log line twice, before printing it to different locations (stdout in turn_log_func_default, syslog or the log file in vrtpprintf). This seems to waste time doing the same job twice.

Is there a particular reason it's done this way?

What I'd propose to do here is to format the log line once and then print that to stdout, the log file and syslog as required by the relevant flags. This would all be handled in the one function turn_log_func_default, with the vrtpprintf function being effectively folded into it. One buffer would be allocated to format the log line, and this would reduce the code size and give more consistency.

But I won't go ahead with that if there's strong opposition to it, or if there's a particular reason for doing it the current way which I don't understand. So please let me know what you'd prefer me to do here.

Unfortunately I am not the original author of the code, so I can't help in it why it was designed that way. We can simplify, but need to be backward compatible and not break any usage. So let's make it in a different PR..

@misi
Copy link
Contributor
misi commented Dec 7, 2020

@misi Any thoughts?

@PaulWay
Sorry I have limited time.. :-(
Accept my apologies that I can only reach here now..

@misi
Copy link
Contributor
misi commented Dec 7, 2020

We need to also think that wide OS supported so it should work and compatible with more exotic OSs like mac, win, etc.

@misi misi added this to the 4.5.2 milestone Dec 8, 2020
@misi misi merged commit c0822da into coturn:master Dec 8, 2020
misi added a commit that referenced this pull request Dec 8, 2020
@PaulWay
Copy link
Contributor Author
PaulWay commented Dec 9, 2020

Hi @misi - thanks for that, sorry for not getting back to you earlier. Hope this all works well!

@misi
Copy link
Contributor
misi commented Dec 10, 2020

@PaulWay I adjusted little bit (add doc, fix cli etc.) but it seems working fine now. Thanks for your help and contribution!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants
0