hi,

Reviving an old thread here. We continue to see the same failures
periodically (e.g. 2 of 10 times) on the CI server only, never locally.

In response to Joakim's comment below that "an extra frame arrived after
the supposed last frame of the last message" based on actual logging I'm
wondering if there couldn't be a potential concurrency issue?

See for example these two log statements that correspond to two WebSocket
messages in the same session (the only session in the test) processed at
nearly (and possibly) the same time in two different threads:

06:43:13,160 [WebSocketClient@1545468091-533] - Processing SockJS open
frame in WebSocketClientSockJsSession[id='b61c4e070bc4e81c83801f2fbe6a27e2,
url=http://localhost:53793/test]
...
06:43:13,161 [WebSocketClient@1545468091-536] - Unhandled Error (closing
connection)
java.io.IOException: Cannot append to finished buffer
        at
org.eclipse.jetty.websocket.common.message.SimpleTextMessage.appendFrame(SimpleTextMessage.java:47)
        at
org.eclipse.jetty.websocket.common.events.AbstractEventDriver.appendMessage(AbstractEventDriver.java:60)
        at
org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onTextFrame(JettyAnnotatedEventDriver.java:201)
        at
org.eclipse.jetty.websocket.common.events.AbstractEventDriver.incomingFrame(AbstractEventDriver.java:160)
        at
org.eclipse.jetty.websocket.common.WebSocketSession.incomingFrame(WebSocketSession.java:309)
        at
org.eclipse.jetty.websocket.common.extensions.ExtensionStack.incomingFrame(ExtensionStack.java:214)
        at
org.eclipse.jetty.websocket.common.Parser.notifyFrame(Parser.java:220)
        at org.eclipse.jetty.websocket.common.Parser.parse(Parser.java:258)
        at
org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.readParse(AbstractWebSocketConnection.java:613)
        at
org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:468)
        at
org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
        at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:626)
        at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:546)
        at java.lang.Thread.run(Thread.java:745)

One another example with a different error message but in the same part of
the code:

17:33:30,200 [WebSocketClient@588756412-539] - Processing SockJS open frame
in WebSocketClientSockJsSession[id='64344caa5fa655c02bd54982011f31be, url=
http://localhost:4113/test]
...
17:33:30,201 [WebSocketClient@588756412-538] - Unhandled Error (closing
connection)
java.io.IOException: Out of order Continuation frame encountered
        at
org.eclipse.jetty.websocket.common.events.AbstractEventDriver.onContinuationFrame(AbstractEventDriver.java:194)
        at
org.eclipse.jetty.websocket.common.events.AbstractEventDriver.incomingFrame(AbstractEventDriver.java:165)
        at
org.eclipse.jetty.websocket.common.WebSocketSession.incomingFrame(WebSocketSession.java:309)
        at
org.eclipse.jetty.websocket.common.extensions.ExtensionStack.incomingFrame(ExtensionStack.java:214)
        at
org.eclipse.jetty.websocket.common.Parser.notifyFrame(Parser.java:220)
        at org.eclipse.jetty.websocket.common.Parser.parse(Parser.java:258)
        at
org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.readParse(AbstractWebSocketConnection.java:613)
        at
org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:468)
        at
org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
        at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:626)
        at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:546)
        at java.lang.Thread.run(Thread.java:745)

Is it possible that under some circumstances on the client side, two
incoming WebSocket messages of the same session may not be processed
sequentially? The QueuedThreadPool from the stack trace runs in a loop but
the log messages are from different threads.

Any idea what else could possibly lead to the above errors? Also for what
it's worth, the same tests parameterized to run with another WebSocket
client do not have these failures.

Thanks,
Rossen

On Wed, Jul 2, 2014 at 4:42 PM, Joakim Erdfelt <[email protected]> wrote:

