rubenlagus / TelegramBots

Java library to create bots using Telegram Bots API
https://telegram.me/JavaBotsApi
MIT License
4.69k stars 1.19k forks source link

Bot stops receiving messages #183

Closed ospavel closed 7 years ago

ospavel commented 7 years ago

Hello!

I have LongPolling-based Telegram bot. It sends messages to users, sometimes receive requests and answer them. This new bot working several days and during this time twice it stops to receive any messages from users. Bot continue send messages, but not receive any. And I did not catch any exception about it in my program, so I don't know about it and can't restart it. After manual restart bot receives all old messages from users.

In System.out log (console) I've found:

Jan, 05, 2017 2:36:38 PM org.telegram.telegrambots.logging.BotLogger severe SEVERE: BOTSESSION java.net.SocketException: Software caused connection abort: recv failed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(Unknown Source) at java.net.SocketInputStream.read(Unknown Source) at java.net.SocketInputStream.read(Unknown Source) at sun.security.ssl.InputRecord.readFully(Unknown Source) at sun.security.ssl.InputRecord.read(Unknown Source) at sun.security.ssl.SSLSocketImpl.readRecord(Unknown Source) at sun.security.ssl.SSLSocketImpl.readDataRecord(Unknown Source) at sun.security.ssl.AppInputStream.read(Unknown Source) at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139) at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:155) at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:165) at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:167) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) at org.telegram.telegrambots.updatesreceivers.DefaultBotSession$ReaderThread.run(DefaultBotSession.java:181)

2017-01-05 14:36:38,730 TRACE [c.t.onUpdateReceived:137] Receive message: /status from user #251 2017-01-05 14:36:38,979 DEBUG [c.t.handleIncomingMessage:165] Status request done 2017-01-05 14:36:38,979 TRACE [c.t.onUpdateReceived:137] Receive message: /status from user #251 2017-01-05 14:36:39,166 DEBUG [c.t.handleIncomingMessage:165] Status request done 2017-01-05 14:36:39,166 TRACE [c.t.onUpdateReceived:137] Receive message: /status from user #251 2017-01-05 14:36:39,343 DEBUG [c.t.handleIncomingMessage:165] Status request done

And no any messages bot receives later.

The code is:

public void onUpdateReceived(Update update) {
    try {
        if (update.hasMessage() && update.getMessage().hasText()) {
            logger.trace("Receive message: {} from user...", update.getMessage().getText());
            handleIncomingMessage(update.getMessage());
        } else if (update.hasCallbackQuery()) {
            logger.trace("Receive query: {} from user...", update.getCallbackQuery().getData());
            handleIncomingQuery(update.getCallbackQuery());
        }
    } catch (Exception e) {
        logger.error("Catch exception", e);
    }
}

Library: telegrambots-2.4.4.3-jar-with-dependencies.jar

On the same computer at the same time I have another Java program with another Telegram bot working with the same scheme, but for me only (it is working several months). It have no such problem all the time.

Where can be the problem? And how I can catch information about such problem to restart the bot?

ospavel commented 7 years ago

By the way, after determining that bot doesn't receive messages, I start it again with startTelegramBot():

private synchronized void startTelegramBot() {
    try {
        if (isTelegramBotRunning())
            stopTelegramBot();
        telegramCommonBot = new TelegramCommonBot();
        TelegramBotsApi telegramBotsApi = new TelegramBotsApi();
        botSession = telegramBotsApi.registerBot(telegramCommonBot);
        logger.info("Common Telegram bot started.");
    } catch (TelegramApiException e) { logger.error("Catch TelegramApiException", e); }
}
private void stopTelegramBot() {
    try {
        if (botSession != null) {
            botSession.stop();
            botSession = null;
        }
    } catch (Exception e) { logger.error("Catch exception", e); }
}
public boolean isTelegramBotRunning() { return botSession != null && botSession.isRunning(); }

and get error in console:

