users@jersey.java.net

Issue with JsonXmlStreamWriter swallowing exceptions <was> Re: [Jersey] Recursive error serializing object

From: Paul Sandoz <Paul.Sandoz_at_Sun.COM>
Date: Fri, 23 Oct 2009 20:37:35 +0200

Hi Rod,

What version of Jersey are you using?

What app server are you using?

Would it be possible to send me part of the server.log with about 10
or say iterations of the Exception?

Another developer, Roman CC'ed, recently reported a similar issue with
a repeating exception that keeps repeating itself:

   http://markmail.org/search/?q=list%3Anet.java.dev.jersey.users+ClientAbortException#query
:list%3Anet.java.dev.jersey.users%20ClientAbortException+page:1+mid:3r7fm75bqhjq7vgs+state:results

I am wondering if this may be a strange integration issue with JAXB
and the StAX JSON writer, the code for writeStartElement in the trunk
does the following:

     public void writeStartElement(String prefix, String localName,
String namespaceURI) throws XMLStreamException {
         ...
         try {
            ...
         } catch (IOException ex) {
              
Logger
.getLogger(JsonXmlStreamWriter.class.getName()).log(Level.SEVERE,
null, ex);
         }
     }

it traps an IOException but never re-throws an XMLStreamException.
Thus it is never reported to JAXB and JAXB will continue trying to
write out the document.

This is in general a *very* serious issue. I will log a P1.

I suspect it is the cause of the stack overflow as the state of the
StAX JSON writer probably results in some sort of recursion, which is
possible when JAXB writes characters.

     public void writeCharacters(String text) throws
XMLStreamException {
         if (processingStack.get(depth).isNotEmpty) {
             writeStartElement(null, "$", null);
             writeCharacters(text); / ****** <- recursive call,
does the log include this method?
             writeEndElement();
         } else {
             try {
                 if (isNonString(processingStack.get(depth -
1).currentName)) {
                      
processingStack.get(depth).writer.write(JsonEncoder.encode(text));
                 } else {
                     processingStack.get(depth).writer.write("\"" +
JsonEncoder.encode(text) + "\"");
                 }
                 processingStack.get(depth).lastWasPrimitive = true;
             } catch (IOException ex) {
                  
Logger
.getLogger(JsonXmlStreamWriter.class.getName()).log(Level.SEVERE,
null, ex);
             }
         }
     }


One work around is switch to the natural JSON convention. I checked
the StAX writer for that and it does not have the same issue with
exceptions.

Paul.

On Oct 23, 2009, at 7:34 PM, Rod Fitzsimmons Frey wrote:

