Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Websocket: NotUtf8Exception after upgrade 9.4.35 -> 9.4.36 or newer #6050

Closed
stasptr opened this issue Mar 9, 2021 · 8 comments · Fixed by #6056
Closed

Websocket: NotUtf8Exception after upgrade 9.4.35 -> 9.4.36 or newer #6050

stasptr opened this issue Mar 9, 2021 · 8 comments · Fixed by #6056
Assignees
Labels
Bug For general bugs on Jetty side

Comments

@stasptr
Copy link

stasptr commented Mar 9, 2021

Jetty version
9.4.38.v20210224

Java version
OpenJDK "15.0.1"

OS type/version
Linux Ubuntu 20.10

Description

After upgrading jetty from 9.4.35.v20201120 to 9.4.36.v20210114 in our prod env we found a significant amount of NotUtf8Exception exceptions during unpacking text WebSocket messages.
The same problem raised when we tried to upgrade to 9.4.37.v20210219 or 9.4.38.v20210224

Also, we found that disabling permessage-deflate ( with factory.getExtensionFactory().unregister("permessage-deflate") ) is fixing this problem.

I suspect a bug created in #5499 (Significant refactoring of PerMessageDeflate), but we have no scenario to reproduce (except for deploying a heavily loaded production server processing lots of user's documents)

Stacktraces usually have different messages NotUtf8Exception (byte xx in state y, incomplete UTF8 sequence). I suspect the exception is caused by random (possibly of multithreading?) damage of buffer data.

One of StackTrace (v 9.4.38.v20210224):

org.eclipse.jetty.util.Utf8Appendable$NotUtf8Exception: Not valid UTF8! byte 63 in state 2","context":"default","exception":"
org.eclipse.jetty.websocket.api.BadPayloadException: 
org.eclipse.jetty.util.Utf8Appendable$NotUtf8Exception: Not valid UTF8! byte 63 in state 2
at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.incomingFrame(AbstractEventDriver.java:169)
	at org.eclipse.jetty.websocket.common.WebSocketSession.incomingFrame(WebSocketSession.java:326)
	at org.eclipse.jetty.websocket.common.extensions.AbstractExtension.nextIncomingFrame(AbstractExtension.java:148)
	at org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension.nextIncomingFrame(PerMessageDeflateExtension.java:111)
	at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension.forwardIncoming(CompressExtension.java:169)
	at org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension.incomingFrame(PerMessageDeflateExtension.java:90)
	at org.eclipse.jetty.websocket.common.extensions.ExtensionStack.incomingFrame(ExtensionStack.java:202)
	at org.eclipse.jetty.websocket.common.Parser.notifyFrame(Parser.java:225)
	at org.eclipse.jetty.websocket.common.Parser.parseSingleFrame(Parser.java:259)
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:459)
	at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:440)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
	at java.base/java.lang.Thread.run(Thread.java:832)
Caused by: org.eclipse.jetty.util.Utf8Appendable$NotUtf8Exception: Not valid UTF8! byte 63 in state 2
	at org.eclipse.jetty.util.Utf8Appendable.appendByte(Utf8Appendable.java:254)
	at org.eclipse.jetty.util.Utf8Appendable.append(Utf8Appendable.java:169)
	at org.eclipse.jetty.websocket.common.message.SimpleTextMessage.appendFrame(SimpleTextMessage.java:60)
	at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.appendMessage(AbstractEventDriver.java:63)
	at org.eclipse.jetty.websocket.common.events.JettyAnnotatedEventDriver.onTextFrame(JettyAnnotatedEventDriver.java:287)
	at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.incomingFrame(AbstractEventDriver.java:152)
	... 21 common frames omitted"}
@joakime
Copy link
Contributor

joakime commented Mar 9, 2021

