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

Remove multi-thread synchronization from CRT logger wrapper #2885

Merged
merged 3 commits into from Mar 19, 2024

Conversation

SergeyRyabinin
Copy link
Contributor

@SergeyRyabinin SergeyRyabinin commented Mar 11, 2024

Issue #, if available:

Description of changes:

Check all that applies:

  • Did a review by yourself.
  • Added proper tests to cover this PR. (If tests are not applicable, explain.)
  • Checked if this PR is a breaking (APIs have been changed) change.
  • Checked if this PR will not introduce cross-platform inconsistent behavior.
  • Checked if this PR would require a ReadMe/Wiki update.

Check which platforms you have built SDK on to verify the correctness of this PR.

  • Linux
  • Windows
  • Android
  • MacOS
  • IOS
  • Other Platforms

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

{
// SDK CRT logger is terminated, fallback to an original/previous CRT logger
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 just thought about it more and realized that we don't control / own "original" logger, so better to not try to over-smart ourselves.

{
Array<char> outputBuff(requiredLength);
#ifdef _WIN32
vsnprintf_s(outputBuff.GetUnderlyingData(), requiredLength, _TRUNCATE, formatStr, args);
Copy link
Contributor Author

Choose a reason for hiding this comment

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

exactly the same logic is in the main SDK logger, so just call it instead.

@SergeyRyabinin SergeyRyabinin force-pushed the sr/crtLoggerLock branch 3 times, most recently from 65bf755 to 349407b Compare March 11, 2024 23:08
ss << DateTime::Now().CalculateGmtTimeWithMsPrecision() << " " << tag << " [" << std::this_thread::get_id() << "] ";

return ss.str();
static Aws::String CreateLogPrefixLine(LogLevel logLevel, const char* tag, const size_t statementSize = 80)
Copy link
Contributor Author

Choose a reason for hiding this comment

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

so what happens here is the attempt to reduce number of memory allocations to 1 (from many) per logging statement processing.
There are still additional allocations from CalculateGmtTimeWithMsPrecision and <<std::this_thread::get_id but the rest of allocations (and stack-allocated Aws::Array) are eliminated.

Comment on lines 46 to 49
static const size_t THREAD_ID_LEN = [](){
Aws::StringStream strStr;
strStr << std::this_thread::get_id();
return strStr.str().size();
Copy link
Collaborator

Choose a reason for hiding this comment

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

this runs only once per application instance, right?

Is it guaranteed that every thread's ID is the same length? If this were just an integer on some platform, I could imagine different threads having different length integers. I guess it's still safe, since this is just for a reserve() call...

Simpler to just have a hard-coded high guess? Or overestimate somewhere and just like, + 10 to prefixLen?

[&](){ return m_logsProcessed.load() == 0; });
void DefaultCRTLogSystem::SetLogLevel(LogLevel logLevel)
{
AWS_UNREFERENCED_PARAM(logLevel); // will use one from the main SDK logger
Copy link
Contributor

Choose a reason for hiding this comment

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

should we set the log level in main SDK logger instead of no-op?

const size_t oldStatementSz = statement.size();
const size_t newStatementSz = oldStatementSz + requiredLength;
// assert(statement.capacity() >= newStatementSz);
// assert(statement.capacity() < 3 * newStatementSz / 2);
Copy link
Contributor

Choose a reason for hiding this comment

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

nit: commented out asserts

@SergeyRyabinin SergeyRyabinin marked this pull request as ready for review March 19, 2024 17:53
@SergeyRyabinin SergeyRyabinin merged commit 406659f into main Mar 19, 2024
4 checks passed
@SergeyRyabinin SergeyRyabinin deleted the sr/crtLoggerLock branch March 19, 2024 18:01
// GetLogSystem returns a raw pointer
// so this is a hack to let all other threads finish their log statement after getting a LogSystem pointer
// otherwise we would need to perform ref-counting on each logging statement
auto tmpLogger = std::move(CRTLogSystem);
Copy link
Contributor

Choose a reason for hiding this comment

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

This approach would not be necessary if the logger's lifetime always exceeded the CRT. We should be able to shutdown the CRT and then call aws_logger_set(nullptr) and have no need for time-based quiesces which are ultimately a flawed approach (someone will always exceed the sleep time). We would then get all the log messages from CRT shutdown. We're shutting down CRT logging before CRT is stopped, and hooking CRT logging in after CRT is started. There's a more fundamental problem here.

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.

None yet

4 participants