> Hi, Gerard. It's a pretty vanilla webservice call to my application
> that
> functions normally most of the time. The size of data returned is
> small
> compared to some calls, and my webservice call is finished by the
> time this
> happens. The return value is
>
> return Response.ok(subList).build();
>
> where subList is a wrapper class holding some data classes plus some
> paging
> information for long lists.
>
> It seems to occur only when a client disconnects while Jersey is
> serializing
> the data out, and even then only sometimes.
>
> -----Original Message-----
> From: gerard davison [mailto:gerard.davison_at_oracle.com]
> Sent: Friday, October 23, 2009 11:09 AM
> To: users_at_jersey.dev.java.net
> Subject: Re: [Jersey] Recursive error serializing object
>
>
> Have your tried capturing the traffic to the server?
>
> Gerard
>
> On 23/10/2009 17:58, Rod Fitzsimmons Frey wrote:
>> I'm having an issue with my webservices that seems related to
>> logging in
>> Jersey, but I'm not sure.
>>
>> Sometimes when a client hangs up in the middle of serializing XML
>> to it,
> my
>> logs will show something like this:
>>
>> Oct 23, 2009 12:34:59 PM
> com.sun.jersey.impl.json.writer.JsonXmlStreamWriter
>> writeStartElement
>> SEVERE: null
>> ClientAbortException: java.io.IOException
>> at
>>
> org
> .apache
> .catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:
>> 358)
>> at
>> org.apache.tomcat.util.buf.ByteChunk.append(ByteChunk.java:325)
>> at
>>
> org
> .apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:
> 381)
>> at
>> org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:
>> 370)
>> at
>>
> org
> .apache
> .catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.ja
>> va:89)
>> at
>>
> com.sun.jersey.spi.container.servlet.ServletContainer
> $Writer.write(ServletCo
>> ntainer.java:249)
>> at
>>
> com.sun.jersey.spi.container.ContainerResponse
> $CommittingOutputStream.write(
>> ContainerResponse.java:115)
>> at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:220)
>> at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:281)
>> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:124)
>> at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:134)
>> at java.io.OutputStreamWriter.write(OutputStreamWriter.java:
>> 220)
>> at java.io.Writer.write(Writer.java:157)
>> at
>>
> com.sun.jersey.impl.json.writer.JsonXmlStreamWriter
> $WriterAdapter.write(Json
>> XmlStreamWriter.java:72)
>> at
>>
> com
> .sun
> .jersey.impl.json.writer.JsonXmlStreamWriter.writeStartElement(JsonXm
>> lStreamWriter.java:398)
>> at
>>
> com
> .sun
> .xml.bind.v2.runtime.output.XMLStreamWriterOutput.beginStartTag(XMLSt
>> reamWriterOutput.java:113)
>> at
>>
> com
> .sun
> .xml.bind.v2.runtime.output.XmlOutputAbstractImpl.beginStartTag(XmlOu
>> tputAbstractImpl.java:98)
>> at
>>
> com.sun.xml.bind.v2.runtime.output.NamespaceContextImpl
> $Element.startElement
>> (NamespaceContextImpl.java:483)
>> at
>>
> com
> .sun
> .xml.bind.v2.runtime.XMLSerializer.endNamespaceDecls(XMLSerializer.ja
>> va:283)
>> at
>>
> com
> .sun
> .xml.bind.v2.runtime.XMLSerializer.childAsXsiType(XMLSerializer.java:
>> 674)
>> at
>>
> com
> .sun
> .xml.bind.v2.runtime.property.SingleElementNodeProperty.serializeBody
>> (SingleElementNodeProperty.java:1
>> 50)
>>
>>
>> (that's about half the stack trace, but you get the idea).
>> That's fine, but what happens is that the stack trace repeats,
>> except with
>> the line
>>
>> at
>>
> com
> .sun
> .jersey.impl.json.writer.JsonXmlStreamWriter.writeStartElement(JsonXm
>> lStreamWriter.java:398)
>> at
>>
> com
> .sun
> .jersey.impl.json.writer.JsonXmlStreamWriter.writeStartElement(JsonXm
>> lStreamWriter.java:398)
>>
>> repeated 2 times. Then again with that line 3 times. Then 4, 5, 6
>> and so
>> on, until I get a stack overflow. By that time the line is
>> repeating many
>> hundreds of times and my log file has ballooned by about 6 GB per
>> occurrence.
>>
>> The app recovers after the stack overflow but while it's occurring it
> slows
>> to a crawl. It takes 3-4 minutes, probably mostly disk write times
>> to the
>> log file.
>>
>> Any insight? My classes are pretty simple, they don't seem to have
>> any
>> circular references that I can find by inspection.
>>
>> Thanks,
>> Rod
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe_at_jersey.dev.java.net
>> For additional commands, e-mail: users-help_at_jersey.dev.java.net
>>
>>
>
> --
> Gerard Davison | Senior Principal Software Engineer | +44 118 924 5095
> Oracle JDeveloper Web Service Tooling Development
> Oracle Corporation UK Ltd is a company incorporated in England &
> Wales.
> Company Reg. No. 1782505.
> Reg. office: Oracle Parkway, Thames Valley Park, Reading RG6 1RA.
>
> Blog http://kingsfleet.blogspot.com
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_jersey.dev.java.net
> For additional commands, e-mail: users-help_at_jersey.dev.java.net
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_jersey.dev.java.net
> For additional commands, e-mail: users-help_at_jersey.dev.java.net
>