[
https://issues.apache.org/jira/browse/AVRO-813?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14986073#comment-14986073
]
Greg McNutt commented on AVRO-813:
----------------------------------
I've run into a similar case:
- code that has been running just fine on windows and linux (aws)
implementations for a year
- flipping over to an OSX dev environment and I quite often see these errors on
receipt of a binary encoded response message.
- ONLY when client and server on same mac does this exception show up:
windows <-> windows -- fine
windows client <-> mac server -- fine
mac client <-> windows server -- fine
mac client <-> mac server -- fails around 25 % of the time
This trace shows the capture -- the returned byte stream and the avro portion
look to be ok. Any suggestions? The ensureBounds(10) seems suspect.
---
2015-11-02T13:01:26.208-0800 [pool-1-thread-1] DEBUG httpclient.wire.content,
principal=, sourceAddr=, - <<
"[0x2][0x16]avro.schema[0xb6][0x3]{"type":"record","name":"StoreWireResult","namespace":"com.guidewire.live.dataService.wire","fields":[{"name":"message","type":{"type":"string","avro.java.string":"String"}},{"name":"data","type":"bytes","default":""}]}[0x0][0xbd][0xea][0x81][0x86]C^[0xb2]/9[0xaa][0xea][0x8d][0xd2][0xc7]2[0xbf][0x2]h[0x4]ok`df/b7/3d/20/dfb73d20-b489-4e98-96b9-c428c1b49d48[0xbd][0xea][0x81][0x86]C^[0xb2]/9[0xaa][0xea][0x8d][0xd2][0xc7]2[0xbf]"
2015-11-02T13:12:19.226-0800 [pool-1-thread-1] DEBUG
org.apache.commons.httpclient.HttpMethodBase, principal=, sourceAddr=, - Should
close connection in response to directive: close
2015-11-02T13:12:19.227-0800 [pool-1-thread-1] DEBUG
org.apache.commons.httpclient.HttpConnection, principal=, sourceAddr=, -
Releasing connection back to connection manager.
2015-11-02T13:12:19.227-0800 [pool-1-thread-1] DEBUG
org.apache.commons.httpclient.MultiThreadedHttpConnectionManager, principal=,
sourceAddr=, - Freeing connection,
hostConfig=HostConfiguration[host=http://127.0.0.1:8098]
2015-11-02T13:12:19.227-0800 [pool-1-thread-1] DEBUG
org.apache.commons.httpclient.util.IdleConnectionHandler, principal=,
sourceAddr=, - Adding connection at: 1446498739227
2015-11-02T13:12:19.227-0800 [pool-1-thread-1] DEBUG
org.apache.commons.httpclient.MultiThreadedHttpConnectionManager, principal=,
sourceAddr=, - Notifying no-one, there are no waiting threads
2015-11-02T13:12:19.227-0800 [pool-1-thread-1] WARN
com.guidewire.live.dataService.services.RemoteDataServiceImpl, principal=,
sourceAddr=, - <Remote> url=http://127.0.0.1:8098/data/store, retry=0
com.guidewire.live.dataService.DataServiceException: /data/store
at
com.guidewire.live.dataService.services.RemoteDataServiceImpl.transportOperation(RemoteDataServiceImpl.java:160)
at
com.guidewire.live.dataService.services.RemoteDataServiceImpl.storeWire(RemoteDataServiceImpl.java:84)
at
com.guidewire.live.dataService.services.StoreAsyncService$StoreResultCallable.call(StoreAsyncService.java:267)
at
com.guidewire.live.dataService.services.StoreAsyncService$StoreResultCallable.call(StoreAsyncService.java:236)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:209)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:284)
at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
at
org.apache.commons.httpclient.WireLogInputStream.read(WireLogInputStream.java:69)
at java.io.FilterInputStream.read(FilterInputStream.java:133)
at
org.apache.commons.httpclient.AutoCloseInputStream.read(AutoCloseInputStream.java:108)
at
org.apache.avro.io.BinaryDecoder$InputStreamByteSource.tryReadRaw(BinaryDecoder.java:839)
at
org.apache.avro.io.BinaryDecoder$ByteSource.compactAndFill(BinaryDecoder.java:692)
at org.apache.avro.io.BinaryDecoder.ensureBounds(BinaryDecoder.java:471)
at org.apache.avro.io.BinaryDecoder.readLong(BinaryDecoder.java:160)
at
org.apache.avro.io.BinaryDecoder.doReadItemCount(BinaryDecoder.java:361)
at org.apache.avro.io.BinaryDecoder.readMapStart(BinaryDecoder.java:408)
at
org.apache.avro.file.DataFileStream.initialize(DataFileStream.java:107)
at org.apache.avro.file.DataFileStream.<init>(DataFileStream.java:84)
at
com.guidewire.live.dataService.util.AvroSerde.fileStreamToObject(AvroSerde.java:80)
at
com.guidewire.live.dataService.services.RemoteDataServiceImpl.transportOperation(RemoteDataServiceImpl.java:157)
... 7 more
> EOFException is thrown during normal operation
> ----------------------------------------------
>
> Key: AVRO-813
> URL: https://issues.apache.org/jira/browse/AVRO-813
> Project: Avro
> Issue Type: Bug
> Components: java
> Affects Versions: 1.5.0
> Reporter: Bruno Dumon
> Assignee: Bruno Dumon
> Labels: memex
> Fix For: 1.8.0
>
> Attachments: avro-813-patch.txt
>
>
> In an application that uses Avro as RPC mechanism (with the NettyTransceiver,
> but that's irrelevant), I've noticed in jprofiler that during normal
> operation quite some time was spent creating EOFExceptions:
> {noformat}
> 5.4% - 2,004 ms org.apache.avro.ipc.generic.GenericResponder.readRequest
> 5.0% - 1,871 ms org.apache.avro.generic.GenericDatumReader.read
> 4.9% - 1,832 ms org.apache.avro.generic.GenericDatumReader.read
> 4.9% - 1,832 ms org.apache.avro.generic.GenericDatumReader.readRecord
> 4.5% - 1,670 ms org.apache.avro.generic.GenericDatumReader.read
> 4.5% - 1,670 ms org.apache.avro.generic.GenericDatumReader.readRecord
> 4.3% - 1,596 ms org.apache.avro.generic.GenericDatumReader.read
> 2.8% - 1,048 ms org.apache.avro.generic.GenericDatumReader.readArray
> 1.3% - 477 ms org.apache.avro.io.ValidatingDecoder.arrayNext
> 1.3% - 471 ms org.apache.avro.io.BinaryDecoder.arrayNext
> 1.3% - 466 ms org.apache.avro.io.BinaryDecoder.doReadItemCount
> 1.3% - 466 ms org.apache.avro.io.BinaryDecoder.readLong
> 1.3% - 466 ms org.apache.avro.io.BinaryDecoder.ensureBounds
> 1.3% - 466 ms org.apache.avro.io.BinaryDecoder$ByteSource.compactAndFill
> 1.3% - 466 ms
> org.apache.avro.io.BinaryDecoder$InputStreamByteSource.tryReadRaw
> 1.3% - 466 ms org.apache.avro.util.ByteBufferInputStream.read
> 1.3% - 466 ms org.apache.avro.util.ByteBufferInputStream.getBuffer
> 1.3% - 466 ms java.io.EOFException.<init>
> 1.3% - 466 ms java.io.IOException.<init>
> 1.2% - 460 ms java.lang.Exception.<init>
> 1.2% - 460 ms java.lang.Throwable.<init>
> 1.2% - 460 ms java.lang.Throwable.fillInStackTrace
> {noformat}
> These exceptions are produced by the ByteBufferInputStream (which modifies
> InputStream's contract: return -1 at eof), but are catched higher up by the
> tryReadRaw method.
> What happens is this:
> The message in question has an (empty) array at the end of its message, thus
> the reader tries to read the size of this array in BinaryDecoder.readLong.
> This calls ensureBounds(10), whose contract is that it should read 10 bytes
> if they are available, and otherwise be quiet. ensureBounds calls via
> compactAndFill the tryReadRaw method. It is this method which catches the
> EOFException, because it only 'tries' to read so many bytes.
> Note that InputStreamByteSource.readRaw (without the 'try' part) does itself
> check if read < 0 in order to throw EOFException, making the throwing of
> EOFException in ByteBufferInputStream unnecessary (for this particular usage).
> There was some talk about EOFException in AVRO-392 too, though it seems this
> particular common case was not mentioned there. When using Avro RPC, or more
> in general, when using Avro to read small messages rather than large files,
> it seems like one can very easily run into this EOFException situation, which
> hurts performance.
> I'll attach a patch which simply removes the throwing of EOFException in
> ByteBufferInputStream, but this will likely break other cases which rely on
> the EOFException being thrown (haven't researched this to the bottom).
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
