0

[7/11/19 10:34:41:786 EDT] 0000010b SystemOut O [2019-07-11 10:34:41,785] [WebContainer : 2] DEBUG loader.Loader (getRow:1533)- Result row:

This effectively slows down the deployment to > 30 minutes.

The application I am working in does not have a logging config and relies on WebSphere's Logs and Trace to control logging. I checked the log level at Troubleshooting > Logs and trace > server_name > Change log detail levels and it is set to *=info. No matter what log level is set here, SystemOut is going to print, as i believe it is not controlled by this configuration. New 20MB logs is created every 4 seconds or so.

There are no genericJvmArguments set. verboseModeClass is false. I compared server.xml of this server with another which doesn't output such SystemOut and the files look similar.

How do I troubleshoot this? What configuration could be causing this?

UPDATE added stack trace of caller of PrintStream based on this answer. I have added two stack traces here. First has a redirection and the second has com.ibm.ws.logging.WsHandlerWrapper.publish using SystemOutStream.

21:02:00.444 0x30004f00              mt.0        > java/io/PrintStream.println(Ljava/lang/String;)V bytecode method, this = 0x7ffa75098
21:02:00.444 0x30004f00       j9trc_aux.0        - jstacktrace:
21:02:00.444 0x30004f00       j9trc_aux.1        - [1] java.io.PrintStream.println (PrintStream.java:829)
21:02:00.444 0x30004f00       j9trc_aux.1        - [2] com.ibm.ejs.ras.hpel.HpelHelper.printHeader (HpelHelper.java:662)
21:02:00.444 0x30004f00       j9trc_aux.1        - [3] com.ibm.ejs.ras.RasHelper.printHeader (RasHelper.java:1898)
21:02:00.444 0x30004f00       j9trc_aux.1        - [4] com.ibm.ejs.ras.RasHelper.printHeader (RasHelper.java:1892)
21:02:00.444 0x30004f00       j9trc_aux.1        - [5] com.ibm.ejs.ras.SystemOutStream.replaceSystemOutStream (SystemOutStream.java:156)
21:02:00.444 0x30004f00       j9trc_aux.1        - [6] com.ibm.ws.runtime.WsServerImpl.redirectStream (WsServerImpl.java:459)
21:02:00.444 0x30004f00       j9trc_aux.1        - [7] com.ibm.ws.runtime.WsServerImpl.bootLoggingServices (WsServerImpl.java:402)
21:02:00.444 0x30004f00       j9trc_aux.1        - [8] com.ibm.ws.runtime.WsServerImpl.start (WsServerImpl.java:201)
21:02:00.444 0x30004f00       j9trc_aux.1        - [9] com.ibm.ws.runtime.WsServerImpl.main (WsServerImpl.java:697)
21:02:00.445 0x30004f00       j9trc_aux.1        - [10] com.ibm.ws.runtime.WsServer.main (WsServer.java:59)
21:02:00.445 0x30004f00       j9trc_aux.1        - [11] sun.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
21:02:00.445 0x30004f00       j9trc_aux.1        - [12] sun.reflect.NativeMethodAccessorImpl.invoke (NativeMethodAccessorImpl.java:90)
21:02:00.445 0x30004f00       j9trc_aux.1        - [13] sun.reflect.DelegatingMethodAccessorImpl.invoke (DelegatingMethodAccessorImpl.java:55) (Compiled Code)
21:02:00.445 0x30004f00       j9trc_aux.1        - [14] java.lang.reflect.Method.invoke (Method.java:508) (Compiled Code)
21:02:00.445 0x30004f00       j9trc_aux.1        - [15] com.ibm.wsspi.bootstrap.WSLauncher.launchMain (WSLauncher.java:234)
21:02:00.445 0x30004f00       j9trc_aux.1        - [16] com.ibm.wsspi.bootstrap.WSLauncher.main (WSLauncher.java:101)
21:02:00.445 0x30004f00       j9trc_aux.1        - [17] com.ibm.wsspi.bootstrap.WSLauncher.run (WSLauncher.java:82)
21:02:00.445 0x30004f00       j9trc_aux.1        - [18] sun.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
21:02:00.445 0x30004f00       j9trc_aux.1        - [19] sun.reflect.NativeMethodAccessorImpl.invoke (NativeMethodAccessorImpl.java:90)
21:02:00.445 0x30004f00       j9trc_aux.1        - [20] sun.reflect.DelegatingMethodAccessorImpl.invoke (DelegatingMethodAccessorImpl.java:55) (Compiled Code)
21:02:00.445 0x30004f00       j9trc_aux.1        - [21] java.lang.reflect.Method.invoke (Method.java:508) (Compiled Code)
21:02:00.445 0x30004f00       j9trc_aux.1        - [22] org.eclipse.equinox.internal.app.EclipseAppContainer.callMethodWithException (EclipseAppContainer.java:587)
21:02:00.445 0x30004f00       j9trc_aux.1        - [23] org.eclipse.equinox.internal.app.EclipseAppHandle.run (EclipseAppHandle.java:198)
21:02:00.445 0x30004f00       j9trc_aux.1        - [24] org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication (EclipseAppLauncher.java:110)
21:02:00.445 0x30004f00       j9trc_aux.1        - [25] org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start (EclipseAppLauncher.java:79)
21:02:00.445 0x30004f00       j9trc_aux.1        - [26] org.eclipse.core.runtime.adaptor.EclipseStarter.run (EclipseStarter.java:354)
21:02:00.445 0x30004f00       j9trc_aux.1        - [27] org.eclipse.core.runtime.adaptor.EclipseStarter.run (EclipseStarter.java:181)
21:02:00.445 0x30004f00       j9trc_aux.1        - [28] sun.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
21:02:00.445 0x30004f00       j9trc_aux.1        - [29] sun.reflect.NativeMethodAccessorImpl.invoke (NativeMethodAccessorImpl.java:90)
21:02:00.445 0x30004f00       j9trc_aux.1        - [30] sun.reflect.DelegatingMethodAccessorImpl.invoke (DelegatingMethodAccessorImpl.java:55)
21:02:00.445 0x30004f00       j9trc_aux.1        - [31] java.lang.reflect.Method.invoke (Method.java:508)
21:02:00.445 0x30004f00       j9trc_aux.1        - [32] org.eclipse.core.launcher.Main.invokeFramework (Main.java:340)
21:02:00.445 0x30004f00       j9trc_aux.1        - [33] org.eclipse.core.launcher.Main.basicRun (Main.java:282)
21:02:00.445 0x30004f00       j9trc_aux.1        - [34] org.eclipse.core.launcher.Main.run (Main.java:981)
21:02:00.445 0x30004f00       j9trc_aux.1        - [35] com.ibm.wsspi.bootstrap.WSPreLauncher.launchEclipse (WSPreLauncher.java:413)
21:02:00.445 0x30004f00       j9trc_aux.1        - [36] com.ibm.wsspi.bootstrap.WSPreLauncher.main (WSPreLauncher.java:174)
21:02:00.446 0x30004f00              mt.6        < java/io/PrintStream.println(Ljava/lang/String;)V bytecode method
.
.
.
02:09:27.893 0x33dd3000              mt.1        > java/io/PrintStream.println(Ljava/lang/String;)V compiled method, this = 0x700d16a70
02:09:27.893 0x33dd3000       j9trc_aux.0        - jstacktrace:
02:09:27.893 0x33dd3000       j9trc_aux.1        - [1] java.io.PrintStream.println (PrintStream.java:829) (Compiled Code)
02:09:27.893 0x33dd3000       j9trc_aux.1        - [2] com.ibm.ejs.ras.SystemStream.writeWebSphereEvent (SystemStream.java:738) (Compiled Code)
02:09:27.893 0x33dd3000       j9trc_aux.1        - [3] com.ibm.ejs.ras.SystemOutStream.logMessage (SystemOutStream.java:330) (Compiled Code)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [4] com.ibm.ejs.ras.SystemOutStream.processEvent (SystemOutStream.java:319) (Compiled Code)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [5] com.ibm.ws.logging.WsHandlerWrapper.publish (WsHandlerWrapper.java:43)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [6] java.util.logging.Logger.log (Logger.java:749) (Compiled Code)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [7] com.ibm.ws.logging.WsLogger.deliverOrBuffer (WsLogger.java:416)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [8] com.ibm.ws.logging.WsLogger.log (WsLogger.java:394)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [9] com.ibm.ws.logging.WsLogger.logp (WsLogger.java:599) (Compiled Code)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [10] org.apache.commons.logging.impl.Jdk14Logger.log (Jdk14Logger.java:126)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [11] org.apache.commons.logging.impl.Jdk14Logger.info (Jdk14Logger.java:193)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [12] org.springframework.context.support.AbstractApplicationContext.initMessageSource (AbstractApplicationContext.java:473)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [13] org.springframework.context.support.AbstractApplicationContext.refresh (AbstractApplicationContext.java:334)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [14] org.springframework.context.support.ClassPathXmlApplicationContext.<init> (ClassPathXmlApplicationContext.java:92)
02:09:27.894 0x33dd3000       j9trc_aux.1        - [15] org.springframework.context.support.ClassPathXmlApplicationContext.<init> (ClassPathXmlApplicationContext.java:77)
.
.
.
.
user2891264
  • 1
  • 2
  • 1
    That looks to me like it's coming from custom/application code rather than WebSphere. – dbreaux Jul 11 '19 at 16:21
  • The application I am working in does not have a logging config and relies on WebSphere's Logs and Trace to control logging. And there is the fact that the second server does not have this problem. – user2891264 Jul 11 '19 at 20:00
  • I am just looking for the things I can try in the server that might help me understand or give a clue. – user2891264 Jul 11 '19 at 20:03
  • "DEBUG" isn't a string that WebSphere writes. Nor that "loader.Loader..." details. I think some component in the application itself or deployed to the same WebSphere server is writing those entries. A quick search suggests maybe Hibernate? – dbreaux Jul 11 '19 at 20:53
  • You are correct. Hibernate maven dependency tree adds jboss-logging:jar:3.3.1.Final as its dependency. The first log having this issue is also related to jboss `[7/12/19 2:26:07:299 EDT] 00000095 SystemOut O [2019-07-12 02:26:07,289] [Default : 7] DEBUG jboss.logging (:38)- Logging Provider: org.jboss.logging.Log4jLoggerProvider` I expected that if my project does not have a logging configuration, WebSphere Admin logging config will take over. Has the JBoss logging taken over control of logging? – user2891264 Jul 12 '19 at 14:07
  • You can't control that JBoss logging through the WebSphere Logs & Trace settings. It looks like this describes the ways you can control it: https://docs.jboss.org/hibernate/orm/4.3/topical/html/logging/Logging.html – dbreaux Jul 12 '19 at 14:48
  • How to find the Java class using System.out.println? I have a temporary fix by unchecking `Show application print statements` in JVM logs settings. – user2891264 Jul 12 '19 at 20:09
  • I have also raised the follow up question here https://stackoverflow.com/questions/57013973/how-to-find-the-java-class-using-system-out-println – user2891264 Jul 12 '19 at 21:00
  • Pretty sure it's Hibernate logging those statements, because of a DEBUG logging level set somewhere in its configuration. – dbreaux Jul 12 '19 at 23:29

0 Answers0