Mi aplicación es una aplicación de arranque de sprint que usa log4j2 y se ejecuta en un servidor Wildfly. Después del ataque de día cero, actualizamos a la última versión de log4j2 (2.16). Pero después de la actualización de log4j, mi aplicación deja de funcionar de vez en cuando. Y cuando miré los volcados de subprocesos, descubrí que hay un interbloqueo creado por log4j. Aquí está mi configuración log4j. Estaba funcionando bien antes de la actualización.
<?xml version="1.0" encoding="UTF-8" ?> <Configuration> <Properties> <Property name="LOGDIR">${sys:jboss.server.log.dir}/application</Property> <Property name="FILE_LOG_PATTERN">%d %-5p [%-8.8t] %-25.25c{1} | [%X{correlationId}] %m%n</Property> </Properties> <Appenders> <Console name="SYSOUT" target="SYSTEM_OUT" follow="true"> <PatternLayout pattern="${FILE_LOG_PATTERN}"/> </Console> <RollingFile name="CSL" fileName="${LOGDIR}/csl.log" filePattern="${LOGDIR}/csl.%d{yyyy-MM-dd}.log.gz" ignoreExceptions="false"> <PatternLayout pattern="${FILE_LOG_PATTERN}"/> <Policies> <TimeBasedTriggeringPolicy/> </Policies> <DefaultRolloverStrategy> <Delete basePath="${LOGDIR}" maxDepth="1"> <IfAny> <IfFileName glob="csl*.log.gz" /> <IfFileName glob="access_log*.log" /> </IfAny> <IfLastModified age="7d" /> </Delete> </DefaultRolloverStrategy> </RollingFile> <RollingFile name="OTR" fileName="${LOGDIR}/otr.log" filePattern="${LOGDIR}/otr.%d{yyyy-MM-dd}.log.gz" ignoreExceptions="true" bufferedIO="true"> <PatternLayout pattern="${FILE_LOG_PATTERN}"/> <Policies> <TimeBasedTriggeringPolicy/> </Policies> <DefaultRolloverStrategy> <Delete basePath="${LOGDIR}" maxDepth="1"> <IfFileName glob="otr*.log.gz" /> <IfLastModified age="23d" /> </Delete> </DefaultRolloverStrategy> </RollingFile> </Appenders> <Loggers> <Logger name="org.apache.catalina.startup.DigesterFactory" level="error" /> <Logger name="org.apache.catalina.util.LifecycleBase" level="error" /> <Logger name="org.apache.coyote.http11.Http11NioProtocol" level="warn" /> <logger name="org.apache.sshd.common.util.SecurityUtils" level="warn"/> <Logger name="org.apache.tomcat.util.net.NioSelectorPool" level="warn" /> <Logger name="org.eclipse.jetty.util.component.AbstractLifeCycle" level="error" /> <Logger name="org.hibernate.validator.internal.util.Version" level="warn" /> <logger name="org.springframework.boot.actuate.endpoint.jmx" level="warn"/> <logger name="org.springframework" level="info"/> <logger name="org.springframework.aop.framework" level="warn"/> <logger name="org.apache.jasper.servlet.JspServlet" level="trace"/> <logger name="com.zaxxer.hikari.pool.HikariPool" level="debug"/> <logger name="com.google.code.ssm.spring.SSMCache" level="warn"/> <logger name="com.faskan" level="info" additivity="false"> <appender-ref ref="OTR" /> <appender-ref ref="CSL" /> </logger> <Root level="info"> <AppenderRef ref="CSL"/> <AppenderRef ref="SYSOUT"/> </Root> </Loggers> </Configuration>Al analizar este problema, encontré un posible defecto en el código log4j. No estoy seguro de si eso puede resultar en un punto muerto.
Posible error de Log4J : según las notas de la versión, se solucionó Habilitar el vaciado inmediato en RollingFileAppender cuando la E/S almacenada en búfer no está habilitada. (LOG4J2-3114) . Pero el código simplemente hace lo contrario en RollingFileAppenderBuilder.
private Appender createAppender(final String name, final Log4j1Configuration config, final Layout layout, final Filter filter, final boolean bufferedIo, boolean immediateFlush, final String fileName, final String level, final String maxSize, final String maxBackups) { org.apache.logging.log4j.core.Layout<?> fileLayout = null; if (bufferedIo) { immediateFlush = true; } ... Debería haber sido if(!bufferedIo) { immediateFlush = true; } . Y uno de mis appender establece explícitamente el valor de bufferedIo en verdadero. Sé que log4j hace un bufferedio por defecto y no es necesario configurar este indicador explícitamente. Pero, lamentablemente, el código en el que estoy trabajando es un código heredado y la configuración funcionaba bien antes de la actualización.
Threaddump "tarea predeterminada-128" #450 prio=5 os_prio=0 tid=0x00007f31f80cf800 nid=0x14c8 esperando la entrada del monitor [0x00007f31a7d88000] java.lang.Thread.State: BLOQUEADO (en el monitor de objetos) en org.apache.logging.log4j .core.appender.OutputStreamManager.writeBytes(OutputStreamManager.java:352) - esperando bloquear <0x00000000c0e70eb0> (un org.apache.logging.log4j.core.appender.OutputStreamManager) en org.apache.logging.log4j.core.layout .TextEncoderHelper.writeEncodedText(TextEncoderHelper.java:96) en org.apache.logging.log4j.core.layout.TextEncoderHelper.encodeText(TextEncoderHelper.java:65) en org.apache.logging.log4j.core.layout.StringBuilderEncoder.encode (StringBuilderEncoder.java:68) en org.apache.logging.log4j.core.layout.StringBuilderEncoder.encode(StringBuilderEncoder.java:32) en org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java :228) en org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:60) en org.apache.logging.log4j.core.appender.Abstr actOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197) en org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190) en org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append( AbstractOutputStreamAppender.java:181) en org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:161) en org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java: 134) en org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:125) en org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89) en org .apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:542) en org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:500) en org.apache.logging .log4j.core.config.LoggerConfig.log(LoggerConfig.java:483) en org.apache.logging .log4j.core.config.LoggerConfig.logParent(LoggerConfig.java:533) en org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502) en org.apache.logging.log4j.core .config.LoggerConfig.log(LoggerConfig.java:483) en org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:388) en org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy .log(AwaitCompletionReliabilityStrategy.java:63) en org.apache.logging.log4j.core.Logger.logMessage(Logger.java:153) en org.apache.logging.slf4j.Log4jLogger.log(Log4jLogger.java:376) en org.apache.commons.logging.impl.SLF4JLocationAwareLog.error(SLF4JLocationAwareLog.java:203) en org.springframework.boot.web.support.ErrorPageFilter.handleCommittedResponse(ErrorPageFilter.java:225)
Encontré mi respuesta en este hilo https://developer.jboss.org/thread/241453 . Es un problema de configuración de log4j/jboss. La solución es excluir el subsistema de registro de jboss de la configuración de implementación de jboss o deshacerse del agregador de consola. Gracias a Ralph Goers del equipo de Log4J por guiarme hacia el hilo jboss.
Cerré el problema que planteé en https://issues.apache.org/jira/browse/LOG4J2-3274 . El fragmento de código que compartí en esta pregunta era del adaptador de compatibilidad log4j-1.2 que no tiene ningún impacto en mi código porque ya estoy usando la última versión de API.