logging-log4j2 icon indicating copy to clipboard operation
logging-log4j2 copied to clipboard

LOG4J2-3558: make default priority configurable

Open bigmarvin opened this issue 3 years ago • 5 comments

I filed LOG4J2-3558 to describe the context behind.

Essentially, we want to check how things work when loggers run in lower priority, and we find it's not feasible until some change like this is made.

bigmarvin avatar Jul 22 '22 15:07 bigmarvin

@ppkarwasz , may I ask for your review?

bigmarvin avatar Aug 01 '22 23:08 bigmarvin

@garydgregory / @remkop / @rgoers , may I ask for your review? I double checked CONTRIBUTING.md while I'm still not really sure what's the missing piece that blocks this PR from getting some feedback. You are picked based on the contribution to this repository, but please feel free to let me know if some other reviewer is more appropriate. Thanks!

bigmarvin avatar Aug 15 '22 15:08 bigmarvin

@bigmarvin Have you tried forking the project and trying your changes there?

Can you explain what benefits you saw in your application when you used it with your customized Log4j fork with configurable priorities?

remkop avatar Aug 17 '22 13:08 remkop

Thank you for the feedbacks! I've just pushed few more changes to address the issues. Could you please take a look?

The story behind would be (presumed) scheduling issue to be tuned. When the load gets high, a few things are observed --

  1. The duration of various tasks (say Runnable) behind REST and gRPC traffic gets expanded
  2. The end-to-end duration of gRPC traffic gets expanded a little more than REST traffic on server side
  3. The client-side e2e duration of gRPC traffic gets expanded way further than its server-side e2e duration

Item 1 is expected as application just has more work to do. Item 2 is also kind of understandable, as a REST call usually have 2 tasks for I/O and 1 task for processing while a gRPC call would need more tasks. There can be extra delay when we break a single task into multiple, even when run by same Executor in sequence.

Item 3 is something concerning. For example, when the latency rises from 5 ms to 6 on server side, it can be from 7 to 20 ms on client side. According to some stats, the duration of tasks in gRPC traffic doesn't rise much and Executors behind don't run out.

The promising theory at present would be some delay in scheduling, e.g. tasks doesn't get executed in time or executing ones don't get as many CPU resources as original because more supporting tasks (e.g. stats aggregation, notifications, logging) are populated and competing for resources.

The changes in this PR facilitate the tunning of thread priorities based on the theory above. Please feel free to let me know what you think, as it's just some theory.

bigmarvin avatar Aug 17 '22 16:08 bigmarvin

@bigmarvin Thanks for the clarification.

My first concern is that thread priority may not make any difference for your application, and then we end up having added public API to Log4j that does not help anyone (and probably confuses users). And for backwards compatibility we would not want to remove it. We don't want to end up in that situation.

What I would suggest is that you actually try this in your application. You already have a fork of Log4j (that is where this PR is coming from), so just build it so you have the binaries (SNAPSHOT binaries of the next version), and run your application with those Log4j SNAPSHOT binaries. You can then configure the priority, and confirm whether or not it makes a difference.

Once you have confirmed that it makes a difference, then you can argue that this change will benefit many users and that you think it should be included in the Log4j library.

That does not necessarily mean that your proposal will be accepted, my impression is that thread priority is not a very reliable mechanism, perhaps an outdated mechanism, and may work differently (or not at all) in different environments, but until you have evidence that it at least made a difference in your environment it is unlikely that this PR will be accepted.

remkop avatar Aug 18 '22 07:08 remkop

This was closed automatically by Github because we renamed the release-2.x branch to 2.x. Feel free to resubmit to the 2.x branch.

ppkarwasz avatar Mar 01 '23 06:03 ppkarwasz