jboss EAP 7 中 standalone-ha 配置的双重日志输出
Double log output for standalone-ha config in jboss EAP 7
我们最近从 Jboss EAP 5.1 升级到 Jboss EAP 7.2。
启动我们的应用程序后，我们可以看到每个操作都在日志文件 server.log 中记录了两次。但是在控制台输出日志是正常的。
2020-05-04 04:41:57,181 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:10190
2020-05-04 04:41:57,181 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:10190
2020-05-04 04:41:57,181 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: JBoss EAP 7.2.0.GA (WildFly Core 6.0.11.Final-redhat-00001) started in 87177ms - Started 2482 of 2655 services (425 services are lazy, passive or on-demand)
2020-05-04 04:41:57,181 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: JBoss EAP 7.2.0.GA (WildFly Core 6.0.11.Final-redhat-00001) started in 87177ms - Started 2482 of 2655 services (425 services are lazy, passive or on-demand)
2020-05-04 03:51:26,345 INFO [nucleusNamespace.atg.dynamo.servlet.dafpipeline.ProfileRequestServlet] (default task-1) [sid : LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl ][pid : 53590070 ][cpoid : 610080 ]This user session is LOGGEDIN
2020-05-04 03:51:26,345 INFO [nucleusNamespace.atg.dynamo.servlet.dafpipeline.ProfileRequestServlet] (default task-1) [sid : LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl ][pid : 53590070 ][cpoid : 610080 ]This user session is LOGGEDIN
2020-05-04 03:51:26,580 INFO [nucleusNamespace.delixl.sol.log.LogService] (default task-1) {6022} [LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl|(null)] 20200504-035126359 43.229.89.35 LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl 53590070 /webshop/catalog/json/profileMarkerJson.jsp 221 200
2020-05-04 03:51:26,580 INFO [nucleusNamespace.delixl.sol.log.LogService] (default task-1) {6022} [LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl|(null)] 20200504-035126359 43.229.89.35 LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl 53590070 /webshop/catalog/json/profileMarkerJson.jsp 221 200
日志记录配置是默认配置，我们没有更改它。以下是 standalone.xml 文件中的默认日志配置；
<subsystem xmlns="urn:jboss:domain:logging:6.0">
<console-handler name="CONSOLE">
<level name="INFO"/>
<formatter>
<named-formatter name="COLOR-PATTERN"/>
</formatter>
</console-handler>
<periodic-rotating-file-handler name="FILE" autoflush="true">
<formatter>
<named-formatter name="PATTERN"/>
</formatter>
<file relative-to="jboss.server.log.dir" path="server.log"/>
<suffix value=".yyyy-MM-dd"/>
<append value="true"/>
</periodic-rotating-file-handler>
<logger category="io.undertow.request">
<level name="ERROR"/>
</logger>
<logger category="com.arjuna">
<level name="WARN"/>
</logger>
<logger category="org.jboss.as.config">
<level name="DEBUG"/>
</logger>
<logger category="sun.rmi">
<level name="WARN"/>
</logger>
<root-logger>
<level name="INFO"/>
<handlers>
<handler name="FILE"/>
<handler name="CONSOLE"/>
</handlers>
</root-logger>
<formatter name="PATTERN">
<pattern-formatter pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n"/>
</formatter>
<formatter name="COLOR-PATTERN">
<pattern-formatter pattern="%K{level}%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n"/>
</formatter>
</subsystem>
列表项
更新
当我更改日志模式以匹配旧 Jboss 时，有双日志，但是，其中一个双行的模式不同。
日志模式：
<formatter name="PATTERN">
<pattern-formatter pattern="%d %-5p [%c] [%X{sid}] [pid:%X{pid}] [oid:%X{cpoid}] %m%n"/>
</formatter>
更改日志模式后的日志输出：
2020-05-04 11:13:37,931 INFO [org.jboss.as.server] [] [pid:] [oid:] WFLYSRV0212: Resuming server
2020-05-04 11:13:37,931 INFO [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0212: Resuming server
2020-05-04 11:13:37,933 INFO [org.jboss.as] [] [pid:] [oid:] WFLYSRV0060: Http management interface listening on http://127.0.0.1:10190/management
2020-05-04 11:13:37,933 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0060: Http management interface listening on http://127.0.0.1:10190/management
2020-05-04 11:13:37,934 INFO [org.jboss.as] [] [pid:] [oid:] WFLYSRV0051: Admin console listening on http://127.0.0.1:10190
2020-05-04 11:13:37,934 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:10190
2020-05-04 11:13:37,934 INFO [org.jboss.as] [] [pid:] [oid:] WFLYSRV0025: JBoss EAP 7.2.0.GA (WildFly Core 6.0.11.Final-redhat-00001) started in 116096ms - Started 2482 of 2655 services (425 services are lazy, passive or on-demand)
2020-05-04 11:13:37,934 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: JBoss EAP 7.2.0.GA (WildFly Core 6.0.11.Final-redhat-00001) started in 116096ms - Started 2482 of 2655 services (425 services are lazy, passive or on-demand)
正如之前在控制台 (stdout) 中提到的，没有重复但显示的日志模式是我更改的模式。
请支持我解决server.log
中的重复登录问题
我已经找到解决这个问题的方法，双重日志记录问题可能是由于代码库中的 log4j 与 JBoss 之间存在冲突。
我不得不在 Jboss 中禁用以下 log4j 配置以解决双重日志记录问题
在$JBOSS_HOME/modules/system/layers/base/org/apache/log4j/main/module.xml
中设置导出="false"
<module name="org.jboss.log4j.logmanager" export="false"/>
我们最近从 Jboss EAP 5.1 升级到 Jboss EAP 7.2。 启动我们的应用程序后，我们可以看到每个操作都在日志文件 server.log 中记录了两次。但是在控制台输出日志是正常的。
2020-05-04 04:41:57,181 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:10190
2020-05-04 04:41:57,181 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:10190
2020-05-04 04:41:57,181 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: JBoss EAP 7.2.0.GA (WildFly Core 6.0.11.Final-redhat-00001) started in 87177ms - Started 2482 of 2655 services (425 services are lazy, passive or on-demand)
2020-05-04 04:41:57,181 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: JBoss EAP 7.2.0.GA (WildFly Core 6.0.11.Final-redhat-00001) started in 87177ms - Started 2482 of 2655 services (425 services are lazy, passive or on-demand)
2020-05-04 03:51:26,345 INFO [nucleusNamespace.atg.dynamo.servlet.dafpipeline.ProfileRequestServlet] (default task-1) [sid : LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl ][pid : 53590070 ][cpoid : 610080 ]This user session is LOGGEDIN
2020-05-04 03:51:26,345 INFO [nucleusNamespace.atg.dynamo.servlet.dafpipeline.ProfileRequestServlet] (default task-1) [sid : LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl ][pid : 53590070 ][cpoid : 610080 ]This user session is LOGGEDIN
2020-05-04 03:51:26,580 INFO [nucleusNamespace.delixl.sol.log.LogService] (default task-1) {6022} [LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl|(null)] 20200504-035126359 43.229.89.35 LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl 53590070 /webshop/catalog/json/profileMarkerJson.jsp 221 200
2020-05-04 03:51:26,580 INFO [nucleusNamespace.delixl.sol.log.LogService] (default task-1) {6022} [LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl|(null)] 20200504-035126359 43.229.89.35 LhGndXwn4RWowaUagJIhFZZ5QBLJSGPGgy6V16Pl 53590070 /webshop/catalog/json/profileMarkerJson.jsp 221 200
日志记录配置是默认配置，我们没有更改它。以下是 standalone.xml 文件中的默认日志配置；
<subsystem xmlns="urn:jboss:domain:logging:6.0">
<console-handler name="CONSOLE">
<level name="INFO"/>
<formatter>
<named-formatter name="COLOR-PATTERN"/>
</formatter>
</console-handler>
<periodic-rotating-file-handler name="FILE" autoflush="true">
<formatter>
<named-formatter name="PATTERN"/>
</formatter>
<file relative-to="jboss.server.log.dir" path="server.log"/>
<suffix value=".yyyy-MM-dd"/>
<append value="true"/>
</periodic-rotating-file-handler>
<logger category="io.undertow.request">
<level name="ERROR"/>
</logger>
<logger category="com.arjuna">
<level name="WARN"/>
</logger>
<logger category="org.jboss.as.config">
<level name="DEBUG"/>
</logger>
<logger category="sun.rmi">
<level name="WARN"/>
</logger>
<root-logger>
<level name="INFO"/>
<handlers>
<handler name="FILE"/>
<handler name="CONSOLE"/>
</handlers>
</root-logger>
<formatter name="PATTERN">
<pattern-formatter pattern="%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n"/>
</formatter>
<formatter name="COLOR-PATTERN">
<pattern-formatter pattern="%K{level}%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%e%n"/>
</formatter>
</subsystem>
列表项
更新
当我更改日志模式以匹配旧 Jboss 时，有双日志，但是，其中一个双行的模式不同。
日志模式：
<formatter name="PATTERN">
<pattern-formatter pattern="%d %-5p [%c] [%X{sid}] [pid:%X{pid}] [oid:%X{cpoid}] %m%n"/>
</formatter>
更改日志模式后的日志输出：
2020-05-04 11:13:37,931 INFO [org.jboss.as.server] [] [pid:] [oid:] WFLYSRV0212: Resuming server
2020-05-04 11:13:37,931 INFO [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0212: Resuming server
2020-05-04 11:13:37,933 INFO [org.jboss.as] [] [pid:] [oid:] WFLYSRV0060: Http management interface listening on http://127.0.0.1:10190/management
2020-05-04 11:13:37,933 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0060: Http management interface listening on http://127.0.0.1:10190/management
2020-05-04 11:13:37,934 INFO [org.jboss.as] [] [pid:] [oid:] WFLYSRV0051: Admin console listening on http://127.0.0.1:10190
2020-05-04 11:13:37,934 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:10190
2020-05-04 11:13:37,934 INFO [org.jboss.as] [] [pid:] [oid:] WFLYSRV0025: JBoss EAP 7.2.0.GA (WildFly Core 6.0.11.Final-redhat-00001) started in 116096ms - Started 2482 of 2655 services (425 services are lazy, passive or on-demand)
2020-05-04 11:13:37,934 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025: JBoss EAP 7.2.0.GA (WildFly Core 6.0.11.Final-redhat-00001) started in 116096ms - Started 2482 of 2655 services (425 services are lazy, passive or on-demand)
正如之前在控制台 (stdout) 中提到的，没有重复但显示的日志模式是我更改的模式。
请支持我解决server.log
中的重复登录问题我已经找到解决这个问题的方法，双重日志记录问题可能是由于代码库中的 log4j 与 JBoss 之间存在冲突。 我不得不在 Jboss 中禁用以下 log4j 配置以解决双重日志记录问题
在$JBOSS_HOME/modules/system/layers/base/org/apache/log4j/main/module.xml
<module name="org.jboss.log4j.logmanager" export="false"/>