I came across numerous errors like the one below in our production server's log.
The problem was intermittent and it took quite a while to figure out what caused it.
Original problem intermittently occurred when a servlet logged a bean to stdout.
To simplify our test, let's create the following JSP
<%
System.out.print("xxx {---} {0} xxx"); // looks innocent, isn't it?
%>
Run it on Glassfish or Sun App Server and watch the exception in the server's log file.
[#|2009-07-25T22:40:09.018-0400|WARNING|sun-appserver-ee8.1_02|javax.enterprise.system.stream.err|_ThreadID=21;|
java.lang.IllegalArgumentException: can't parse argument number ---
at java.text.MessageFormat.makeFormat(MessageFormat.java:1330)
at java.text.MessageFormat.applyPattern(MessageFormat.java:450)
at java.text.MessageFormat.<init>(MessageFormat.java:350)
at java.text.MessageFormat.format(MessageFormat.java:803)
at com.sun.enterprise.server.logging.UniformLogFormatter.uniformLogFormat(UniformLogFormatter.java:200)
at com.sun.enterprise.server.logging.UniformLogFormatter.format(UniformLogFormatter.java:114)
at java.util.logging.StreamHandler.publish(StreamHandler.java:179)
at com.sun.enterprise.server.logging.FileandSyslogHandler.publish(FileandSyslogHandler.java:404)
at java.util.logging.Logger.log(Logger.java:452)
at java.util.logging.Logger.doLog(Logger.java:474)
at java.util.logging.Logger.log(Logger.java:497)
at com.sun.enterprise.server.logging.SystemOutandErrHandler$LoggingByteArrayOutputStream.flush(SystemOutandErrHandler.java:198)
at java.io.PrintStream.write(PrintStream.java:414)
at sun.nio.cs.StreamEncoder$CharsetSE.writeBytes(StreamEncoder.java:336)
at sun.nio.cs.StreamEncoder$CharsetSE.implFlushBuffer(StreamEncoder.java:404)
at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:115)
at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:169)
at java.io.PrintStream.write(PrintStream.java:459)
at java.io.PrintStream.print(PrintStream.java:602)
at org.apache.jsp.test_jsp._jspService(test_jsp.java:45)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:105)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:860)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:336)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:301)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:251)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:860)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:249)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAsPrivileged(Subject.java:517)
at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:282)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:165)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:257)
at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:161)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:157)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:263)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:551)
at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:225)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:173)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:551)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:161)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:551)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:933)
at com.sun.enterprise.web.connector.httpservice.HttpServiceProcessor.process(HttpServiceProcessor.java:226)
at com.sun.enterprise.web.HttpServiceWebContainer.service(HttpServiceWebContainer.java:2071)
As you see above, the server intercepts user's stdout message and tries to log it into a file.
The problem is that whenever there is {0} in the stdout, Sun's UniformLogFormatter tries to pass the log message through MessageFormat, which fails on {----} or any other non-integer value within {}.
String "{0}" in our case was produced by toString() method of a List containing a single zero element. When the list contained more or different elements the error disappeared
The question is, why the server does not log a message as is and tries to format it?
So, until this issue is fixed, WATCH WHAT YOU ARE LOGGING.
Just for the record, the problem occurs on the following servers:
Sun Java System Application Server Enterprise Edition 8.1_02 (build b11-fcs)
Sun GlassFish Enterprise Server v2.1 (9.1.1) (build b60e-fcs)
[Message sent by forum member 'anatolitor' (anatolitor)]
http://forums.java.net/jive/thread.jspa?messageID=357590