Tomcat9 Log4j2 - ведение журнала отличается между двумя серверами

Я использую два разных сервера Tomcat9 (DEV, PROD), каждый из которых работает с отдельными поставщиками услуг CentOS 7, и журналы приложений, сгенерированные с использованием одного и того же log4j2.xml, отличаются. В версии DEV я получаю полный журнал com.example, но в версии PROD я получаю только журнал org.hibernate.

Оба сервера настроены одинаково (показано ниже). Оба используют один и тот же log4j2.xml, MyWebApp.war, развернутый на каждом Tomcat, идентичен.

Оба Tomcats являются стандартными установками - это означает, что я не добавлял какие-либо jar-файлы или свойства log4j ни к одному из них.

Я надеюсь, что у кого-то есть что рассмотреть.

Спасибо,

Боб

Конфигурация РАЗРАБОТЧИКА:

 Provider: VPS
 rpm -q centos-release
    centos-release-7-6.1810.2.el7.centos.x86_64 

 java -cp /opt/tomcat/apache-tomcat-9.0.20/lib/catalina.jar org.apache.catalina.util.ServerInfo
    Server version: Apache Tomcat/9.0.20
    Server built:   May 3 2019 22:26:00 UTC
    Server number:  9.0.20.0
    OS Name:        Linux
    OS Version:     2.6.32-042stab127.2
    Architecture:   amd64
    JVM Version:    1.8.0_212-b04
    JVM Vendor:     Oracle Corporation

Конфигурация PROD:

 Provider: Jelastic
 rpm -q centos-release
    centos-release-7-6.1810.2.el7.centos.x86_64

 java -cp /opt/tomcat/lib/catalina.jar org.apache.catalina.util.ServerInfo
    Server version: Apache Tomcat/9.0.19
    Server built:   Apr 12 2019 14:22:48 UTC
    Server number:  9.0.19.0
    OS Name:        Linux
    OS Version:     3.10.0
    Architecture:   amd64
    JVM Version:    1.8.0_202-b08
    JVM Vendor:     Oracle Corporation

log4j2.xml:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Properties>
        <Property name="logPath">/home/example/logs</Property>
    </Properties>

    <Appenders>
        <Console name="console" target="SYSTEM_OUT">
            <PatternLayout
                pattern="%d [%t] %-5p [%C.%M()] %m%n" />
        </Console>

        <RollingFile name="rollingFile" fileName="${logPath}/MyWebApp.log"
            filePattern="${logPath}/cucumber-log_%d{yyyy-MM-dd}.log">
            <PatternLayout
                pattern="%d [%t] %-5p [%C.%M()] %m%n" />
            <Policies>
                <OnStartupTriggeringPolicy />
                <TimeBasedTriggeringPolicy interval="1"
                    modulate="true" />
            </Policies>
        </RollingFile>
    </Appenders>

    <Loggers>
        <Logger name="org.springframework" level="warn" additivity="false">
           <AppenderRef ref="console" level="warn"/>
           <AppenderRef ref="rollingFile" level="warn"/>
        </Logger>
        <Logger name="org.hibernate" level="debug" additivity="false">
           <AppenderRef ref="console" level="debug"/>
           <AppenderRef ref="rollingFile" level="debug"/>
        </Logger>
        <Logger name="com.example" level="trace" additivity="false">
           <AppenderRef ref="console" level="trace"/>
           <AppenderRef ref="rollingFile" level="trace"/>
        </Logger>
        <Root level="TRACE" additivity="false">
            <AppenderRef ref="console" />
            <AppenderRef ref="RollingFile" />
        </Root>
    </Loggers>
</Configuration>

mywebapp.war:

введите здесь описание изображения

DEV MyWebApp.log (конец режима гибернации И начало ведения журнала mywebapp):

