RE: Why am I seeing WARN:SLF4JLOGFactory on Shutdown 7.1.x

Richard Yummy, modified 7 Years ago. New Member Posts: 10 Join Date: 11/7/18 Recent Posts
Full message from catalina.out is

WARN: The method class org.apache.commons.logging.impl.SLF4JLogFactory#release() was invoked.
WARN: Please see http://www.slf4j.org/codes.html#release for an explanation.

I  did not see this with LP 7.0 but for the last two releases of LP 7.1.1 and 7.1.2. I have experienced the warnings as the last output and immediately after closing themes using shutdown.sh.

I read the slf4j.org web site explaination, but hoped it had been fixed between 7.1.1 and 7.1.2.

Any help in understanding what impact if any. Is it something I can fix?

Thank you.
thumbnail
Christoph Rabel, modified 7 Years ago. Liferay Legend Posts: 1555 Join Date: 9/24/09 Recent Posts
I just tried this with a clean installation of Liferay Community Edition Portal 7.1.2 CE GA3 and I don't see that warning.
Do you have some of your own modules deployed? Could you check, if this still happens when you remove them?
Richard Yummy, modified 7 Years ago. New Member Posts: 10 Join Date: 11/7/18 Recent Posts
Thank you for the timely response and sounds like I bungled something.

I did not add modules.

To clarify, this is a new installation on CentOS 7.6 using the Liferay Community Edition Portal 7.1.2 CE GA3 with Tomcat bundle. I have tried both openjdk 1.8 and 11.

I have been able to consistently reproduce the warning across installation and not seeing the expected shutdown messages that I get with my LP CE 7.0, e.g. Pausing ProtocolHandler ["http-apr-8080"].

Attached the configtest.sh results, java environment variables, and catalina.out showing the error.

Advice on any additional troubleshooting files or strategies?

Thank you!
thumbnail
Christoph Rabel, modified 7 Years ago. Liferay Legend Posts: 1555 Join Date: 9/24/09 Recent Posts
I am not sure if it has anything to do with your problem. But I think, you start the process with some extra java options. Maybe they have sideeffects.

NOTE: Picked up JDK_JAVA_OPTIONS:  --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED

I guess, you start that openjdk.sh first, to set the jave paths. And then you start Liferay with tomcat/bin/startup.sh? I am not sure, how you installed Java, but you should either put that into setenv.sh or maybe into the profile of the liferay user, so that it is always set. e.g.:
https://www.cyberciti.biz/faq/linux-unix-set-java_home-path-variable/.
Richard Yummy, modified 6 Years ago. New Member Posts: 10 Join Date: 11/7/18 Recent Posts
I didn't set JDK_JAVA_OPTIONS, so that is not expected? What values should be set? or is there a way to nuke them?

Also, I did not execute any of the scripts in Liferay's /bin directory outside of the test, startup, and shutdown scripts. Was I suppose to execute others prior to the inital startup?

The file openjdk.sh is placed in /etc/profile.d/ to set the Java Environmental variables for all user sessions. The article you provided is doing the samething as I did except that the directory is called profile.d. Is there a better way?


Note:
The OpenJDK is the package as compiled by the CentOS project from Red Hat's source. I didn't do anything special and had no issues with the  strategy with LP CE 7.0, but, clearly, something has changed.

I appreciate your help.
thumbnail
Christoph Rabel, modified 6 Years ago. Liferay Legend Posts: 1555 Join Date: 9/24/09 Recent Posts
I am not sure, these settings have anything to do with the problem, but it is at least a difference. My server here is started with these runtime parameters (I checked ps -ef)

/usr/bin/java
  -Djava.util.logging.config.file=/opt/liferay/tomcat-9.0.10/conf/logging.properties
  -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
  -Djava.awt.headless=true
  -Djava.security.egd=file:/dev/./urandom
  -Djdk.tls.ephemeralDHKeySize=2048
  -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
  -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
  -Dfile.encoding=UTF8
  -Djava.net.preferIPv4Stack=true
  -Dorg.apache.catalina.loader.WebappClassLoader.ENABLE_CLEAR_REFERENCES=false
  -Duser.timezone=GMT
  -Xms2560m -Xmx2560m -XX:MaxNewSize=1536m -XX:MaxMetaspaceSize=384m -XX:MetaspaceSize=384m -XX:NewSize=1536m -XX:SurvivorRatio=7
  -Dignore.endorsed.dirs= -classpath /opt/liferay/tomcat-9.0.10/bin/bootstrap.jar:/opt/liferay/tomcat-9.0.10/bin/tomcat-juli.jar
  -Dcatalina.base=/opt/liferay/tomcat-9.0.10
  -Dcatalina.home=/opt/liferay/tomcat-9.0.10
  -Djava.io.tmpdir=/opt/liferay/tomcat-9.0.10/temp org.apache.catalina.startup.Bootstrap start