This would be very surprising. (we pass all of the industry websocket test tooling for compliance to the spec)
And would seem to be an artifact of a bad WebSocket client (that doesn't implement permessage-deflate properly).

Can you replicate this?
If so, can you capture the traffic on Wireshark and see if it concurs with the BadPayload issue?

@stasptr
Copy link
Author

stasptr commented Mar 9, 2021

Our policy forbids capturing user's data (as it may contain private information).
I'll try to reproduce this issue in test env with test data

Clients use the browser's WebSocket implementation, and there are multiple versions of chrome and firefox (including the latest) in logs with these exceptions, so they are not likely to have a bug in permessage-deflate.

BTW, I see no changes in 9.4.36 changing permessage-deflate algorithm, all changes are in buffering.

@stasptr
Copy link
Author

stasptr commented Mar 9, 2021

native-jetty-websocket-example.zip

Here is modified

https://github.com/jetty-project/embedded-jetty-websocket-examples/tree/master/native-jetty-websocket-example

changes:
version set to: 9.4.36.v2021011

server:
// required for test: buffer < message size
nativeWebSocketConfiguration.getPolicy().setInputBufferSize(16384);

client:

  • turned on permessage-deflate
    ClientUpgradeRequest clientUpgradeRequest = new ClientUpgradeRequest();
    clientUpgradeRequest.addExtensions("permessage-deflate");
  • send random text message of size 30k

Note:
it works with version 9.4.35.v20201120
but fails with 9.4.36.v20210114 or newer

@gregw gregw added the Bug For general bugs on Jetty side label Mar 10, 2021
lachlan-roberts added a commit that referenced this issue Mar 10, 2021
Signed-off-by: Lachlan Roberts <lachlan@webtide.com>
lachlan-roberts added a commit that referenced this issue Mar 11, 2021
Signed-off-by: Lachlan Roberts <lachlan@webtide.com>
@joakime
Copy link
Contributor

joakime commented Mar 11, 2021

Opened PR #6056

@joakime joakime added this to To do in Jetty 9.4.38 via automation Mar 11, 2021
@joakime joakime moved this from To do to In progress in Jetty 9.4.38 Mar 11, 2021
lachlan-roberts added a commit that referenced this issue Mar 17, 2021
Signed-off-by: Lachlan Roberts <lachlan@webtide.com>
lachlan-roberts added a commit that referenced this issue Mar 17, 2021
…ft8Exception

Issue #6050 - fix bug for permessage deflate buffer aggregation
@lachlan-roberts
Copy link
Contributor

This is now fixed with PR #6056.

Jetty 9.4.38 automation moved this from In progress to Done Mar 17, 2021
lachlan-roberts added a commit that referenced this issue Mar 17, 2021
Signed-off-by: Lachlan Roberts <lachlan@webtide.com>
lachlan-roberts added a commit that referenced this issue Mar 17, 2021
Signed-off-by: Lachlan Roberts <lachlan@webtide.com>
lachlan-roberts added a commit that referenced this issue Mar 19, 2021
…Uft8Exception

Issue #6050 - Bring PermessageDeflateBufferTest to Jetty 10.
@gregw gregw removed this from Done in Jetty 9.4.38 Mar 25, 2021
@gregw gregw added this to Done in Jetty 9.4.39 Mar 25, 2021
@moizm89
Copy link

moizm89 commented Jun 7, 2022

Hi @lachlan-roberts,

Getting the same issue in version 10.0.7.
Is this fix ported to 10.0.7?

Thanks

@joakime
Copy link
Contributor

joakime commented Jun 7, 2022

@moizm89 Jetty 10.0.9 is the latest version.

The changes for this issue on Jetty 10 are in commit cc81b30 which shows it's first appearance in Jetty 10.0.2

@joakime
Copy link
Contributor

joakime commented Jun 7, 2022

@moizm89 if you have a reproduction case, please open a new issue against Jetty 10.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug For general bugs on Jetty side
Projects
No open projects
Development

Successfully merging a pull request may close this issue.

5 participants