Jan 05, 2017 10:30:20 PM org.apache.http.impl.execchain.RetryExec execute INFO: I/O exception (java.net.SocketException) caught when processing request to {s}->https://api.telegram.org:443: Socket closed Jan 05, 2017 10:30:20 PM org.apache.http.impl.execchain.RetryExec execute INFO: Retrying request to {s}->https://api.telegram.org:443 Jan 05, 2017 10:30:20 PM org.telegram.telegrambots.logging.BotLogger severe SEVERE: BOTSESSION java.lang.IllegalStateException: Connection pool shut down at org.apache.http.util.Asserts.check(Asserts.java:34) at org.apache.http.pool.AbstractConnPool.lease(AbstractConnPool.java:184) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.requestConnection(PoolingHttpClientConnectionManager.java:251) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:175) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) at org.telegram.telegrambots.updatesreceivers.DefaultBotSession$ReaderThread.run(DefaultBotSession.java:181) 2017-01-05 22:30:21,077 INFO Common Telegram bot started.

But bot starts working properly.

rubenlagus commented 7 years ago

Those errors look like a connection error.... not sure. Example: http://stackoverflow.com/questions/135919/java-net-socketexception-software-caused-connection-abort-recv-failed

ospavel commented 7 years ago

Maybe. Any way may be situations of loosing connection. Problem is that bot no longer receive any messages after this. It quietly hangs on receiving. And no information about any exceptions (logged to system out only) was sent to me, so I can't check and restart the bot in time. Is there any approach how I can solve such situations in time?

rubenlagus commented 7 years ago

At the moment, the api is waiting for 0.5 secs after a network issue. I have never experience this kind of error, but I can try to build some kind of Exponential Backoff to in order to reduce the retries.

In any case, I'm still not sure why this error is raising in your system.

ospavel commented 7 years ago

During 3 weeks I didn't get such error anymore. I don't know why it was too...

But I often see in log error 502 from Telegram service:

Jan 26, 2017 12:41:02 PM org.telegram.telegrambots.logging.BotLogger severe
SEVERE: BOTSESSION
org.telegram.telegrambots.exceptions.TelegramApiRequestException: Unable to deserialize response
        at org.telegram.telegrambots.api.methods.updates.GetUpdates.deserializeResponse(GetUpdates.java:122)
        at org.telegram.telegrambots.updatesreceivers.DefaultBotSession$ReaderThread.run(DefaultBotSession.java:186)
Caused by: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', '
false' or 'null')
 at [Source: <html>
<head><title>502 Bad Gateway</title></head>
<body bgcolor="white">
<center><h1>502 Bad Gateway</h1></center>
<hr><center>nginx/1.10.0</center>
</body>
</html>
; line: 1, column: 2]
        at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1702)
        at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:558)
        at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:456)
        at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._handleOddValue(ReaderBasedJsonParser.java:1906)
        at com.fasterxml.jackson.core.json.ReaderBasedJsonParser.nextToken(ReaderBasedJsonParser.java:749)
        at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3834)
        at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3783)
        at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2861)
        at org.telegram.telegrambots.api.methods.updates.GetUpdates.deserializeResponse(GetUpdates.java:114)
        ... 1 more

This message repeats one by one several seconds and fills more that 10000 console lines so I can't find the beginning of it. But in my debug log I see that before this error occur there were no any messages from my bot to telegram. It looks like Telegram service error, I don't know why. My bot working ok, so it is not important for me, but maybe it will be good to correct error 502 parsing.

rubenlagus commented 7 years ago

This kind of error is returned by Telegram system and the parsing problem is because it doesn't contains an actual JSON payload (but HTML one). All I could do is reducing logging level of parsing error so they don't trigger as a SEVERE but maybe as a WARNING or even less.

mansoor035 commented 7 years ago

Hello!

I have LongPolling-based Telegram bot. I receive message form user, do some calculations , and return result to user. when my network disconnects , obviously my telegram bot Stops receiving updates, but when my network resumes still my bot is not receiving any update. what could be the possible cause

