How to identity what is printing to System.out in Java application

Solution Unverified - Updated -

Environment

Red Hat JBoss Enterprise Application Platform (EAP) 6.0

Issue

We are seeing a lot of stdout statements in the server.log. They look like this:

#|2013-08-26 03:44:41,991|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 83)||#]
[#|2013-08-26 03:44:41,992|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 83)||#]
[#|2013-08-26 03:44:44,082|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 32)||#]
[#|2013-08-26 03:44:44,082|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 32)||#]
[#|2013-08-26 03:44:44,933|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 14)||#]
[#|2013-08-26 03:44:44,934|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 14)||#]
[#|2013-08-26 03:44:44,949|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 37)||#]
[#|2013-08-26 03:44:44,950|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 37)||#]
[#|2013-08-26 03:44:46,055|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 39)||#]
[#|2013-08-26 03:44:46,056|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 39)||#]
[#|2013-08-26 03:44:46,838|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 61)||#]
[#|2013-08-26 03:44:46,839|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 61)||#]
[#|2013-08-26 03:44:47,039|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 14)||#]

Are they coming from JBoss?

Resolution

The domain.xml/standalone.xml file defines the following FILE Logger Formatter:

<pattern-formatter pattern="[#|%d{YYYY-MM-dd HH:mm:ss,SSS}|%-5p|[%c]|(ThreadId: %t)|%s%E|#]%n"/>

The following describes what will be printed by the formatter:

%d = date & time
%-5p = Severity level (INFO)
%c =  Category of the logging event (stdout)
%t = Thread name (sc-http-executor-threads - 14)
%s = Message (none)
%E = Stacktrace (none)

This matches what is being seen in the server log:

[#|2013-08-26 03:44:44,934|INFO |[stdout]|(ThreadId: sc-http-executor-threads - 14)||#]

These are caused by a empty System.out.println() statement somewhere within the thread. Remove these print calls or provide a meaningful message.

You can use the following ByteMan rule to trigger on the class used by the logmanager to redirect stdout output back into the logging system.

RULE DelegatingPrintStream.println
CLASS org.jboss.stdio.StdioContext$DelegatingPrintStream
METHOD println
AT ENTRY
IF TRUE
DO traceOpen("DelegatingPrintStream", "stdout.txt"); traceStack("", "DelegatingPrintStream")
ENDRULE

RULE DelegatingPrintStream.print
CLASS org.jboss.stdio.StdioContext$DelegatingPrintStream
METHOD print
AT ENTRY
IF TRUE
DO traceOpen("DelegatingPrintStream", "stdout.txt"); traceStack("", "DelegatingPrintStream")
ENDRULE

Root Cause

Empty System.out.print() or System.out.println() statements were being called within the application.

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.

Comments