Hi!

While smoke-testing Tomcat 7.0.77, I noted an odd behaviour with old
chat servlet example.

I wonder whether this is reproducible.
"Scenario 1" may be a browser bug, as I see it in Firefox, but not in Chrome.

I tested one of scenarios in 7.0.76 and it reproduced there as well
(details below).

Configuration:
==========

I am running Tomcat 7.0.77 with Java 8 (8u121 32-bit, Windows 10).

Default configuration
+ removed AJP connector
+ configured protocol attribute on HTTP connector.
Starting with NIO implementation.

Running without Security manager.

Using Firefox 52.0.2 (64-bit).

Windows 10.

Scenario 1:
==========

1. Start Tomcat.
Start Firefox, open a new window in privacy mode (Ctrl+Shift+P)

2. Open http://localhost:8080/examples/websocket-deprecated/

3. Ctrl+click on "Chat example" link, so that it is opened in
background in a new tab.

Switch to the opened tab.
There is a log pane with the following text.
[[[
Info: WebSocket connection opened.
* Guest1 has joined.
]]]

Send some chat texts (type some in chat box and press enter).
The sent text is echoed
[[[
Guest1: foobar
]]]

Close the tab.

4. Repeat step 3 to open a new tab again.

> Ctrl+click on "Chat example" link, so that it is opened in background in a 
> new tab.
> Switch to the opened tab.

EXPECTED:
"connection opened" and "Guest 2 has joined" text in the log pane.

ACTUAL
There is no text. The log pane is empty.

Further repeats (closing and opening) show the same behaviour (no text).

Restarting Tomcat resets behaviour to Step 3. (First opening - OK,
Second and further - bad).

This is reproducible in 7.0.77 with NIO.
This is reproducible in 7.0.77 with BIO.
This is reproducible in 7.0.76 with NIO.  (Thus it is not new in 7.0.77)

This is not reproducible in 7.0.77 with APR.

With APR there is no difference between first and second subsequent openings:
the "connection opened" and "guest joined" text is always printed,
BUT I see notable delay between opening the tab and appearance of the text:
the delay is about 0,5- 1 second (just less than a heart beat, can
blink eyes twice).

Changing browser to Chrome (incognito mode), 57.0.2987.133 (64-bit)
the problem does not reproduce:
any connector (BIO, NIO, APR) - expected "connection opened", "guest
joined" text appears immediately.

Scenario 2
========
Trying a more simple scenario:
Just open the "chat" example in a tab and refresh it (F5 or Ctrl+F5)
in Firefox:
- NIO & BIO: no issues. "connection opened" and "Guest joined"
messages appear immeadiately
- APR: "connection opened" and "Guest joined" messages appear with the
same 0,5 sec delay as mentioned above.


Scenario 3
=========
1. Start Tomcat. Start Chrome, open new windows in incognito mode (Ctrl+Shif+N).
2. Open two copies of chat example in two browser tabs
http://localhost:8080/examples/websocket-deprecated/chat.html

3. Switch to the second copy (second tab) and press F5 key on keyboard
several times (refreshing the page).
4. Switch to the first copy (fist tab) and look what text is printed
in the log pane. I see:
[[[
Info: WebSocket connection opened.
* Guest1 has joined.
* Guest2 has joined.
* Guest2 has disconnected.
* Guest3 has joined.
* Guest3 has disconnected.
* Guest4 has joined.
* Guest4 has disconnected.
* Guest5 has joined.
* Guest5 has disconnected.
* Guest5 has disconnected.
* Guest5 has disconnected.
* Guest6 has joined.
* Guest6 has disconnected.
* Guest6 has disconnected.
* Guest6 has disconnected.
* Guest7 has joined.
* Guest7 has disconnected.
* Guest8 has joined.
]]]

I do not understand why the same "disconnected" message is repeated 3 times.

This is reproducible with 7.0.77 + any of NIO, BIO, APR.

Using Firefox + NIO/BIO/APR I do not see connection difficulties from
scenario 1,
and I do not see repeated messages.

Scenario 3 + JSR356
=========
Trying this scenario with modern (Websocket spec API) implementation
of chat servlet.
In Chrome:
1. Single reload of second tab results in Guest number increased by 2.
The log pane messages in the first tab are grouped by 2:
[[[
* Guest32 has disconnected.
* Guest33 has disconnected.
* Guest34 has joined.
* Guest35 has joined.
* Guest34 has disconnected.
* Guest35 has disconnected.
* Guest36 has joined.
* Guest37 has joined.
* Guest36 has disconnected.
* Guest37 has disconnected.
* Guest38 has joined.
]]]

2. The are IOException and NullPointerException in Tomcat logs
(catalina.2017-03-31.log)

i18n text "Программа на вашем хост-компьютере разорвала установленное
подключение"
means that "Connection was broken"

