The %c (aka %logger) pattern uses the logger name. The %C (aka %class) pattern does the runtime lookup which kills performance.
On Mon, 6 Aug 2018 at 11:00, Shawn Heisey <[email protected]> wrote: > I'm a committer on the Solr project. Recently we completed an upgrade > to log4j2, a change that we're very happy with. The "rotate on startup" > option has greatly simplified our start scripts, and we're running a > version with full community support. > > https://issues.apache.org/jira/browse/SOLR-7887 > > Now we're contemplating switching to async, which is apparently how > log4j2 achieves "insane performance." > > http://www.grobmeier.de/log4j-2-performance-close-to-insane-20072013.html > > I've been reading what I can find about how to switch, but the docs seem > to indicate at least two ways to do it, and I can't tell by looking at > those which approach is better. At the end of this message is a paste > URL with the log4j2 config that Solr ships. Any suggestions for > improving the config are appreciated. > > What are the potential problems of async logging? I'm guessing that > there's a possibility that messages will get logged out of order if it > takes longer to process one message than it does to process another one > that happens immediately afterwards. If this can happen, would the > timestamps still be accurate even if logged out of order? Although even > with millisecond precision, it's likely that they would have the same > visible timestamp, so most of the time that might not actually be useful. > > I was reading about mixing async and sync loggers, and wondering whether > that would solve any out-of-order problems for critical log messages. > Thinking mainly about having WARN and ERROR use sync. A properly > functioning Solr server with a modern config logs almost nothing at WARN > or ERROR. Typically even if the config isn't modern, a well-functioning > server usually only logs such messages at startup or index reload. The > vast majority of what Solr usually logs is at INFO. There's a fair > amount of DEBUG in the code, and possibly even some at a lower level, > but the logging threshold defaults to INFO. Solr can be a little noisy > in its logs, but we are taking steps to reduce the verbosity. If the > server is particularly busy, it can generate a lot of logs quickly. > > Beyond that, I have a question about other ways that we can improve > performance. I've been reading that the use of %C or %c (we use %c{.1} > in the config) causes performance to drag, because the class must be > looked up. But from what I can tell, it is not actually using the class > name in the log output ... it's using the *Logger* name. The first line > of the below is at the top of most of the classes in Solr. All three of > these lines are in one particular class -- SolrCore: > > private static final Logger log = > LoggerFactory.getLogger(MethodHandles.lookup().lookupClass()); > private static final Logger requestLog = > LoggerFactory.getLogger(MethodHandles.lookup().lookupClass().getName() + > ".Request"); > private static final Logger slowLog = > LoggerFactory.getLogger(MethodHandles.lookup().lookupClass().getName() + > ".SlowRequest"); > > The parameter in the first "getLogger" call is a Class, but the > parameter in the other two is a String. Does the performance impact for > %c apply to String-based loggers or just Class-based loggers? If the > performance impact doesn't apply to a String-based logger, maybe we > could just add .getName() to the first line. If necessary, we could > switch to including the class name in each log message from a static > string in the class... would the performance impact of doing that be > worth the time and the massive patch? I do like the flexibility of > having log4j shorten the class name with the suffix on our "%c{.1}" > pattern, which would be challenging to make configurable inside Solr > itself. > > Keep in mind that Solr is using slf4j API calls, not log4j directly. > Our slf4j binding is log4j2. > > At the following pastes are an example of the logging output and the > log4j2 config that produced it: > > https://apaste.info/MqMq > https://apaste.info/tTcc > > Thanks, > Shawn > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > > -- Matt Sicker <[email protected]>
