Skip to content
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

Optimize log message code generation #1101

Merged
merged 10 commits into from
Feb 5, 2024

Conversation

sethrj
Copy link
Member

@sethrj sethrj commented Feb 2, 2024

While testing the contents of g4vg.dylib with nm to make sure no Celeritas physics was included, I found that template instantiations for the logger message on char const[N] were being saved as actual function calls. This is pretty silly because those functions unroll effectively to put_char(ptr, N), so there's not going to be any code size gain by not inlining those.

The second optimization is that I've marked as "unlikely" that the log level is high enough to print, moving the printing code to a "cold" section. This improves instruction cache locality in the typical case where a logger message is ignored.

I've also replaced std::string with std::string_view and made better use of move semantics to further reduce the amount of code needed to create and destroy a logging message, especially when it's not printed.


For reference, given the code:

void write_message(int i, char const* s)
{
    CELER_LOG(debug) << "Error: expected " << i << " to be " << s
                     << "(but double is " << 1.234 << ')';
}

With the new code, there are 15 instructions between "get the world logger" and the function exit. With the old code, there's ~120 (but the "not logging" case skips some of those). The old code also has several calls to delete due to using string rather than string_view.

@sethrj sethrj added core Software engineering infrastructure performance Changes for performance optimization labels Feb 2, 2024
Copy link
Contributor

@pcanal pcanal left a comment

Choose a reason for hiding this comment

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

LGTM

@sethrj sethrj merged commit 0f77652 into celeritas-project:develop Feb 5, 2024
20 of 21 checks passed
@sethrj sethrj deleted the logger-opt branch February 5, 2024 13:28
pcanal pushed a commit to pcanal/celeritas that referenced this pull request Feb 6, 2024
* Force-inline logger message functions
* Pass provenance by rvalue
* Use string view for provenance
* Only inline non-null log message components
* Mark logging as unlikely
* Fix potential bug when moving logger message
* Remove silly dynamic cast
* Rename Provenance to LogProvenance
sethrj added a commit that referenced this pull request Feb 14, 2024
* Force-inline logger message functions
* Pass provenance by rvalue
* Use string view for provenance
* Only inline non-null log message components
* Mark logging as unlikely
* Fix potential bug when moving logger message
* Remove silly dynamic cast
* Rename Provenance to LogProvenance
sethrj added a commit that referenced this pull request Feb 15, 2024
* Force-inline logger message functions
* Pass provenance by rvalue
* Use string view for provenance
* Only inline non-null log message components
* Mark logging as unlikely
* Fix potential bug when moving logger message
* Remove silly dynamic cast
* Rename Provenance to LogProvenance
@sethrj sethrj added _unfiled enhancement New feature or request and removed _unfiled labels Apr 2, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
core Software engineering infrastructure enhancement New feature or request performance Changes for performance optimization
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants