pengrad / java-telegram-bot-api

Telegram Bot API for Java
https://core.telegram.org/bots
Apache License 2.0
1.79k stars 372 forks source link

Log spam on getUpdates when BOT token is wrong / revoked #168

Closed mircoianese closed 5 years ago

mircoianese commented 5 years ago

Hello, with the latest version (4.3.0) i'm experiencing loops caused by wrong tokens on my BOTS. I have a BOT where users can configure their own BOT, so they enter their own token, and if they revoke the token I start getting a huge spam in logs:

INFO: Update listener error for request {"method":"getUpdates"} with response 401 Unauthorized
Jun 13, 2019 8:41:56 PM okhttp3.internal.platform.Platform log
INFO: Update listener error for request {"method":"getUpdates"} with response 401 Unauthorized
Jun 13, 2019 8:41:56 PM okhttp3.internal.platform.Platform log
INFO: Update listener error for request {"method":"getUpdates"} with response 401 Unauthorized
Jun 13, 2019 8:41:57 PM okhttp3.internal.platform.Platform log
INFO: Update listener error for request {"method":"getUpdates"} with response 401 Unauthorized

As you can see I get about 4 per second, so it's like it's looping. Is there any way to intercept this and kill the update listener?

Thanks a lot!

pengrad commented 5 years ago

Thanks for reporting! We discussed it here #161, but I just added exceptions logging after that.

I added error handler in new branch. You can try to use it adding dependency via JitPack https://jitpack.io/#pengrad/java-telegram-bot-api/error-handler-SNAPSHOT

allprojects {
    repositories {
        ...
        maven { url 'https://jitpack.io' }
    }
}

dependencies {
        implementation 'com.github.pengrad:java-telegram-bot-api:error-handler-SNAPSHOT'
}

It's absolutely same 4.3.0 version but you can handle update errors passing 2nd lambda (ErrorHandler) to setUpdatesListener like this:

bot.setUpdatesListener(updates -> {
    processUpdates(updates);
    return UpdatesListener.CONFIRMED_UPDATES_ALL;
}, (response, exception) -> {
    if (response != null) {
        System.out.println("bad response: " + response.errorCode() + " : " + response.description());
        // can check that errorCode is 401
        if (response.errorCode() == 401) {
            bot.removeGetUpdatesListener();
        }
    } else {
        exception.printStackTrace();
    }
});
mircoianese commented 5 years ago

Hello, thanks a lot! I will test it this weekend and report back! :)

pengrad commented 5 years ago

Released in 4.3.1 New usage is:

bot.setUpdatesListener(updates -> {
    // process updates
    return UpdatesListener.CONFIRMED_UPDATES_ALL;
}, e -> {
    if (e.response() != null) {
        // god bad response from telegram 
        e.response().errorCode();
        e.response().description();
    } else {
        // probably network error
        e.printStackTrace();
    }
});
mircoianese commented 5 years ago

I confirm it's working fine for me, thanks!

mircoianese commented 5 years ago

Hello. Recently I'm having some issues where for some unknown reason updateListener stops running. I should have try-catch everywhere but I can't debug this. I have an app with 100+ BOTs running and some of them just stops responding. A total reboot of the app solves the issue. Do you have an idea what the cause could be? Maybe is something in my code, but do you have any advice where I should look, also based on recent changes on updateListener behaviour

Thanks!

pengrad commented 5 years ago