[[[
Mar 31, 2017 2:04:42 AM websocket.chat.ChatAnnotation onError
SEVERE: Chat Error: java.io.IOException:
java.util.concurrent.ExecutionException: java.io.IOException:
Программа на вашем хост-компьютере разорвала установленное подключение
java.io.IOException: java.util.concurrent.ExecutionException:
java.io.IOException: Программа на вашем хост-компьютере разорвала
установленное подключение
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:286)
    at 
org.apache.tomcat.websocket.WsSession.sendCloseMessage(WsSession.java:572)
    at org.apache.tomcat.websocket.WsSession.onClose(WsSession.java:495)
    at 
org.apache.tomcat.websocket.WsFrameBase.processDataControl(WsFrameBase.java:348)
    at org.apache.tomcat.websocket.WsFrameBase.processData(WsFrameBase.java:290)
    at 
org.apache.tomcat.websocket.WsFrameBase.processInputBuffer(WsFrameBase.java:131)
    at 
org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:67)
    at 
org.apache.tomcat.websocket.server.WsHttpUpgradeHandler$WsReadListener.onDataAvailable(WsHttpUpgradeHandler.java:204)
    at 
org.apache.coyote.http11.upgrade.AbstractServletInputStream.onDataAvailable(AbstractServletInputStream.java:203)
    at 
org.apache.coyote.http11.upgrade.AbstractProcessor.upgradeDispatch(AbstractProcessor.java:93)
    at 
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:635)
    at 
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1770)
    at 
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1729)
    at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at 
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.util.concurrent.ExecutionException:
java.io.IOException: Программа на вашем хост-компьютере разорвала
установленное подключение
    at 
org.apache.tomcat.websocket.FutureToSendHandler.get(FutureToSendHandler.java:120)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:281)
    ... 16 more
Caused by: java.io.IOException: Программа на вашем хост-компьютере
разорвала установленное подключение
    at sun.nio.ch.SocketDispatcher.write0(Native Method)
    at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:51)
    at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
    at sun.nio.ch.IOUtil.write(IOUtil.java:65)
    at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:492)
    at org.apache.tomcat.util.net.NioChannel.write(NioChannel.java:125)
    at 
org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java:185)
    at 
org.apache.coyote.http11.upgrade.NioServletOutputStream.doWriteInternal(NioServletOutputStream.java:94)
    at 
org.apache.coyote.http11.upgrade.NioServletOutputStream.doWrite(NioServletOutputStream.java:61)
    at 
org.apache.coyote.http11.upgrade.AbstractServletOutputStream.writeInternal(AbstractServletOutputStream.java:153)
    at 
org.apache.coyote.http11.upgrade.AbstractServletOutputStream.write(AbstractServletOutputStream.java:121)
    at 
org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.onWritePossible(WsRemoteEndpointImplServer.java:94)
    at 
org.apache.tomcat.websocket.server.WsRemoteEndpointImplServer.doWrite(WsRemoteEndpointImplServer.java:81)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.writeMessagePart(WsRemoteEndpointImplBase.java:456)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessage(WsRemoteEndpointImplBase.java:344)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessageBlock(WsRemoteEndpointImplBase.java:276)
    ... 16 more

Mar 31, 2017 2:04:42 AM websocket.chat.ChatAnnotation onError
SEVERE: Chat Error: java.lang.NullPointerException: Deflater has been closed
java.lang.NullPointerException: Deflater has been closed
    at java.util.zip.Deflater.ensureOpen(Deflater.java:545)
    at java.util.zip.Deflater.deflate(Deflater.java:426)
    at 
org.apache.tomcat.websocket.PerMessageDeflate.sendMessagePart(PerMessageDeflate.java:345)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.startMessage(WsRemoteEndpointImplBase.java:303)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase$TextMessageSendHandler.write(WsRemoteEndpointImplBase.java:788)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendPartialString(WsRemoteEndpointImplBase.java:252)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendString(WsRemoteEndpointImplBase.java:195)
    at 
org.apache.tomcat.websocket.WsRemoteEndpointBasic.sendText(WsRemoteEndpointBasic.java:37)
    at websocket.chat.ChatAnnotation.broadcast(ChatAnnotation.java:93)
    at websocket.chat.ChatAnnotation.start(ChatAnnotation.java:59)
    at sun.reflect.GeneratedMethodAccessor23.invoke(Unknown Source)
    at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at 
org.apache.tomcat.websocket.pojo.PojoEndpointBase.doOnOpen(PojoEndpointBase.java:66)
    at 
org.apache.tomcat.websocket.pojo.PojoEndpointServer.onOpen(PojoEndpointServer.java:70)
    at 
org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.init(WsHttpUpgradeHandler.java:137)
    at 
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:663)
    at 
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1770)
    at 
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1729)
    at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at 
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)
]]]


Best regards,
Konstantin Kolinko

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org

Reply via email to