log4j_init_tomcat.properties not found on SAP Commerce 2011

[adiputera]

Hi All,

Recently we're trying to upgrade our hybris version, until 2005, everything is fine, but on 2011 I got this error when starting server :

ERROR StatusLogger File not found in file system or classpath: log4j_init_tomcat.properties
ERROR StatusLogger Reconfiguration failed: No configuration found for '2f8e39b4' at 'null' in 'null'

That error is not a blocker and the server startup successfully, the problem is, looks like the logger is not initialized/detected, and I notice until server startup there are a lot less logs than the usual. All extension's log is not being logged. If I check on HAC -> Platform -> logging, I only got 2 entries, usually I have up to 22 entries.

I try to search for log4j_init_tomcat.properties on 1811, 1905, and 2005 but I can't find that file.

This is Logging configuration in HAC :

Full Log until server startup, then stopping server :

Running hybrisPlatform on Tomcat...
--> Wrapper Started as Console
Java Service Wrapper Professional Edition 64-bit 3.5.29
  Copyright (C) 1999-2016 Tanuki Software, Ltd. All Rights Reserved.
    http://wrapper.tanukisoftware.com
  Licensed to SAP SE for hybris Platform


Launching a JVM...
Listening for transport dt_socket at address: 8000
WrapperManager: Initializing...
Jan 18, 2021 4:46:57 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-nio-9001"]
Jan 18, 2021 4:46:57 PM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFO: Using a shared selector for servlet write/read
Jan 18, 2021 4:46:57 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["https-jsse-nio-9002"]
Jan 18, 2021 4:46:57 PM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFO: Using a shared selector for servlet write/read
Jan 18, 2021 4:46:57 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-nio-127.0.0.1-8009"]
Jan 18, 2021 4:46:57 PM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFO: Using a shared selector for servlet write/read
Jan 18, 2021 4:46:57 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 652 ms
Jan 18, 2021 4:46:57 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service [Catalina]
Jan 18, 2021 4:46:57 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/8.5.57
Jan 18, 2021 4:46:57 PM de.hybris.tomcat.ConfigurableRfc6265CookieProcessor$JuliLogHandler info
INFO: No Same Site cookie config file found at tomcat\bin\sameSiteCookies.properties
Loading additional classes from: [file:/home/hybris/bin/platform/resources/libpatches/spring-web-patch-5.2.9.RELEASE-1.jar]
ERROR StatusLogger File not found in file system or classpath: log4j_init_tomcat.properties
ERROR StatusLogger Reconfiguration failed: No configuration found for '7a217bbe' at 'null' in 'null'
Jan 18, 2021 4:47:00 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 18, 2021 4:47:00 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 18, 2021 4:47:00 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 18, 2021 4:47:00 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 18, 2021 4:47:07 PM de.hybris.platform.solr.controller.commands.StartSolrServersCommand executeCommand
INFO: Starting Solr servers ...
Jan 18, 2021 4:47:07 PM de.hybris.platform.solr.controller.commands.StartSolrServerCommand getSolrServerStatus
INFO: Checking Solr server status for instance [name: default, hostname: localhost, port: 8983, mode: STANDALONE]
Jan 18, 2021 4:47:07 PM de.hybris.platform.solr.controller.commands.StartSolrServerCommand startSolrServer
INFO: Starting Solr server for instance [name: default, hostname: localhost, port: 8983, mode: STANDALONE]
Waiting up to 180 seconds to see Solr running on port 8983 [\]  
Started Solr server on port 8983 (pid=38669). Happy searching!

WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by ma.glasnost.orika.converter.builtin.CloneableConverter (file:/home/hybris/bin/platform/ext/core/lib/orika-core-1.5.2.jar) to method java.lang.Object.clone()
WARNING: Please consider reporting this to the maintainers of ma.glasnost.orika.converter.builtin.CloneableConverter
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:45 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:46 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:46 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:46 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:46 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'DispatcherServlet'
Jan 18, 2021 4:48:47 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:47 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:48 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc-v2'
Jan 18, 2021 4:48:49 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:49 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'DispatcherServlet'
Jan 18, 2021 4:48:50 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:50 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:50 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:51 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:51 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:51 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:51 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:53 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:53 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:54 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:54 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:54 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:54 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'DispatcherServlet'
Jan 18, 2021 4:48:54 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:55 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:55 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:55 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:55 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:55 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 18, 2021 4:48:55 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:56 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:56 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:58 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 18, 2021 4:48:58 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:48:59 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:48:59 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:49:00 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:49:02 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:49:02 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'DispatcherServlet'
Jan 18, 2021 4:49:02 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 18, 2021 4:49:02 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:49:02 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:49:02 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:49:02 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'DispatcherServlet'
Jan 18, 2021 4:49:03 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'DispatcherServlet'
Jan 18, 2021 4:49:03 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:49:03 PM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 18, 2021 4:49:03 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring root WebApplicationContext
Jan 18, 2021 4:49:04 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:49:05 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'DispatcherServlet'
Jan 18, 2021 4:49:06 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'springmvc'
Jan 18, 2021 4:49:08 PM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'DispatcherServlet'
Jan 18, 2021 4:50:09 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-nio-9001"]
Jan 18, 2021 4:50:09 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["https-jsse-nio-9002"]
Jan 18, 2021 4:50:09 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-nio-127.0.0.1-8009"]
Jan 18, 2021 4:50:09 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 191925 ms
^CINT trapped.  Shutting down.
shutting down hybris registry..
Sending stop command to Solr running on port 8983 ... waiting up to 180 seconds to allow Jetty process 38669 to stop gracefully.
ERROR StatusLogger File not found in file system or classpath: log4j_init_tomcat.properties
ERROR StatusLogger Reconfiguration failed: No configuration found for 'Default' at 'null' in 'null'
<-- Wrapper Stopped

Tomcat configuration :

java.opts.gc = -XX:+UseG1GC -XX:+UseTLAB -Xlog:gc:${HYBRIS_LOG_DIR}/tomcat/java_gc.log
java.opts.jmx = -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false
java.opts.log = -Dlog4j.configurationFile=log4j_init_tomcat.properties
java.opts.dirs = -Dcatalina.base=%CATALINA_BASE% -Dcatalina.home=%CATALINA_HOME% -Djava.io.tempdir=${HYBRIS_TEMP_DIR}
java.opts.enc = -Dfile.encoding=UTF-8
java.opts.oom = -XX:-HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=${HYBRIS_LOG_DIR}/tomcat
java.time.zone=-Duser.timezone=Asia/Jakarta
tomcat.generaloptions = -server ${java.opts.mem} ${java.opts.gc} ${java.opts.jmx} ${java.opts.log} ${java.opts.dirs} ${java.opts.enc} ${java.opts.oom} -Djava.net.preferIPv4Stack=true -Djava.net.preferIPv6Addresses=false ${java.time.zone}
tomcat.javaoptions=-Djava.net.preferIPv4Stack=true -Djava.net.preferIPv6Addresses=false

Any help is appreciated.

Thanks.

[stefanweis]

Same here. Were you able to resolve this issue?

[adiputera]

stefanweis not yet, still looking for the solution

[former_member1069441]

Hi adiputera, were you able to resolved this?

[adiputera]

Hi icysorceress

Yes I'm able to resolve this.

Please update your tomcat.generaloptions and tomcat.javaoptions with the one from platform/project.properties and then add your own tomcat options.

Remove java.opts.log properties from local.properties, or if you didn't want to remove it, add java.opts.log to tomcat.javaoptions

[adiputera · Accepted solution]

Okay so to prevent any confussion, my final tomcat options is