2019-06-13 05:18:36,998 [main] DEBUG [org.hibernate.engine.transaction.jta.platform.internal.JtaPlatformInitiator.initiateService()] No JtaPlatform was specified, checking resolver
2019-06-13 05:18:36,998 [main] TRACE [org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService()] Initializing service [role=org.hibernate.engine.transaction.jta.platform.spi.JtaPlatformResolver]
2019-06-13 05:18:37,002 [main] DEBUG [org.hibernate.engine.transaction.jta.platform.internal.JtaPlatformResolverInitiator.initiateService()] No JtaPlatformResolver was specified, using default [org.hibernate.engine.transaction.jta.platform.internal.StandardJtaPlatformResolver]
2019-06-13 05:18:37,027 [main] DEBUG [org.hibernate.engine.transaction.jta.platform.internal.StandardJtaPlatformResolver.resolveJtaPlatform()] Could not resolve JtaPlatform, using default [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2019-06-13 05:18:37,028 [main] INFO  [org.hibernate.engine.transaction.jta.platform.internal.JtaPlatformInitiator.initiateService()] HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2019-06-13 05:18:37,031 [main] DEBUG [org.hibernate.query.spi.NamedQueryRepository.checkNamedQueries()] Checking 0 named HQL queries
2019-06-13 05:18:37,031 [main] DEBUG [org.hibernate.query.spi.NamedQueryRepository.checkNamedQueries()] Checking 0 named SQL queries
2019-06-13 05:18:37,032 [main] TRACE [org.hibernate.type.spi.TypeConfiguration.sessionFactoryCreated()] Handling #sessionFactoryCreated from [org.hibernate.internal.SessionFactoryImpl@35c7c5e] for TypeConfiguration
2019-06-13 05:18:37,036 [main] DEBUG [org.hibernate.internal.SessionFactoryRegistry.<init>()] Initializing SessionFactoryRegistry : org.hibernate.internal.SessionFactoryRegistry@2ebf0e46
2019-06-13 05:18:37,037 [main] DEBUG [org.hibernate.internal.SessionFactoryRegistry.addSessionFactory()] Registering SessionFactory: 7ffcae61-38d8-4cc8-9cc2-4889b35589f0 (<unnamed>)
2019-06-13 05:18:37,038 [main] DEBUG [org.hibernate.internal.SessionFactoryRegistry.addSessionFactory()] Not binding SessionFactory to JNDI, no JNDI name configured
2019-06-13 05:20:23,717 [ajp-nio-8009-exec-1] WARN  [com.example.tanglemydata.controller.AccountController.getAllAdData()] ENTRY
2019-06-13 05:20:23,719 [ajp-nio-8009-exec-1] DEBUG [com.example.tanglemydata.service.AccountService.getAllAdData()] ENTRY
2019-06-13 05:20:23,794 [ajp-nio-8009-exec-1] TRACE [org.hibernate.internal.SessionFactoryImpl$SessionBuilderImpl.openSession()] Opening Hibernate Session.  tenant=null, owner=null
2019-06-13 05:20:24,088 [ajp-nio-8009-exec-1] TRACE [org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService()] Initializing service [role=org.hibernate.resource.transaction.spi.TransactionCoordinatorBuilder]
2019-06-13 05:20:24,254 [ajp-nio-8009-exec-1] TRACE [org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService()] Initializing service [role=org.hibernate.stat.spi.StatisticsImplementor]
2019-06-13 05:20:24,295 [ajp-nio-8009-exec-1] DEBUG [org.hibernate.stat.internal.StatisticsInitiator.initiateServiceInternal()] Statistics initialized [enabled=false]
2019-06-13 05:20:24,303 [ajp-nio-8009-exec-1] TRACE [org.hibernate.service.internal.AbstractServiceRegistryImpl.initializeService()] Initializing service [role=org.hibernate.jmx.spi.JmxService]
2019-06-13 05:20:24,319 [ajp-nio-8009-exec-1] TRACE [org.hibernate.internal.SessionImpl.<init>()] Opened Session [3eb81c15-c50c-44a5-9825-5e31d3cb2172] at timestamp: 1560403224040

PROD MyWebApp.log (последние 9 записей):

2019-06-13 04:39:40,435 [main] DEBUG [org.hibernate.engine.transaction.jta.platform.internal.JtaPlatformInitiator.initiateService()] No JtaPlatform was specified, checking resolver
2019-06-13 04:39:40,437 [main] DEBUG [org.hibernate.engine.transaction.jta.platform.internal.JtaPlatformResolverInitiator.initiateService()] No JtaPlatformResolver was specified, using default [org.hibernate.engine.transaction.jta.platform.internal.StandardJtaPlatformResolver]
2019-06-13 04:39:40,505 [main] DEBUG [org.hibernate.engine.transaction.jta.platform.internal.StandardJtaPlatformResolver.resolveJtaPlatform()] Could not resolve JtaPlatform, using default [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2019-06-13 04:39:40,506 [main] INFO  [org.hibernate.engine.transaction.jta.platform.internal.JtaPlatformInitiator.initiateService()] HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2019-06-13 04:39:40,509 [main] DEBUG [org.hibernate.query.spi.NamedQueryRepository.checkNamedQueries()] Checking 0 named HQL queries
2019-06-13 04:39:40,509 [main] DEBUG [org.hibernate.query.spi.NamedQueryRepository.checkNamedQueries()] Checking 0 named SQL queries
2019-06-13 04:39:40,513 [main] DEBUG [org.hibernate.internal.SessionFactoryRegistry.<init>()] Initializing SessionFactoryRegistry : org.hibernate.internal.SessionFactoryRegistry@34e10162
2019-06-13 04:39:40,514 [main] DEBUG [org.hibernate.internal.SessionFactoryRegistry.addSessionFactory()] Registering SessionFactory: bba8ac5f-afd5-4b89-ba16-77f5c980fa0e (<unnamed>)
2019-06-13 04:39:40,515 [main] DEBUG [org.hibernate.internal.SessionFactoryRegistry.addSessionFactory()] Not binding SessionFactory to JNDI, no JNDI name configured

Командная строка DEV:

cat /proc/23517/cmdline
/usr/bin/java-Djava.util.logging.config.file=/opt/tomcat/apache-tomcat-9.0.20/conf/logging.properties-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager-Djdk.tls.ephemeralDHKeySize=2048-Djava.protocol.handler.pkgs=org.apache.catalina.webresources-Dorg.apache.catalina.security.SecurityListener.UMASK=0027-Dignore.endorsed.dirs=-classpath/opt/tomcat/apache-tomcat-9.0.20/bin/bootstrap.jar:/opt/tomcat/apache-tomcat-9.0.20/bin/tomcat-juli.jar-Dcatalina.base=/opt/tomcat/apache-tomcat-9.0.20-Dcatalina.home=/opt/tomcat/apache-tomcat-9.0.20-Djava.io.tmpdir=/opt/tomcat/apache-tomcat-9.0.20/temporg.apache.catalina.startup.Bootstrapstart

Командная строка PROD:

cat /proc/19765/cmdline
/usr/java/jdk1.8.0_202/bin/java.orig-javaagent:/java_agent/jelastic-gc-agent.jar=period=300,debug=0-XX:+UseStringDeduplication-XX:+UseG1GC-Xmaxf0.3-Xminf0.1-Xmx614M-Xmn30M-Xms32M-Djava.util.logging.config.file=/opt/tomcat/conf/logging.properties-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager-DReceiverIp=-DMagicPort=-XX:+UseCompressedOops-server-Djvm=tomcat-Djava.awt.headless=true-Djava.net.preferIPv4Stack=false-DjvmRid=-Djdk.tls.ephemeralDHKeySize=2048-Djava.protocol.handler.pkgs=org.apache.catalina.webresources-Dorg.apache.catalina.security.SecurityListener.UMASK=0027-Dignore.endorsed.dirs=-classpath/opt/tomcat/bin/bootstrap.jar:/opt/tomcat/bin/tomcat-juli.jar-Dcatalina.base=/opt/tomcat-Dcatalina.home=/opt/tomcat-Djava.io.tmpdir=/opt/tomcat/temporg.apache.catalina.startup.Bootstrapstarttomcat

person BobC    schedule 13.06.2019    source источник
comment
Запустите ps aux на обоих серверах и найдите идентификатор процесса для каждого из них. Затем запустите cat /proc/{proc_id}/cmdLine для обоих процессов и найдите переданные аргументы. Найдите любой аргумент уровня ведения журнала.   -  person Perimosh    schedule 14.06.2019
comment
@Perimosh - я не подумал посмотреть на командную строку - спасибо. Я отредактировал пост и добавил командные строки DEV и PROD. Оба они включают logging.properties, но файлы идентичны. Я не вижу в командной строке PROD ничего, что могло бы повлиять на ведение журнала, а вы?   -  person BobC    schedule 14.06.2019
comment
Ваши DEV и PROD кажутся одинаковыми, хотя я вижу некоторые различия. С точки зрения непрерывной интеграции и выпуска, если DEV — ваша последняя среда перед развертыванием в PROD, то они должны выглядеть почти одинаково. Во всяком случае, вы проверили, что это: tomcat-9.0.20 dev java.util.logging.config.file=/opt/tomcat/apache-tomcat-9.0.20/conf/logging.properties действительно одинаковы??   -  person Perimosh    schedule 14.06.2019
comment
Так же на всякий случай можно сделать md5 поверх ваших вар файлов в DEV и PROD?   -  person Perimosh    schedule 14.06.2019
comment
@Perimosh - как я уже говорил ранее, они оба включают logging.properties, но файлы идентичны. Я загрузил файлы на свою рабочую станцию, использовал BeyondCompare. Они одинаковые. Один и тот же WAR развернут на DEV и PROD.   -  person BobC    schedule 14.06.2019
comment
Вы проверили оба catalina.properties с обоих серверов?   -  person Perimosh    schedule 14.06.2019


Ответы (1)


Я ОП. Задача решена.

Это было связано с тем, что Jelastic не обновлял папку веб-приложений после развертывания Tomcat. Поэтому использовался старый log4j2.xml.

Боб

person BobC    schedule 17.06.2019