Search code examples
tomcatjettyjava-websocketjsr356

WebSocket Handshake on Tomcat returns Unexpected Response Code 500


I have a WebSocket application that registers the endpoint programmatically, without the use of Annotations.

The relevant code is:

ServerEndpointConfig.Configurator configurator = 
                (ServerEndpointConfig.Configurator)configuratorClass.newInstance();   
ServerEndpointConfig serverEndpointConfig = ServerEndpointConfig.Builder
                .create(endpointClass, endpointPath)
                .configurator(configurator)
                .build();

ServerContainer serverContainer = (ServerContainer)app
                .getServletContext()
                .getAttribute("javax.websocket.server.ServerContainer");
serverContainer.addEndpoint(serverEndpointConfig);

Everything works fine when I run it inside an IDE with an embedded Jetty container, where the dependency is on tomcat-websocket and tomcat-websocket-api libraries via Maven, but when I deploy it in Tomcat (8.5.5), and then try to establish a WebSocket connection, I get the following error in the browser's console:

WebSocket connection to 'ws://127.0.0.1:8080/echo' failed: Error during WebSocket handshake: Unexpected response code: 500

I do not get any error or other information logged in the Catalina output, and am not sure how to go about debugging this issue.

I need to configure the endpoint programmatically because much of the information is not known at compile time, so please do not point me to an Annotation solution.

I have set the log level to FINE, and this is the relevant snippet:

T.550 FINE [http-nio-IP-Acceptor-0] o.a.tomcat.util.threads.LimitLatch.countUpOrAwait Counting up[http-nio-IP-Acceptor-0] latch=2
T.551 FINE [http-nio-IP-exec-3] o.a.coyote.AbstractProtocol$ConnectionHandler.process Processing socket [o.a.tomcat.util.net.NioChannel@1e87b268:java.nio.channels.SocketChannel[connected local=/192.168.1.17:8080 remote=/192.168.1.17:51259]] with status [OPEN_READ]
T.551 FINE [http-nio-IP-exec-3] o.a.coyote.http11.Http11InputBuffer.parseRequestLine Received [GET /echo HTTP/1.1
Host: 192.168.1.17:8080
Connection: Upgrade
Pragma: no-cache
Cache-Control: no-cache
Upgrade: websocket
Origin: http://192.168.1.17:8080
Sec-WebSocket-Version: 13
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.99 Safari/537.36
Accept-Encoding: gzip, deflate, sdch
Accept-Language: en-US,en;q=0.8
Cookie: LUCEE_ADMIN_LANG=en; cfid=de1b0016-ad0c-4601-b8ce-ecb47771b9c8; cftoken=0; LUCEE_ADMIN_LASTPAGE=debugging.logs
Sec-WebSocket-Key: Ogg0VPp9O3XZlR8rrgz4Gg==
Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits

]
T.553 FINE [http-nio-IP-exec-3] o.a.tomcat.util.http.Rfc6265CookieProcessor.parseCookieHeader Cookies: Parsing b[]: LUCEE_ADMIN_LANG=en; cfid=de1b0016-ad0c-4601-b8ce-ecb47771b9c8; cftoken=0; LUCEE_ADMIN_LASTPAGE=debugging.logs
T.554 FINE [http-nio-IP-exec-3] o.a.catalina.authenticator.AuthenticatorBase.invoke Security checking request GET /echo
T.554 FINE [http-nio-IP-exec-3] o.a.catalina.realm.RealmBase.findSecurityConstraints   No applicable constraints defined
T.554 FINE [http-nio-IP-exec-3] o.a.catalina.authenticator.AuthenticatorBase.invoke  Not subject to any constraint
T.561 FINE [http-nio-IP-exec-3] o.a.tomcat.util.http.Parameters.setEncoding Set encoding to ISO-8859-1
T.563 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass loadClass(o.a.tomcat.util.collections.LocalStrings, false)
T.563 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass   Delegating to parent classloader1 java.net.URLClassLoader@31befd9f
T.563 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass   Searching local repositories
T.563 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.findClass     findClass(o.a.tomcat.util.collections.LocalStrings)
T.564 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.findClass     --> Returning ClassNotFoundException
T.564 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream getResourceAsStream(org/apache/tomcat/util/collections/LocalStrings.properties)
T.564 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   Delegating to parent classloader java.net.URLClassLoader@31befd9f
T.565 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   Searching local repositories
T.565 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   --> Resource not found, returning null
T.566 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass loadClass(o.a.tomcat.util.collections.LocalStrings_en, false)
T.566 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass   Delegating to parent classloader1 java.net.URLClassLoader@31befd9f
T.567 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass   Searching local repositories
T.567 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.findClass     findClass(o.a.tomcat.util.collections.LocalStrings_en)
T.568 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.findClass     --> Returning ClassNotFoundException
T.569 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream getResourceAsStream(org/apache/tomcat/util/collections/LocalStrings_en.properties)
T.569 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   Delegating to parent classloader java.net.URLClassLoader@31befd9f
T.570 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   Searching local repositories
T.571 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   --> Resource not found, returning null
T.571 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass loadClass(o.a.tomcat.util.collections.LocalStrings_en_US, false)
T.571 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass   Delegating to parent classloader1 java.net.URLClassLoader@31befd9f
T.572 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.loadClass   Searching local repositories
T.572 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.findClass     findClass(o.a.tomcat.util.collections.LocalStrings_en_US)
T.573 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.findClass     --> Returning ClassNotFoundException
T.573 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream getResourceAsStream(org/apache/tomcat/util/collections/LocalStrings_en_US.properties)
T.573 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   Delegating to parent classloader java.net.URLClassLoader@31befd9f
T.574 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   Searching local repositories
T.574 FINE [http-nio-IP-exec-3] o.a.catalina.loader.WebappClassLoaderBase.getResourceAsStream   --> Resource not found, returning null
T.581 FINE [http-nio-IP-exec-3] o.a.coyote.AbstractProcessorLight.process Socket: [o.a.tomcat.util.net.NioEndpoint$NioSocketWrapper@6689cfeb:o.a.tomcat.util.net.NioChannel@1e87b268:java.nio.channels.SocketChannel[connected local=/192.168.1.17:8080 remote=/192.168.1.17:51259]], Status in: [OPEN_READ], State out: [CLOSED]
T.582 FINE [http-nio-IP-exec-3] o.a.tomcat.util.threads.LimitLatch.countDown Counting down[http-nio-IP-exec-3] latch=2
T.114 FINE [http-nio-IP-exec-4] o.a.coyote.AbstractProtocol$ConnectionHandler.process Processing socket [o.a.tomcat.util.net.NioChannel@406eaa39:java.nio.channels.SocketChannel[connected local=/192.168.1.17:8080 remote=/192.168.1.17:51254]] with status [ERROR]
T.115 FINE [http-nio-IP-exec-4] o.a.tomcat.util.threads.LimitLatch.countDown Counting down[http-nio-IP-exec-4] latch=1

Solution

  • OK, after much debugging I found that modifyHandshake() threw an NPE which caused this issue.

    I'm surprised that nothing about that was logged even with the log level set to FINE.