#tomcat properties
java.time.zone=-Duser.timezone=Asia/Jakarta
java.opts.mem = -Xms12G -Xmx12G
tomcat.javaoptions=-Djava.net.preferIPv4Stack=true -Djava.net.preferIPv6Addresses=false
tomcat.generaloptions=${tomcat.jdkmodules.config} -Djava.locale.providers=COMPAT,CLDR ${java.opts.mem} -ea -Dcatalina.base=%CATALINA_BASE% -Dcatalina.home=%CATALINA_HOME% -Dfile.encoding=UTF-8 -Djava.util.logging.config.file=jdk_logging.properties -Djava.io.tmpdir="${HYBRIS_TEMP_DIR}" ${java.time.zone}

I replace my custom tomcat.javaoptions and tomcat.generaloptions with the one from platform/project.properties and then re-add my custom tomcat options (java.time.zone and java.opts.mem)

[adiputera]

After consulting with SAP, the solution is to remove `${java.opts.log}` from tomcat.generaloptions and add it to tomcat.javaoptions

java.opts.gc=-XX:+UseG1GC -XX:+UseTLAB -Xlog:gc:${HYBRIS_LOG_DIR}/tomcat/java_gc.log
java.opts.jmx =-Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false
java.opts.log=-Dlog4j.configurationFile=log4j_init_tomcat.properties
java.opts.dirs =-Dcatalina.base=%CATALINA_BASE%-Dcatalina.home=%CATALINA_HOME%-Djava.io.tempdir=${HYBRIS_TEMP_DIR}
java.opts.enc =-Dfile.encoding=UTF-8
java.opts.oom =-XX:-HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=${HYBRIS_LOG_DIR}/tomcat
java.time.zone=-Duser.timezone=Asia/Jakarta
tomcat.generaloptions =-server ${java.opts.mem} ${java.opts.gc} ${java.opts.jmx} ${java.opts.dirs} ${java.opts.enc} ${java.opts.oom} -Djava.net.preferIPv4Stack=true -Djava.net.preferIPv6Addresses=false ${java.time.zone}
tomcat.javaoptions=-Djava.net.preferIPv4Stack=true -Djava.net.preferIPv6Addresses=false ${java.opts.log}

[namelessf3ar]

This solved all issues, thanks.

[adiputera]

namelessf3ar you're welcome, glad it help you

[former_member734243]

Thanks a lot for the solution. Was stuck with this issue for a long time.

[adiputera]

I'm glad it helps vishal.parmar.hmmh

[mpern]

do not use log4j1.x, it is deprecated and EOL.

see my answer below

https://answers.sap.com/answers/13425459/view.html

[mpern]

Please do not use log4j 1.x anymore, it is deprecated and EOL. We only keep the dependency around for legacy reasons.

All (new) logging should be done via SLF4J, the logging itself is handled by log4j2 under the hood.

Only use property-based logging configuration, especially in CCv2.

log4j2.logger.foo.name=com.package.Foo
log4j2.logger.foo.level=WARN

Further information: Upgrading to Log4j2

Other important considerations for CCv2:

• do not change the root logger
• do not configure additional appenders
• do not configure a custom log4j2 xml configuration

All logs must go to stdout with the default config.

[adiputera]

We upgrade from 6.6 to 20.11, so all properties that is not causing errors are still there.

So, we just have to remove java.opts.log from our local.properties?

[mpern]

yes.

I would also highly recommend you re-align your custom tomcat.generaloptions with the new ootb settings, in case you haven't done so already.

[adiputera]

Okay, thank you!

[stefanweis]

There seems to be a change in the new log4j version 2.13.3 which came with Hybris 2011.

For tomcat we had our logging parameter set like this: -Dlog4j.configuration=, but it needs to be set like this -Dlog4j.configurationFile=

After that, logging is working fine again

[adiputera]

Thanks for answering. Yes I notice new log4j version, already tried -Dlog4j.configurationFile=, but still not working