> What features of websocket are you using?
> Interested in all features you use, client and server side.
> Some features: binary and/or text messages, auto fragmentation,
> compression extensions, streaming, jsr-356 decoders/encoders, jsr-356
> messagehandlers, etc ...
>
>
> --
> Joakim Erdfelt <[email protected]>
> webtide.com <http://www.webtide.com/> - intalio.com/jetty
> Expert advice, services and support from from the Jetty & CometD experts
> eclipse.org/jetty - cometd.org
>
>
> On Wed, Jul 2, 2014 at 12:50 PM, Rossen Stoyanchev <
> [email protected]> wrote:
>
>> Unfortunately I cannot reproduce it reliably. It's hard with concurrency
>> issues like that.
>>
>> I was hoping the stack trace might lead to some thoughts about what may
>> be going on. Is there anything I could be doing incorrectly to lead to this
>> exception? If not any other theories based on the stack trace? I could try
>> to introduce a delay somewhere even in the Jetty code to get it to occur
>> but could use some help to narrow it down.
>>
>> Rosen
>>
>>
>> On Wed, Jul 2, 2014 at 3:27 PM, Joakim Erdfelt <[email protected]>
>> wrote:
>>
>>> If you have a reproducible testcase we'd like to see it.
>>> The exception is saying that the there was an extra frame (for a text
>>> message) that arrived after the supposed last frame of that same message.
>>>
>>> --
>>> Joakim Erdfelt <[email protected]>
>>> webtide.com <http://www.webtide.com/> - intalio.com/jetty
>>> Expert advice, services and support from from the Jetty & CometD experts
>>> eclipse.org/jetty - cometd.org
>>>
>>>
>>> On Wed, Jul 2, 2014 at 11:40 AM, Rossen Stoyanchev <
>>> [email protected]> wrote:
>>>
>>>> hi-
>>>>
>>>> I have a simple unit test in which a Jetty WebSocketClient connects to
>>>> a Jetty server and sends 100 messages in a loop that the server then echoes
>>>> back. When all messages are received in the client, the test is complete.
>>>> This runs okay most of the times except occasionally on our CI server there
>>>> is a client-side failure after 40-50 messages that looks like this:
>>>>
>>>> java.io.IOException: Cannot append to finished buffer
>>>>         at
>>>> org.eclipse.jetty.websocket.common.message.SimpleTextMessage.appendFrame(SimpleTextMessage.java:47)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.events.AbstractEventDriver.appendMessage(AbstractEventDriver.java:60)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onTextFrame(JettyAnnotatedEventDriver.java:201)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.events.AbstractEventDriver.incomingFrame(AbstractEventDriver.java:160)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.WebSocketSession.incomingFrame(WebSocketSession.java:302)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.extensions.ExtensionStack.incomingFrame(ExtensionStack.java:215)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.Parser.notifyFrame(Parser.java:220)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.Parser.parse(Parser.java:258)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.readParse(AbstractWebSocketConnection.java:602)
>>>>         at
>>>> org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:458)
>>>>         at
>>>> org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:534)
>>>>         at
>>>> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:607)
>>>>         at
>>>> org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:536)
>>>>         at java.lang.Thread.run(Thread.java:745)
>>>>
>>>> From what I can see all server messages are processed sequentially
>>>> (always the same Jetty thread) while client side messages are received in
>>>> different threads. It is possible there is an issue with concurrency in the
>>>> client?
>>>>
>>>> Rossen
>>>>
>>>>
>>>>
>>>> _______________________________________________
>>>> jetty-users mailing list
>>>> [email protected]
>>>> To change your delivery options, retrieve your password, or unsubscribe
>>>> from this list, visit
>>>> https://dev.eclipse.org/mailman/listinfo/jetty-users
>>>>
>>>
>>>
>>> _______________________________________________
>>> jetty-users mailing list
>>> [email protected]
>>> To change your delivery options, retrieve your password, or unsubscribe
>>> from this list, visit
>>> https://dev.eclipse.org/mailman/listinfo/jetty-users
>>>
>>
>>
>> _______________________________________________
>> jetty-users mailing list
>> [email protected]
>> To change your delivery options, retrieve your password, or unsubscribe
>> from this list, visit
>> https://dev.eclipse.org/mailman/listinfo/jetty-users
>>
>
>
> _______________________________________________
> jetty-users mailing list
> [email protected]
> To change your delivery options, retrieve your password, or unsubscribe
> from this list, visit
> https://dev.eclipse.org/mailman/listinfo/jetty-users
>
_______________________________________________
jetty-users mailing list
[email protected]
To change your delivery options, retrieve your password, or unsubscribe from 
this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-users

Reply via email to