Skip to content

Conversation

@chrissie-c
Copy link
Contributor

This adds a new %T option to the logging format for millisecond resolution timestamps.

It breaks a little-used API call (custom logging) but as we're heading for a 2.0 release anyway (because of the callsite changes) I don't see this as a big problem.

Plus some misc tidying
There is otherwise no straightforward way for an application
to know if hi-res timestamps are implemented
@jfriesse
Copy link
Member

@chrissie-c Thank you for the feature-test macro. Just as a reminder (talked on IRC already) of weird behavior I've found.

Without patch, current corosync master (707a9afa304dff3ad142739d6193dc2287c3fcc1) timestamps logged to stderr, files or blackbox are in sync. With patches applied (I've just compiled aa6bc9f branch from your libqb fork) behavior looks like:

stderr

Oct 26 16:10:08 trace   [TOTEM ] Received ringid(170238751:112) seq 7
Oct 26 16:10:08 trace   [TOTEM ] releasing messages up to and including 6
Oct 26 16:10:08 trace   [TOTEM ] releasing messages up to and including 7

/var/log/cluster/corosync.log

May 09 14:03:44 [28396] vmrhel7-n01.test.org corosync trace   [TOTEM ] Received ringid(170238751:112) seq 7
May 09 13:11:44 [28396] vmrhel7-n01.test.org corosync trace   [TOTEM ] releasing messages up to and includin
g 6
May 09 13:11:44 [28396] vmrhel7-n01.test.org corosync trace   [TOTEM ] releasing messages up to and includin
g 7

and blackbox is similar.

trace   May 09 14:03:44 message_handler_mcast(4298):13: Received ringid(170238751:112) seq 7
trace   May 09 13:11:44 messages_free(2646):13: releasing messages up to and including 6
trace   May 09 13:11:44 messages_free(2646):13: releasing messages up to and including 7

struct qb_log_callsite *cs,
time_t timestamp,
struct timespec *timestamp,
va_list ap);

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually pacemaker uses these to implement its PCMK_trace_blackbox option (which dumps a blackbox when a message at a specified function+line is logged). Would it be possible to add these as new methods, and somehow wrap the old ones around the new ones? I can use the new constant to know which signature to use going forward, but it would be nice if newer libqb could be used with existing pacemaker versions.

Awesome that we're getting the capability, btw.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll have a look into that. The callback hooks quite low into the libqb code but it's doable I think.
It probably mean 2 API calls for registering a custom logger and expanding the target struct to contain 2 logger functions. Or I could overload vlogger if I'm feeling evil.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thinking closely about this, I don't think there's any point in doing it. Partly because this is for libqb 2.0, but mainly because we've already remove the linker-section based logging callsites, so that means anything linked against libqb1 is not going to work anyway.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wasn't thinking of already linked executables so much as someone upgrading libqb and rebuilding but not upgrading pacemaker, but that case may not be worth a lot of effort.

@jfriesse
Copy link
Member

@chrissie-c Last fix (6bfba48) solved the issue I've had, so ACK by me.

I'm going to do anothe patch to add to this that makes qb_blackbox
backwards compatible with old BB files, so this new file format
is interim.
* from a new one with this header.
*/

struct _blackbox_file_header {
Copy link
Member

@jfriesse jfriesse Oct 29, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because this structure is used directly in fwrite it should be marked as a packed (because qb_rb_write_to_file is saving field by field).

Yet another crazy idea (please ignore it if you feel like I had already too many of them :) ), what about storing it in network order so blackbox is "portable" between different endian systems (so it would be possible to share blackbox)?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not convinced it's worth the effort TBH.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Understood (and kind of agree, we can always ask for text dump).

@chrissie-c chrissie-c merged commit 0e2d4d6 into ClusterLabs:master Nov 9, 2018
chrissie-c added a commit that referenced this pull request Nov 9, 2018
* log: Add high-resolution timestamp option for log files

This adds the %T option to the log format for millisecond timestamps. There's a feature test macro QB_FEATURE_LOG_HIRES_TIMESTAMPS so that applications know that they are available.

Because this changes the internal logging API, applications that use custom loggers will also need to change their custom logging destinations to take a struct timespec instead of a time_t. The above feature test macro will help in deciding which is appropriate.
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.

3 participants