I tried it with Oracle and OpenJDK (versions 181 and 201). I don't see the problem on Debian and Ubuntu, so I have no idea what causes this for you.
Richard Yummy, modified 6 Years ago. New Member Posts: 10 Join Date: 11/7/18 Recent Posts
Christoph, I really appreciate your time. Below is my `ps -ef | grep java` output. I am not seeing a problem. I will continue to hunt.

liferay  21777     1 64 06:40 pts/0    00:02:49 /usr/lib/jvm/jre/bin/java
    -Djava.util.logging.config.file=/opt/liferay/tomcat-9.0.10/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
    -Dfile.encoding=UTF8
    -Djava.net.preferIPv4Stack=true
    -Dorg.apache.catalina.loader.WebappClassLoader.ENABLE_CLEAR_REFERENCES=false
    -Duser.timezone=GMT
    -Xms2560m -Xmx2560m -XX:MaxNewSize=1536m -XX:MaxMetaspaceSize=384m -XX:MetaspaceSize=384m -XX:NewSize=1536m -XX:SurvivorRatio=7
    -Dignore.endorsed.dirs= -classpath /opt/liferay/tomcat-9.0.10/bin/bootstrap.jar:/opt/liferay/tomcat-9.0.10/bin/tomcat-juli.jar
    -Dcatalina.base=/opt/liferay/tomcat-9.0.10
    -Dcatalina.home=/opt/liferay/tomcat-9.0.10
    -Djava.io.tmpdir=/opt/liferay/tomcat-9.0.10/temp org.apache.catalina.startup.Bootstrap start
Richard Yummy, modified 6 Years ago. New Member Posts: 10 Join Date: 11/7/18 Recent Posts
Correction:

There is a difference with our ps -ef outputs. You have the following and I do not.

  -Djava.awt.headless=true
  -Djava.security.egd=file:/dev/./urandom


I will keep digging.
thumbnail
Christoph Rabel, modified 6 Years ago. Liferay Legend Posts: 1555 Join Date: 9/24/09 Recent Posts
Those settings are probably irrelevant for your issue. I am not sure, if it is still the case, but at least in Tomcat 7 it improved tomcat startup times to set /dev/./urandom. So, it is probably a good idea to set it.

Anyway: Did you try to search for jcl-over-slf4j.jar ?
According to documentation, it is often responsible for that error. I have one in webapps/ROOT/WEB-INF/lib/jcl-over-slf4j.jar, maybe you have two of them in the path (for whatever reason).
Richard Yummy, modified 6 Years ago. New Member Posts: 10 Join Date: 11/7/18 Recent Posts
I did do a hunt for jcl-over-slf4j.jar, originally, but it was so long ago, best to go look again. It would be great if I found a duplicate and it was a simple matter of fixing by removing one or whatever. I will dig into the problem this weekend.

Good information on Tomcat and -Djava.security.egd=file:/dev/./urandom . I will take a closer look at this as well.
Richard Yummy, modified 6 Years ago. New Member Posts: 10 Join Date: 11/7/18 Recent Posts
I did a clean install of CentOS 7.6 with updates. Installed java-11-openjdk and export JRE_HOME=/usr/lib/jvm/jre/. Downloaded 7.1.2 GA3, ./startup.sh then ./shutdown.sh.  I made no changes to the operating system except as stated an no configuration outside of the defaults for Liferay.
16-Apr-2019 14:40:23.786 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 91061 ms
2019-04-16 14:40:59.394 INFO  [main][ThemeHotDeployListener:171] 1 theme for classic-theme was unregistered
2019-04-16 14:40:59.946 INFO  [main][ThemeHotDeployListener:171] 1 theme for admin-theme was unregistered
WARN: The method class org.apache.commons.logging.impl.SLF4JLogFactory#release() was invoked.
WARN: Please see http://www.slf4j.org/codes.html#release for an explanation.
I verified there was only one instance of jcl-over-slf4j.jar.
[root@liferay bin]# locate jcl-over-slf4j.jar
/root/liferay/tomcat-9.0.10/webapps/ROOT/WEB-INF/lib/jcl-over-slf4j.jar

I just want to scream.