Skip to content

Timestamped logging macro for elapsed physical time #546

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.

Sign up for GitHub

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

Jump to bottom
Open
wants to merge 11 commits into
base: main
Choose a base branch
from
Open

Timestamped logging macro for elapsed physical time #546

wants to merge 11 commits into from

Conversation

@adi-65-ray
Copy link
Collaborator

@adi-65-ray adi-65-ray commented Sep 21, 2025 •
edited
Loading

This PR is a fix for #395.

I have implemented a macro which prepends the physical lapsed time to debug messages
LF_TIMESTAMP_PRINT_DEBUG in logging_macros.h
I have also included a test code to test the functionality of the macro to check its expected output.
Example output:
DEBUG: [12345678]Hello World

@hokeun hokeun marked this pull request as ready for review September 22, 2025 17:50
@hokeun hokeun self-requested a review September 22, 2025 17:50
hokeun
hokeun reviewed Sep 22, 2025
View reviewed changes
Copy link
Member

@hokeun hokeun left a comment

Choose a reason for hiding this comment

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

This is a great start. Thanks! I left some suggestions.

@hokeun hokeun requested a review from edwardalee September 22, 2025 17:57
@hokeun
Copy link
Member

hokeun commented Sep 22, 2025

Just to provide the context @adi-65-ray (Aditya Ray) is an M.S. student at ASU, and he kindly volunteered to fix this issue. This PR will be his very first contribution.

edwardalee
edwardalee requested changes Sep 25, 2025
View reviewed changes
Copy link
Contributor

@edwardalee edwardalee left a comment

Choose a reason for hiding this comment

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

This is a nice feature to have, but there remain some subtleties. If we can resolve these, it might be nice to have this be part of the LF_PRINT_DEBUB macro rather than being a whole new macro.

edwardalee
edwardalee approved these changes Sep 28, 2025
View reviewed changes
Copy link
Contributor

@edwardalee edwardalee left a comment •
edited
Loading

Choose a reason for hiding this comment

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

LGTM!
(Modulo getting the tests to pass)

@hokeun hokeun changed the title Timestamped logging macro Timestamped logging macro for elapsed physical time Sep 28, 2025
@hokeun hokeun linked an issue Sep 28, 2025 that may be closed by this pull request
Prepend logging prints with the current/elapsed physical time #395
Open
@hokeun hokeun added the enhancement Enhancement of existing feature label Sep 28, 2025
@hokeun hokeun requested a review from Jakio815 October 14, 2025 19:18
hokeun
hokeun approved these changes Oct 21, 2025
View reviewed changes
Copy link
Member

@hokeun hokeun left a comment

Choose a reason for hiding this comment

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

👍

@hokeun hokeun enabled auto-merge October 21, 2025 18:58
@hokeun hokeun mentioned this pull request Oct 21, 2025
Open
@hokeun hokeun disabled auto-merge October 22, 2025 16:06
@adi-65-ray adi-65-ray requested a review from hokeun October 22, 2025 18:56
hokeun
hokeun approved these changes Oct 30, 2025
View reviewed changes
Copy link
Member

@hokeun hokeun left a comment

Choose a reason for hiding this comment

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

Awesome!

@hokeun hokeun enabled auto-merge October 30, 2025 19:07
edwardalee
edwardalee reviewed Oct 31, 2025
View reviewed changes
.github/workflows/ci.yml
Copy link
Contributor

@edwardalee edwardalee Oct 31, 2025

Choose a reason for hiding this comment

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

Do we really want to set LOG_LEVEL globally for all tests? What are the consequences of this? Can it be set within your one test that needs it?

Copy link
Collaborator Author

@adi-65-ray adi-65-ray Oct 31, 2025

Choose a reason for hiding this comment

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

I tried redefining LOG_LEVEL locally in the test file but it gave waring for redeclaration and -Werror is set so it gets stuck.

@edwardalee
Copy link
Contributor

edwardalee commented Oct 31, 2025

This PR is a fix for #395.

I have implemented a macro which prepends the physical lapsed time to debug messages LF_TIMESTAMP_PRINT_DEBUG in logging_macros.h I have also included a test code to test the functionality of the macro to check its expected output.

expected output: DEBUG: Start time: -9223372036854775808 DEBUG: [-7464962496372149757] [Test case: 0]testing timed debug prints DEBUG: [-7464962491372064629] [Test case: 1]testing timed debug prints DEBUG: [-7464962486371771465] [Test case: 2]testing timed debug prints DEBUG: [-7464962481371438023] [Test case: 3]testing timed debug prints DEBUG: [-7464962476371116940] [Test case: 4]testing timed debug prints DEBUG: [-7464962471370813344] [Test case: 5]testing timed debug prints DEBUG: [-7464962466370645568] [Test case: 6]testing timed debug prints DEBUG: [-7464962461370410362] [Test case: 7]testing timed debug prints DEBUG: [-7464962456370065744] [Test case: 8]testing timed debug prints DEBUG: [-7464962451369754731] [Test case: 9]testing timed debug prints

Why are these numbers negative?

@adi-65-ray adi-65-ray closed this Oct 31, 2025
auto-merge was automatically disabled October 31, 2025 07:59

Pull request was closed

@adi-65-ray adi-65-ray reopened this Oct 31, 2025
@adi-65-ray
Copy link
Collaborator Author

adi-65-ray commented Oct 31, 2025

This PR is a fix for #395.
I have implemented a macro which prepends the physical lapsed time to debug messages LF_TIMESTAMP_PRINT_DEBUG in logging_macros.h I have also included a test code to test the functionality of the macro to check its expected output.
expected output: DEBUG: Start time: -9223372036854775808 DEBUG: [-7464962496372149757] [Test case: 0]testing timed debug prints DEBUG: [-7464962491372064629] [Test case: 1]testing timed debug prints DEBUG: [-7464962486371771465] [Test case: 2]testing timed debug prints DEBUG: [-7464962481371438023] [Test case: 3]testing timed debug prints DEBUG: [-7464962476371116940] [Test case: 4]testing timed debug prints DEBUG: [-7464962471370813344] [Test case: 5]testing timed debug prints DEBUG: [-7464962466370645568] [Test case: 6]testing timed debug prints DEBUG: [-7464962461370410362] [Test case: 7]testing timed debug prints DEBUG: [-7464962456370065744] [Test case: 8]testing timed debug prints DEBUG: [-7464962451369754731] [Test case: 9]testing timed debug prints

Why are these numbers negative?

initially my test was wrong I wasn't using assertions and just printing it. I'll update the description so that others don't get confused.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@edwardalee edwardalee edwardalee approved these changes

@hokeun hokeun hokeun approved these changes

@Jakio815 Jakio815 Awaiting requested review from Jakio815

Assignees

No one assigned

Labels

enhancement Enhancement of existing feature

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

Prepend logging prints with the current/elapsed physical time

3 participants

@adi-65-ray @hokeun @edwardalee