Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Unexpected response 408 log in cometd client side

Tags:

java

jetty

cometd

I am using a java cometd client. It was connected for several minutes, but after sometime it logged following error. What I should do on error 408? Should I disconnect, terminate, abort or just ignore, call Java GC?

java.net.ProtocolException: Unexpected response 408 HTTP Error 408 Request timeout

The Web server (running the Web site) thinks that there has been too long an interval of time between

  • the establishment of an IP connection (socket) between the client (e.g. your Web browser or our CheckUpDown robot) and the server and
  • the receipt of any data on that socket, so the server has dropped the connection.

The socket connection has actually been lost - the Web server has timed out on that particular socket connection. The request from the client must be repeated - in a timely manner.

extended BayeuxClient

    public class EventHostClient extends BayeuxClient {
        private final Logger logger = LoggerFactory.getLogger(EventHostClient.class);

        public EventHostClient(String url, ClientTransport transport, ClientTransport... transports) {
            super(url, transport, transports);
        }

        @Override
        public void onFailure(Throwable x, Message[] messages) {
            logger.info("Messages failed "+ x.getMessage());
            logger.debug("Messages failed. Reason : " + Arrays.toString(messages), x);
        }
}

Here is the log messages

2017-06-22 17:59:37.221 [HttpClient-2123] DEBUG c.q.q.n.i.eventhost.EventHostClient - Messages failed. Reason : [{id=4681, connectionType=long-polling, channel=/meta/connect, clientId=btom76smmlh9g4dyq2fkcd61}]
java.net.ProtocolException: Unexpected response 408: TransportExchange@5332249c=POST//10.2.2.250:18080/cometd/connect#CONTENT(0ms)->COMPLETED(0ms)sent=1012ms
    at org.cometd.client.BayeuxClient$PublishTransportListener.onProtocolError(BayeuxClient.java:1161) [cometd-java-client-2.5.0.jar:na]
    at org.cometd.client.transport.LongPollingTransport$TransportExchange.onResponseComplete(LongPollingTransport.java:324) [cometd-java-client-2.5.0.jar:na]
    at org.eclipse.jetty.client.HttpExchange$Listener.onResponseComplete(HttpExchange.java:1158) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.HttpExchange.setStatus(HttpExchange.java:305) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.AbstractHttpConnection$Handler.messageComplete(AbstractHttpConnection.java:337) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:637) [jetty-http-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) [jetty-http-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.AsyncHttpConnection.handle(AsyncHttpConnection.java:133) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:627) [jetty-io-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:51) [jetty-io-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) [jetty-util-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) [jetty-util-7.6.7.v20120910.jar:7.6.7.v20120910]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_67]
2017-06-22 17:59:37.221 [HttpClient-2123] DEBUG c.q.q.n.i.sms.ChannelSubscriber - Recieved connection FAILED | {"message":{"id":"4681","connectionType":"long-polling","channel":"/meta/connect","clientId":"btom76smmlh9g4dyq2fkcd61"},"id":"4681","org.cometd.client.publishCallback":null,"exception":"java.net.ProtocolException: Unexpected response 408: TransportExchange@5332249c=POST//10.2.2.250:18080/cometd/connect#CONTENT(0ms)->COMPLETED(0ms)sent=1012ms","successful":false,"channel":"/meta/connect"} to subscriber id : 1
2017-06-22 17:59:37.221 [pool-513-thread-1] DEBUG c.q.q.n.i.e.E.1264409962 - Connecting, transport org.cometd.client.transport.LongPollingTransport@43e7229c
2017-06-22 17:59:37.221 [pool-513-thread-1] DEBUG c.q.q.n.i.e.E.1264409962 - Sending messages [{id=4683, connectionType=long-polling, channel=/meta/connect, clientId=btom76smmlh9g4dyq2fkcd61}]
2017-06-22 17:59:39.221 [pool-513-thread-1] DEBUG c.q.q.n.i.e.E.1264409962 - Connecting, transport org.cometd.client.transport.LongPollingTransport@43e7229c
2017-06-22 17:59:39.225 [pool-513-thread-1] DEBUG c.q.q.n.i.e.E.1264409962 - Sending messages [{id=4684, connectionType=long-polling, channel=/meta/connect, clientId=btom76smmlh9g4dyq2fkcd61}]
2017-06-22 17:59:39.230 [HttpClient-2123] DEBUG c.q.q.n.i.e.E.1264409962 - State update: CONNECTED -> UNCONNECTED
2017-06-22 17:59:39.230 [HttpClient-2123] INFO  c.q.q.n.i.eventhost.EventHostClient - Messages failed Unexpected response 408: TransportExchange@101a870=POST//10.2.2.250:18080/cometd/connect#CONTENT(0ms)->COMPLETED(0ms)sent=2009ms
2017-06-22 17:59:39.230 [HttpClient-2123] DEBUG c.q.q.n.i.eventhost.EventHostClient - Messages failed. Reason : [{id=4683, connectionType=long-polling, channel=/meta/connect, clientId=btom76smmlh9g4dyq2fkcd61}]
java.net.ProtocolException: Unexpected response 408: TransportExchange@101a870=POST//10.2.2.250:18080/cometd/connect#CONTENT(0ms)->COMPLETED(0ms)sent=2009ms
    at org.cometd.client.BayeuxClient$PublishTransportListener.onProtocolError(BayeuxClient.java:1161) [cometd-java-client-2.5.0.jar:na]
    at org.cometd.client.transport.LongPollingTransport$TransportExchange.onResponseComplete(LongPollingTransport.java:324) [cometd-java-client-2.5.0.jar:na]
    at org.eclipse.jetty.client.HttpExchange$Listener.onResponseComplete(HttpExchange.java:1158) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.HttpExchange.setStatus(HttpExchange.java:305) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.AbstractHttpConnection$Handler.messageComplete(AbstractHttpConnection.java:337) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:637) [jetty-http-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) [jetty-http-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.AsyncHttpConnection.handle(AsyncHttpConnection.java:133) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:627) [jetty-io-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:51) [jetty-io-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) [jetty-util-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) [jetty-util-7.6.7.v20120910.jar:7.6.7.v20120910]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_67]
