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

Implement faster ThreadContextMap #2330

Merged
merged 6 commits into from
Mar 12, 2024

Conversation

jengebr
Copy link
Contributor

@jengebr jengebr commented Feb 29, 2024

This implements a version of ThreadContextMap that is faster than `DefaultThreadContextMap, and is suitable for applications with nested classloaders, such as web applications running in containers. Key characteristics of this version are:

  1. Faster copy-and-modify operations
  2. Lower memory allocation
  3. State is contained in a single object using a JVM-defined class (Object[]). This solves the classloader reference problem.
  4. Performance is better than DefaultThreadContextMap except for get() operations, where performance becomes linear.

See PR #2321 for additional context and related conversations.

@ppkarwasz ppkarwasz requested a review from jvz March 1, 2024 18:25
@ppkarwasz ppkarwasz added this to the 2.24.0 milestone Mar 4, 2024
@jengebr
Copy link
Contributor Author

jengebr commented Mar 7, 2024

@jvz not sure what your schedule is, but I'll be unavailable next week and unable to respond to comments. I've lined up a coworker to watch the conversation and help where possible.

@jengebr
Copy link
Contributor Author

jengebr commented Mar 7, 2024

Our application ran into a JDK performance issue which makes constructors slow whenever the object has a final member variable. We're removing finals from hotspots, and the code in this PR contains several instances of this problem. Any objection if we remove the keyword final from those member variables? Not sure if it'll violate enforced styling.

@vy
Copy link
Member

vy commented Mar 8, 2024

@jengebr, very sharp of you! Thanks for chasing this! Keeping finals out due to the reason you stated is perfectly fine, but please document it (preferably, with a pointer to the relevant OpenJDK issue) wherever this modification is needed.

OTOH, given the impact surface of this problem and its severity, I expect it to be promptly addressed by OpenJDK. Maybe we should put a reminder to remove this in a year or so. WDYT?

Copy link
Contributor

@ppkarwasz ppkarwasz left a comment

Choose a reason for hiding this comment

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

@jengebr,

This seems as a very promising successor of DefaultThreadContextMap. I would just:

  • repackage it to org.apache.logging.log4j.internal.map (or something similar). This package will not be exported from the JPMS module, so it can not be used outside of log4j-api. If people show interest in using this implementation outside of Log4j API, you can resubmit it to Commons Collections,
  • remove the support for inheritable ThreadLocals. IMHO it is an anachronistic way to propagate contexts between threads, that might have been useful, when people used new Thread directly.

Regarding the second point I thought about introducing soon (after the 2.23.1 release) two methods to ThreadContextMap:

    /**
     * Saves the current context map data.
     * <p>
     *     The returned object is not affected by later changes to the context map.
     * </p>
     * @return An opaque immutable version of the internal context map representation used.
     * @see #restoreContextMap
     * @since 2.24
     */
    Object saveContextMap();

    /**
     * Restores the context map data, from a saved version.
     * @param contextMap An opaque immutable version of the internal context map representation used.
     * @see #saveContextMap
     * @since 2.24
     */
    void restoreContextMap(Object contextMap);

These methods will solve two problems:

  1. Will allow us to enter the modern era of context propagation. For example we can use them to easily implement ThreadLocalAccessor from the Micrometer Context Propagation library,
  2. Will solve your original problem with CloseableThreadContext: we can use saveContextMap/restoreContextMap to efficiently restore the initial context data.

@jengebr
Copy link
Contributor Author

jengebr commented Mar 8, 2024

@jengebr, very sharp of you! Thanks for chasing this! Keeping finals out due to the reason you stated is perfectly fine, but please document it (preferably, with a pointer to the relevant OpenJDK issue) wherever this modification is needed.

OTOH, given the impact surface of this problem and its severity, I expect it to be promptly addressed by OpenJDK. Maybe we should put a reminder to remove this in a year or so. WDYT?

@vy I think the reminder is a very good idea. How do you suggest we do that? Is there a github mechanism, or just a comment in the code?

@jengebr
Copy link
Contributor Author

jengebr commented Mar 8, 2024

I've pushed the updated code, working through unrelated build failures. May revise further if something actually is related.

@jengebr
Copy link
Contributor Author

jengebr commented Mar 8, 2024

Local build completed successfully with no further revisions. I'll be "back" in about 1.5 weeks, will address comments quickly after that.

Copy link
Contributor

@ppkarwasz ppkarwasz left a comment

Choose a reason for hiding this comment

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

LGTM

@ppkarwasz ppkarwasz merged commit 7818b0f into apache:2.x Mar 12, 2024
9 checks passed
@ppkarwasz
Copy link
Contributor

@jengebr,

Thank your for your contribution. I'll enable it by default in the 2.24 branch.

ppkarwasz added a commit that referenced this pull request Mar 13, 2024
@jengebr
Copy link
Contributor Author

jengebr commented Mar 18, 2024

Thank you for your encouragement! I hope this helps other as much as it'll help us.

@jengebr jengebr deleted the StringArrayThreadContextMap branch March 18, 2024 15:47
SeasonPanPan pushed a commit to SeasonPanPan/logging-log4j2 that referenced this pull request Mar 21, 2024
@ppkarwasz ppkarwasz mentioned this pull request Mar 31, 2024
@vy
Copy link
Member

vy commented Oct 2, 2024

@jengebr, would you mind reminding me why did we settle on an copy-on-write map instead of a mutable one (and cloning it if getImmutableMapOrNull(), getMap(), etc. is requested), please?

@jengebr
Copy link
Contributor Author

jengebr commented Oct 2, 2024

Hi @vy - copy-on-write was the previous state, where it would fully copy the existing HashMap into a new one, then pass that around. To answer the immediate question, I implemented copy-on-write because that was the current behavior.

As for why it was first introduced, I speculate it's because the Map object itself can be exposed to the caller, and therefore is conceivably at risk of concurrent updates.

The cost of copying a HashMap is quite high (slow iteration across the original, object allocations to create the new) and the perf advantage of the new one comes from drastically reducing it. If we dropped the copy-and-modify requirement, we'd see better performance than either HashMap or this.

@jengebr
Copy link
Contributor Author

jengebr commented Oct 2, 2024

cloning it if getImmutableMapOrNull(), getMap(), etc. is requested

Currently, direct updates to getMap() are visible to the ThreadContext(), and updates to ThreadContext() are visible to the get*Map() methods. This would be a breaking change, although possibly an acceptable cost.

@vy
Copy link
Member

vy commented Oct 2, 2024

@jengebr, thanks so much for the quick and elaborate response! 😍

Currently, direct updates to getMap() are visible to the ThreadContext(), and updates to ThreadContext() are visible to the get*Map() methods.

I guess, while we can still retain these behaviours using a mutable map, I am more inclined to treat these as misuses rather than features.

Right now I am firefighting with #2946 (the issue that we couldn't completely resolve in 2.24.1) in #3050 – your review is more than welcome! 🤩 There I try to just fix the reported bug. I intend to submit another PR rewriting DefaultThreadContextMap using a mutable array.

@jengebr
Copy link
Contributor Author

jengebr commented Oct 2, 2024

Thanks for working on this! I added one suggestion on the PR (streams add overhead), but I like how much easier it is to read that code.

I look forward to the mutable array! Please let me know once it's ready and I can support with some performance analysis.

@ppkarwasz
Copy link
Contributor

Currently, direct updates to getMap() are visible to the ThreadContext(), and updates to ThreadContext() are visible to the get*Map() methods.

I guess, while we can still retain these behaviours using a mutable map, I am more inclined to treat these as misuses rather than features.

By looking closely at ThreadContext.getImmutableContext() I also believe that the returned object could be mutable and if a user tries to modify it, he breaches the method's contract.

Note that ThreadContext.getImmutableContext() is a "feature" of the Log4j API only. SLF4J users can only get a copy using MDC.getCopyOfContextMap(), so we don't risk misuse from their part.

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