Hi, yes there was one change that probably could affect this. Now exceptions in update listener (user's code) aren't caught and terminate update handler. If you can check logs of that bots - there should be errors like this Exception in thread "OkHttp Dispatcher"

I'm now sure how to handle it better, this "bad" update that cause exception will be redelivered next time if library will catch it, so there will be endless exceptions.

Right now the best way is to find and fix it in code. But I will come up with the way of skipping such bad updates.

To make sure that it's really client's code error - I pushed branch where exceptions in update listener are handled by errorHandler. Please try on this dep via JitPack

dependencies {
    implementation 'com.github.pengrad:java-telegram-bot-api:catch-updates-error-SNAPSHOT'
}

To catch exception you need to pass 2nd lambda as here https://github.com/pengrad/java-telegram-bot-api/issues/168#issuecomment-503455398 or it will be logged, bot should continue to work anyway.

mircoianese commented 5 years ago

Hello @pengrad !

Thanks for the answer! After doing some tests I went back to version 4.3.1 because I was still getting issues even on your catch-updates-error-SNAPSHOT.

I was finally able to see the exceptions I get in console when an update listener dies, and this is the exception:

2019-06-28 16 21 39

So, it looks like that my problems are caused by some sort of timeout. I noticed that not all BOT dies when this happens, but I think almost half the BOTs die at the same moment (infact I get a lot of exceptions at once).

This is the code I currently use to create the HttpClient. Any adivice on how to catch that exception and keep the UpdateListener running?

            BOT=new TelegramBot.Builder(BOT_TOKEN)
                .okHttpClient(new OkHttpClient.Builder()
                    .readTimeout(10, TimeUnit.SECONDS)
                    .writeTimeout(10, TimeUnit.SECONDS)
                    .connectTimeout(10, TimeUnit.SECONDS)
                    .addInterceptor(chain -> {
                        try{       
                            Request request = chain.request();
                            Response response = chain.proceed(request);                     
                            int tryCount = 0;
                            while (!response.isSuccessful() && tryCount < 5) {
                                if(response.code()>=400 || response.code()<500) {
                                    return response;
                                }
                                tryCount++;
                                LOGGER.writeLog("Failed Telegram Request... retrying " + tryCount + "/5");
                                //LOGGER.writeLog("request: " + request.url());
                                //LOGGER.writeLog("code " + response.code() + ": " + response.message());
                                    response = chain.proceed(request);
                            }
                            return response;
                        }catch(Exception e) {}
                        return null;
                    })
                    .build())
                .build();

Thanks!

pengrad commented 5 years ago

Ok, I can't fully reproduce it but at least i can make update listener to die now with your custom OkHttpClient.

Timeout is not a problem, it can happens on network requests. The problem is in OkHttp interceptor where you catch this timeout exception catch(Exception e) {} and return null response. In my case null response is a problem. You need to remove try-catch block - this will make normal exceptions handling - update handler will catch it in onFailed callback and repeat request.

Actually this interceptor doesn't work as intended. Because this line if(response.code()>=400 || response.code()<500) is always true - any code is always >400 or <500. So it always returns 1st response and tryCount isn't really used. I suggest to remove interceptor completely. If you want to keep it or fix - then you need to remove only try-catch block.

Btw, there are default timeouts on default OkHttpClient https://github.com/pengrad/java-telegram-bot-api/blob/master/library/src/main/java/com/pengrad/telegrambot/TelegramBot.java#L139 So maybe you don't need custom OkHttpClient also.

Please try and inform has it fixed your problem or not.

mircoianese commented 5 years ago

Hello @pengrad ,

Thanks a lot, really! This seems to have solved my issue (I removed the interceptor). I left my timeouts because I have a question: 75 Seconds timeout on default timeout is not too much? If not, why?

Thank you again!

pengrad commented 5 years ago

I had timeouts errors on 10sec value. Don't remember where exactly I found 75sec, seems in some other telegram lib

mircoianese commented 5 years ago

Hello @pengrad

I just had some more timeouts that made the Listener to Fail with INFO: Update Listener Failed. I got some java.net.UnknownHostException: api.telegram.org

Unfortunately I do not have logs, but why this was not catch into the Error Handler?

My Error Handler is:

                try{
                    if (e.response() != null) {
                        BOT.log().writeLog("bad response: " + e.response().errorCode() + " : " + e.response().description());
                        // can check that errorCode is 401
                        if(e.response().errorCode() == 401) {
                            if(BOT.vars().TELEGRAM_FAILS > 5) {
                                BOT.bot().removeGetUpdatesListener();
                            }
                            BOT.vars().TELEGRAM_FAILS++;
                            return;
                        }else if(e.response().errorCode() == 409) {
                            LoadBOT.deleteWebhook(BOT);
                            return;
                        }
                    }else{
                        e.printStackTrace();
                    }
                }catch(Exception a) {
                    a.printStackTrace();
                }

Thanks

pengrad commented 5 years ago

Are you on catch-updates-error branch?

mircoianese commented 5 years ago

No, I'm on 4.3.1. Shall I update?