2017-06-22 17:59:39.230 [HttpClient-2123] DEBUG c.q.q.n.i.sms.ChannelSubscriber - Recieved connection FAILED | {"message":{"id":"4683","connectionType":"long-polling","channel":"/meta/connect","clientId":"btom76smmlh9g4dyq2fkcd61"},"id":"4683","org.cometd.client.publishCallback":null,"exception":"java.net.ProtocolException: Unexpected response 408: TransportExchange@101a870=POST//10.2.2.250:18080/cometd/connect#CONTENT(0ms)->COMPLETED(0ms)sent=2009ms","successful":false,"channel":"/meta/connect"} to subscriber id : 1
2017-06-22 17:59:40.231 [pool-513-thread-1] DEBUG c.q.q.n.i.e.E.1264409962 - Connecting, transport org.cometd.client.transport.LongPollingTransport@43e7229c
2017-06-22 17:59:40.231 [pool-513-thread-1] DEBUG c.q.q.n.i.e.E.1264409962 - Sending messages [{id=4685, connectionType=long-polling, advice={timeout=0}, channel=/meta/connect, clientId=btom76smmlh9g4dyq2fkcd61}]
2017-06-22 17:59:40.236 [HttpClient-2120] DEBUG c.q.q.n.i.e.E.1264409962 - State update: UNCONNECTED -> UNCONNECTED
2017-06-22 17:59:40.236 [HttpClient-2124] DEBUG c.q.q.n.i.e.E.1264409962 - Processing meta connect {id=4685, successful=true, channel=/meta/connect, advice={interval=0, reconnect=retry, timeout=30000}}
2017-06-22 17:59:40.236 [HttpClient-2120] INFO  c.q.q.n.i.eventhost.EventHostClient - Messages failed Unexpected response 408: TransportExchange@13d95194=POST//10.2.2.250:18080/cometd/connect#CONTENT(0ms)->COMPLETED(0ms)sent=1010ms
2017-06-22 17:59:40.236 [HttpClient-2124] DEBUG c.q.q.n.i.e.E.1264409962 - State update: UNCONNECTED -> CONNECTED
2017-06-22 17:59:40.236 [HttpClient-2124] DEBUG c.q.q.n.i.sms.ChannelSubscriber - Recieved connection confirmed | {"id":"4685","successful":true,"channel":"/meta/connect","advice":{"interval":0,"reconnect":"retry","timeout":30000}} to subscriber id : 1
2017-06-22 17:59:40.236 [HttpClient-2120] DEBUG c.q.q.n.i.eventhost.EventHostClient - Messages failed. Reason : [{id=4684, connectionType=long-polling, channel=/meta/connect, clientId=btom76smmlh9g4dyq2fkcd61}]
java.net.ProtocolException: Unexpected response 408: TransportExchange@13d95194=POST//10.2.2.250:18080/cometd/connect#CONTENT(0ms)->COMPLETED(0ms)sent=1010ms
    at org.cometd.client.BayeuxClient$PublishTransportListener.onProtocolError(BayeuxClient.java:1161) [cometd-java-client-2.5.0.jar:na]
    at org.cometd.client.transport.LongPollingTransport$TransportExchange.onResponseComplete(LongPollingTransport.java:324) [cometd-java-client-2.5.0.jar:na]
    at org.eclipse.jetty.client.HttpExchange$Listener.onResponseComplete(HttpExchange.java:1158) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.HttpExchange.setStatus(HttpExchange.java:305) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.AbstractHttpConnection$Handler.messageComplete(AbstractHttpConnection.java:337) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:637) [jetty-http-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) [jetty-http-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.client.AsyncHttpConnection.handle(AsyncHttpConnection.java:133) [jetty-client-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:627) [jetty-io-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:51) [jetty-io-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) [jetty-util-7.6.7.v20120910.jar:7.6.7.v20120910]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) [jetty-util-7.6.7.v20120910.jar:7.6.7.v20120910]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_67]
like image 505
rinjan Avatar asked Jun 22 '17 13:06

rinjan


1 Answers

As you have seen it is a 408 HTTP response.

Should I disconnect, terminate, abort or just ignore, call Java GC?

  • disconnect: As the connection is timed out (2009ms) you do not really need to disconnect as the client failed your connection to the server and it will retry according to your log.
  • terminate, ignore: It really depends on your business logic. If You need to roll back transactions etc.
  • call GC: It does not really do anything.

TL.DR.: The decision should be made based on the business logic as every network could fail in various ways.

like image 121
Hash Avatar answered Sep 28 '22 03:09

Hash