Неожиданный ответ 408 на клиентской стороне кометд

Я использую клиент java cometd. Он был подключен в течение нескольких минут, но через некоторое время он зарегистрировал следующую ошибку. Что мне делать error 408? Должен ли я отключить, завершить, прервать или просто игнорировать вызов Java GC?

java.net.ProtocolException: Неожиданный ответ 408 Ошибка HTTP 408 Тайм-аут запроса

Веб-сервер (на котором запущен веб-сайт) считает, что между

  • установление IP-соединения (сокета) между клиентом (например, вашим веб-браузером или нашим роботом CheckUpDown) и сервером и
  • получение любых данных в этом сокете, поэтому сервер разорвал соединение.

Соединение сокета фактически было потеряно - веб-сервер имеет timed out на этом конкретном соединении сокета. Запрос от клиента должен быть повторен - своевременно.

расширенный клиент Байе

    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);
        }
}

Вот сообщения журнала

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]

java jetty cometd
person rinjan    schedule 22.06.2017    source источник
comment
Где проблема?   -  person ByeBye    schedule 22.06.2017
comment
Я не уверен в каких-либо последствиях из-за такого поведения. Проблема, которую он говорит, является ошибкой протокола. Есть ли что-нибудь (например: отключение, подключение, ...), которое я могу сделать, чтобы исправить ошибку 408. трассировка стека: onProtocolError (BayeuxClient.java:1161   -  person rinjan    schedule 22.06.2017

Ответы (2)


arrow_upward
4
arrow_downward

Как вы видели, это ответ 408 HTTP.

Должен ли я отключить, завершить, прервать или просто игнорировать вызов Java GC?

  • отключить: поскольку время ожидания соединения истекло (2009ms), вам на самом деле не нужно отключаться, так как клиент не смог подключиться к серверу и повторит попытку в соответствии с вашим журналом.
  • Завершить, игнорировать: это действительно зависит от вашей бизнес-логики. Если Вам нужно откатить транзакции и т.д.
  • вызов GC: на самом деле он ничего не делает.

TL.DR.: Решение должно приниматься на основе бизнес-логики, поскольку каждая сеть может дать сбой по-разному.

person Hash    schedule 28.06.2017
comment
Спасибо за ответ. Мы отправляем сообщения с сервера cometd клиенту. Клиент Cometd будет использовать эти сообщения и отправлять электронные письма. Сервер отправляет ответ 408. Это не сбой сети, верно? - person rinjan; 28.06.2017
comment
вызов GC - клиент Commetd инициирует серверные HttpClients. Я думал, что несколько http-клиентов подключены правильно, поэтому они вызывают проблему 408. Я думал, что вызов GC может уничтожить эти экземпляры httpclient. Но это зависит от того, как клиент cometd обрабатывает объекты httpclient. - person rinjan; 28.06.2017
comment
Да https://httpstatuses.com/408 означает, что сервер был недоступен по крайней мере несколько секунд. Это может быть ошибка сети, а также не работающий сервер приложений. Клиент должен обрабатывать свои GC roots, вам не нужно заботиться о них в этом случае, насколько я знаю. - person Hash; 28.06.2017
comment
Спасибо. httpstatuses.com/408 говорит, что если у клиента есть невыполненный запрос в пути, клиент МОЖЕТ повторить этот запрос при новом соединении. Я думаю, что клиент cometd делает это, инициируя новые экземпляры HttpClient (от HttpClient-2120 до 2125 в файле журнала). Это правильно ? - person rinjan; 28.06.2017
comment
Судя по вашему логу так и есть. :) - person Hash; 28.06.2017
comment
Согласно вашему комментарию, кажется, что проблема не имеет никакого эффекта, поэтому нам не нужно исправлять. Есть ли способ перестать регистрировать эти сообщения? Он занимает много места в файле журнала. Я попытался разорвать эти старые соединения (httpclients), вызвав методы разъединения, завершения. Но это не останавливает регистрацию сообщения под тем же идентификатором httpclient. - person rinjan; 28.06.2017
comment
Это отладочные сообщения. Если вы повысите уровень журнала до INFO, он не будет регистрировать такие сообщения. - person Hash; 28.06.2017
comment
спасибо Марк. Извините, что не предоставил код ранее. Мы регистрируем сообщения под информацией и отладкой. Даже на информационном уровне есть много записей журнала. - person rinjan; 28.06.2017
comment
Не могли бы вы принять ответ, если это хороший ответ для вас? :) - person Hash; 11.07.2017

arrow_upward
1
arrow_downward

Я поднял вопрос в гитхабе, где размещен проект. Автор (г-н Симоне Борде) кометы сказал, что я использую очень старую версию кометы. Он попросил меня обновиться до кометда 3.1.2. В настоящее время мы обновляем наше приложение с помощью cometd.

https://github.com/cometd/cometd/issues/730

person rinjan    schedule 05.07.2017