j0er9 commented 7 years ago

Hi, I am facing the same problem with a LongPolling bot. Pretty interesting is that my bot also do not receive any new messages but is able to send messages. I use a 2nd long running background thread which use the bot instance and send messages if necessary. So I can say the bot is not dead completely. This might help to analyse....

rubenlagus commented 7 years ago

Next version will bring a few improvements on this topic. Hopefully should be enough

mansoor035 commented 7 years ago

Thank u

On Sat, Feb 25, 2017 at 6:42 PM, Ruben Bermudez notifications@github.com wrote:

Next version will bring a few improvements on this topic. Hopefully should be enough

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/rubenlagus/TelegramBots/issues/183#issuecomment-282483169, or mute the thread https://github.com/notifications/unsubscribe-auth/AYxoZbaxFXwL7CU78RNoDRITVsPG4mD5ks5rgCiugaJpZM4LcJwV .

-- --

Regards

MANSOOR RAJA, JTO (NIB chandigarh), PUNJAB TELECOM CIRCLE Ph No: 9463322009

rubenlagus commented 7 years ago

@ospavel Was this fixed?

mansoor035 commented 7 years ago

yes sir it seems to be working fine

On Wed, Mar 22, 2017 at 3:29 AM, Ruben Bermudez notifications@github.com wrote:

@ospavel https://github.com/ospavel Was this fixed?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/rubenlagus/TelegramBots/issues/183#issuecomment-288232724, or mute the thread https://github.com/notifications/unsubscribe-auth/AYxoZb6-Gd0NPq2MbymrbDkEyRaQisnPks5roEhagaJpZM4LcJwV .

-- --

Regards

MANSOOR RAJA, JTO (NIB chandigarh), PUNJAB TELECOM CIRCLE Ph No: 9463322009

rubenlagus commented 7 years ago

Nice, closing

parsakav commented 6 years ago

Line 57 : try {

        botsApi.registerBot(new MyAmazingBot());
    } 

Error :

Jul 16, 2018 8:58:39 AM org.apache.http.impl.execchain.RetryExec execute INFO: I/O exception (java.net.SocketException) caught when processing request to {s}->https://api.telegram.org:443: Network is unreachable (connect failed) Jul 16, 2018 8:58:39 AM org.apache.http.impl.execchain.RetryExec execute INFO: Retrying request to {s}->https://api.telegram.org:443 Jul 16, 2018 8:58:39 AM org.apache.http.impl.execchain.RetryExec execute INFO: I/O exception (java.net.SocketException) caught when processing request to {s}->https://api.telegram.org:443: Network is unreachable (connect failed) Jul 16, 2018 8:58:39 AM org.apache.http.impl.execchain.RetryExec execute INFO: Retrying request to {s}->https://api.telegram.org:443 Jul 16, 2018 8:58:39 AM org.apache.http.impl.execchain.RetryExec execute INFO: I/O exception (java.net.SocketException) caught when processing request to {s}->https://api.telegram.org:443: Network is unreachable (connect failed) Jul 16, 2018 8:58:39 AM org.apache.http.impl.execchain.RetryExec execute INFO: Retrying request to {s}->https://api.telegram.org:443 Error executing setWebook method org.telegram.telegrambots.exceptions.TelegramApiRequestException: Error executing setWebook method at org.telegram.telegrambots.bots.TelegramLongPollingBot.clearWebhook(TelegramLongPollingBot.java:55) at org.telegram.telegrambots.TelegramBotsApi.registerBot(TelegramBotsApi.java:120) at superGroup.superGroup.Main.main(Main.java:59) Caused by: java.net.SocketException: Network is unreachable (connect failed) at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:589) at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:339) at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:359) at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108) at org.telegram.telegrambots.bots.TelegramLongPollingBot.clearWebhook(TelegramLongPollingBot.java:43) ... 2 more

Whats this error?