[#XFIRE-637] New LocalChanel code records a log error on a SOAP fault

XFire

New LocalChanel code records a log error on a SOAP fault

Created: 11/Sep/06 02:03 PM Updated: 02/Oct/06 10:44 PM

Component/s:

Core

Affects Version/s:

1.2.1

Fix Version/s:

1.2.2

Time Tracking:

Not Specified

Description

« Hide

In one of my handlers I throw a IllegalArgumentException if a SOAP header does not have a valid value. This then causes a SOAP Fault to be returned to the client (dynamic proxy).

When using the new LocalChanel (with a single extra thread) the following exception is returned as the piped stream is no longer open, although the client code does return the error message of the SOAP fault.

org.codehaus.xfire.XFireRuntimeException: Couldn't write stream.. Nested exception is org.codehaus.xfire.fault.XFireFault: Couldn't write message.
org.codehaus.xfire.fault.XFireFault: Couldn't write message.
at org.codehaus.xfire.soap.SoapSerializer.writeMessage(SoapSerializer.java:92)
at org.codehaus.xfire.transport.local.LocalChannel$1.run(LocalChannel.java:149)
at java.lang.Thread.run(Thread.java:534)
Caused by: com.ctc.wstx.exc.WstxIOException: Pipe closed
at com.ctc.wstx.sw.BaseStreamWriter.safeFlushStream(BaseStreamWriter.java:1439)
at com.ctc.wstx.sw.BaseStreamWriter.flush(BaseStreamWriter.java:313)
at org.codehaus.xfire.soap.SoapSerializer.writeMessage(SoapSerializer.java:88)
... 2 more
Caused by: java.io.IOException: Pipe closed
at java.io.PipedInputStream.receive(PipedInputStream.java:136)
at java.io.PipedInputStream.receive(PipedInputStream.java:176)
at java.io.PipedOutputStream.write(PipedOutputStream.java:129)
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$CharsetSE.implFlush(StreamEncoder.java:408)
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:152)
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:213)
at com.ctc.wstx.sw.BaseStreamWriter.flushStream(BaseStreamWriter.java:1430)
at com.ctc.wstx.sw.BaseStreamWriter.safeFlushStream(BaseStreamWriter.java:1437)
... 4 more

I tried using the debugger to get more details but as this is a timing related bug, when you step through the code you don't get the exception in the log

Paul

Description

In one of my handlers I throw a IllegalArgumentException if a SOAP header does not have a valid value. This then causes a SOAP Fault to be returned to the client (dynamic proxy). When using the new LocalChanel (with a single extra thread) the following exception is returned as the piped stream is no longer open, although the client code does return the error message of the SOAP fault. org.codehaus.xfire.XFireRuntimeException: Couldn't write stream.. Nested exception is org.codehaus.xfire.fault.XFireFault: Couldn't write message. org.codehaus.xfire.fault.XFireFault: Couldn't write message. at org.codehaus.xfire.soap.SoapSerializer.writeMessage(SoapSerializer.java:92) at org.codehaus.xfire.transport.local.LocalChannel$1.run(LocalChannel.java:149) at java.lang.Thread.run(Thread.java:534) Caused by: com.ctc.wstx.exc.WstxIOException: Pipe closed at com.ctc.wstx.sw.BaseStreamWriter.safeFlushStream(BaseStreamWriter.java:1439) at com.ctc.wstx.sw.BaseStreamWriter.flush(BaseStreamWriter.java:313) at org.codehaus.xfire.soap.SoapSerializer.writeMessage(SoapSerializer.java:88) ... 2 more Caused by: java.io.IOException: Pipe closed at java.io.PipedInputStream.receive(PipedInputStream.java:136) at java.io.PipedInputStream.receive(PipedInputStream.java:176) at java.io.PipedOutputStream.write(PipedOutputStream.java:129) 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$CharsetSE.implFlush(StreamEncoder.java:408) at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:152) at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:213) at com.ctc.wstx.sw.BaseStreamWriter.flushStream(BaseStreamWriter.java:1430) at com.ctc.wstx.sw.BaseStreamWriter.safeFlushStream(BaseStreamWriter.java:1437) ... 4 more I tried using the debugger to get more details but as this is a timing related bug, when you step through the code you don't get the exception in the log Paul

Show »

All

Comments

Work Log

Change History

Sort Order:

Ascending order - Click to sort in descending order

[ Permlink | « Hide ]

Dan Diephouse - 11/Sep/06 04:51 PM

I take it this worked fine before 1.2.1? I wonder whats going on here....

[ Permlink | « Hide ]

Paul Austin - 11/Sep/06 05:02 PM

Dan,

There is a piped stream between the two, which is being closed in the writer thread and the main, as in this case the fault is being thrown before the full message is read the main thread is exiting and closing the piped stream while the writer thread is still writing the main message out.

(above is a theory).

I think we could resolve this by moving all of the stream/reader/writer closes to be done after the writeThread.join, that way we know we are not using the streams any more.

I think that should solve the issue

Paul

[ Permlink | « Hide ]

Dan Diephouse - 11/Sep/06 05:12 PM

That is a good suggestion. I'll have to look into it...

[ Permlink | « Hide ]

Paul Austin - 15/Sep/06 02:40 PM

Dan,

The following fixes solve the problem.

The first is replacing the exception in the thread with a log statement, the exception just gets caught and dumped to stderr by the thread handler, so we may as well just log it.

The second is making sure that the whole request message was read before closing the stream, this makes sure the write thread does not bail

An alternate option to this fix would be to catch IOExceptions and ignore them but log any other exceptions in the write thread. This would be more efficient as you don't have to wait for the whole message to be written

Index: local/LocalChannel.java
===================================================================
— local/LocalChannel.java (revision 1932)
+++ local/LocalChannel.java (working copy)
@@ -154,7 +154,7 @@
}
catch( Exception e )

{ - throw new XFireRuntimeException( "Couldn't write stream.", e ); + logger.error(e.getMessage(), e); }

}

@@ -170,7 +170,9 @@
inMessage.setEncoding( message.getEncoding() );

channel.receive( receivingContext, inMessage );
-
+ while (reader.hasNext()) { + reader.next(); + }
reader.close();
stream.close();
}

[ Permlink | « Hide ]

Dan Diephouse - 02/Oct/06 10:44 PM

Thanks Paul, your patches and feedback are always helpful! I applied the reader.next() fix to SVN. We probably only have two end tags which we haven't read, so I doubt the performance impact will be much.