Telegram: sendTelegramQuery not working after long inactive time

Hi there,
im using the telegram-binding to remind myself that 3 days are gone and i should start cleaning again.

This is the rule:

rule "Esmeralda: Check for cleaning request"
when
Time cron "0 0 9 * * ?"
then
logInfo("VACUUM", "ESMERALDA CHECK FOR CLEANING REQUEST")

// if exactly three days are gone
if (dVac1_last_clean_days.state == 3){

    logInfo("VACUUM", "ESMERALDA ADDING CLEAN REQUEST")

    // Jarvis notification
    val telegramAction = getActions("telegram","telegram:telegramBot:jarvis")
    telegramAction.sendTelegramQuery("<b> &#129529; Soll Esmeralda wischen? &#129529; </b>\n\nDas letzte mal war vor " + dVac1_last_clean_days.state.toString + " Tagen!","oh_esme_sweep","Wischen","Keine Aktion")

    logInfo("VACUUM", "JARVIS NOTIFICATION SENT")

    // Create task
    lDel_Num.sendCommand(-1)
    lTim_Str.sendCommand(lTim_Str.state.toString + String::format( "%1$te.%1$tm.%1$tY", now) + ";")
    lTop_Str.sendCommand(lTop_Str.state.toString + "Esmeralda;")
    lTxt_Str.sendCommand(lTxt_Str.state.toString + "Ich würde gerne wischen, Senhor! Das letzte mal war vor " + dVac1_last_clean_days.state.toString + " Tagen ;")
    lCol_Str.sendCommand(lCol_Str.state.toString + "green;")
    lAct_Str.sendCommand(lAct_Str.state.toString + "command;")
    lActCom_Str.sendCommand(lActCom_Str.state.toString + "sweep;")
    lActItm_Str.sendCommand(lActItm_Str.state.toString + "dVac1_vacuumaction;")
    lActTxt_Str.sendCommand(lActTxt_Str.state.toString + "Wischen beginnen;")
    lIco_Str.sendCommand(lIco_Str.state.toString + "f7:smallcircle_circle;")
    
    logInfo("VACUUM", "ESMERALDA CLEANING REQUEST ADDED TO LOGLIST")
}

end

As you see

  • Each day at 9 am
  • If passed Days is exactly 3
  • A telegram notification shall be sent
  • and “// Create task” does something in my own built task system

If this rule is not executed for a longer time (like e.g. over night), i do NOT get a telegram message and some of the logInfos are missing (see below), BUT the code under “// Create task” is executed

This is what i get from frontail if the telegram message is not sent
You see that everything after Telegram Action seems not to be executed, but the sendCommands under “// Create task” are!

2022-06-01 09:00:00.907 [INFO ] [org.openhab.core.model.script.VACUUM] - ESMERALDA CHECK FOR CLEANING REQUEST
2022-06-01 09:00:00.923 [INFO ] [org.openhab.core.model.script.VACUUM] - ESMERALDA ADDING CLEAN REQUEST

If i then change the rule temporarily (via ssh and VSCode) to execute a few minutes after the current time all of the code gets executed and i get a telegram message with exactly the same code but only changed the cron-time

I assume

  • All of my code should be correct because it can properly be executed some times
  • Only the fact, that there is a long time where i do not use the telegram binding causes an error

Does this make sense?
Does someone know a similar issue?
I have no idea how to further debug this … maybe some of you have a good advice for that

I already opened

What i found,

but did not help so far:
(Maybe because i dont fully understand it)

My System

  • Custom Home Server with TrueNAS-SCALE-Angelfish
  • Dockerized openHAB alpine-latest
runtimeInfo:
  version: 3.2.0
  buildString: Release Build
locale: en-US
systemInfo:
  configFolder: /openhab/conf
  userdataFolder: /openhab/userdata
  logFolder: /openhab/userdata/logs
  javaVersion: 11.0.13
  javaVendor: Alpine
  osName: Linux
  osVersion: 5.10.109+truenas
  osArchitecture: amd64
  availableProcessors: 4
  freeMemory: 306664480
  totalMemory: 468713472
bindings:
  - astro
  - chromecast
  - http
  - ipcamera
  - miio
  - mqtt
  - network
  - ntp
  - openweathermap
  - pushbullet
  - somfytahoma
  - telegram
  - wifiled
clientInfo:
  device:
    ios: false
    android: false
    androidChrome: false
    desktop: true
    iphone: false
    ipod: false
    ipad: false
    edge: false
    ie: false
    firefox: false
    macos: false
    windows: false
    cordova: false
    phonegap: false
    electron: false
    nwjs: false
    webView: false
    webview: false
    standalone: false
    pixelRatio: 1
    prefersColorScheme: dark
  isSecureContext: false
  locationbarVisible: true
  menubarVisible: true
  navigator:
    cookieEnabled: true
    deviceMemory: N/A
    hardwareConcurrency: 8
    language: en-US
    languages:
      - en-US
    onLine: true
    platform: Linux x86_64
  screen:
    width: 3440
    height: 1440
    colorDepth: 24
  support:
    touch: false
    pointerEvents: true
    observer: true
    passiveListener: true
    gestures: false
    intersectionObserver: true
  themeOptions:
    dark: dark
    filled: true
    pageTransitionAnimation: default
    bars: light
    homeNavbar: default
    homeBackground: default
    expandableCardAnimation: default
  userAgent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like
    Gecko) Chrome/91.0.4472.164 Safari/537.36
timestamp: 2022-06-01T08:16:21.466Z

Do you see a SocketTimeoutException?
If yes then the communication to Telegram is the problem.
I used a workaround and added for all my telegram message calls that fail a second call:

    var result = telegramAction.sendTelegram(0000000L, "XYZ")
    if (result == false)
       telegramAction.sendTelegram(0000000L, "XYZ")

But I’m not sure if this is also possible for the sendTelegramQuery call.
However, I still experience some Messages not being sent from time to time. But it was at least improving the situation a bit.
Ideally the binding would realize itself when messages could not be delivered and queue them for some retries later on.

1 Like

I have a similar problem.
I do a telegram binding restart every night with a rule DSL

rule "restart telegram"
when 
Time cron "0 15 4 * * ?"
then 	
var String url = "http://user:password@<openhab-ip>:8080/rest/things/telegram:telegramBot:ThingID/enable" 
sendHttpPutRequest(url, "text/plain", 'enabled', 5000)
Thread::sleep (1000)
sendHttpPutRequest(url, "text/plain", 'true', 5000)
end

Greets
Sebastian

1 Like

Does this restart fix all problems regarding this topic?
Im not sure if the problem appears at a random time or only during the night …

I hope i opened the GitHub Issue at the right place, this would be a chance to find out / fix the core problem

I think that my problem has to do with the 24h disconnect from ISP.
That’s why I run this rule according to the diconnect. Since then I have no more problems.

1 Like

Hmh OK
I will do a little bit of testing and give feedback

Thanks to your help!

I have a similar problem since late 2021, you already linked to the Github issue. I noticed not all of my messages were sent by the OH Telegram binding.

I did some testing. If I send a message every minute, everything arrives. If I send a message hourly, about half of them arrive.

[WARN ] [gram.internal.action.TelegramActions] - Exception occured whilst sending message:java.net.SocketTimeoutException: timeout

Since april 2022 the situation got worse. None of my messages arrive, and I get this error in the logs:

[INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'telegram:telegramBot:Telegram_Bot' changed from OFFLINE (COMMUNICATION_ERROR): java.net.SocketException: Connection reset by peer (Write failed) to OFFLINE (COMMUNICATION_ERROR): java.net.SocketException: Connection reset
2022-06-10 11:15:06.605 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'telegram:telegramBot:Telegram_Bot' changed from OFFLINE (COMMUNICATION_ERROR): java.net.SocketException: Connection reset to OFFLINE (COMMUNICATION_ERROR): java.net.SocketException: Connection reset by peer (Write failed)

I’ve added some items with the network binding to check for error’s, but they all seem fine.

Thing:

network:servicedevice:apitelegram @ "Internet" [ hostname="api.telegram.org", port=80 ]

Items:

Switch         APITelegram_online      "Telegram API online"                     <network>                               {channel="network:servicedevice:apitelegram:online"}
Number:Time    APITelegram_latency     "Telegram API latency"                    <time>                                  {channel="network:servicedevice:apitelegram:latency"}
DateTime       APITelegram_lastseen    "Telegram API lastseen"                   <network>                               {channel="network:servicedevice:apitelegram:lastseen"}

Log confirms the Telegram API is online and reachable:

2022-06-10 11:20:49.417 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'APITelegram_latency' changed from 0 ms to 1 ms
2022-06-10 11:20:49.417 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'APITelegram_lastseen' changed from 2022-06-10T11:19:49.415+0200 to 2022-06-10T11:20:49.417+0200

Even after an OH restart messages fail immediately. Also using the if (result == false) code, but it makes no difference.

Furthermore, I use the Android Telegram app and the Telegram web interface without any issues. So I suspect there is a problem/bug with the OH Telegram binding.

In that case it would help to identify your OH / binding version. In case of a problem/bug with the binding I would expect to see many more of these reports.

That’s a good point.

I have been reading all 3.3.0 release notes, they don’t mention TG. I also checked the commit history from the TG binding, nothing noteworthy has changed. Also can’t find many bug reports related to TG.

Maybe TG changed something on their hand?

Currently I’m running OH 3.3.0M6, binding is the same version.

I would like to try and downgrade the binding to 3.2.0. But I can’t seem to find the jar online. Who knows where I can find it?

1 Like

Have a look at
https://openhab.jfrog.io/ui/native/libs-pullrequest-local/org/openhab/addons/bundles/org.openhab.binding.telegram/

then even more should report about problems as this would be binding version independent.

2 Likes

So today is 3 days after the last try and i got the error again

2022-06-13 09:01:16.432 [WARN ] [gram.internal.action.TelegramActions] - Exception occured whilst sending message:java.net.SocketTimeoutException: timeout

Currently im testing the Solution of @Baschtlwaschtl
I modified minor things like using a token/bearer for the sendHttpPutRequest
I tested it so it should be working to send this HttpPutRequest correctly
→ As mentioned above, this does not fix the problem im my case (i think)

rule "restart telegram"

when 

    Time cron "0 30 2 * * ?"

then 	

    var result = "";

    // var String url = "http://user:password@<openhab-ip>:8080/rest/things/telegram:telegramBot:ThingID/enable" 
    val headers = newHashMap("Authorization" -> "Bearer oh.TelegramServerReset.XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX", "WWW-Authenticate" -> "Basic")
    var String url = "http://XXX.XXX.XXX.XXX:8080/rest/things/telegram:telegramBot:jarvis/enable" 
    
    result = sendHttpPutRequest(url, "text/plain", 'enabled', headers, 5000)
    // logInfo("TELEGRAM", result)
    
    Thread::sleep (1000)
    
    result = sendHttpPutRequest(url, "text/plain", 'true', headers, 5000)
    // logInfo("TELEGRAM", result)

    logInfo("TELEGRAM", "Reset telegram server")

end

Not sure how to proceed …

I’ve resolved my issue. It seems like api.telegram.org was included in a DNSBL in pfBlockerNG on my pfSense firewall.

Still strange that the Telegram bot performance was gradually deteriorating over time, and that the Android + web app are working fine. They probably have other means to connect to TG servers.

1 Like

Thanks @stfn82 for your input

Yes thats feeling ankward also from my side

Today i started another test → Before my code with the command telegramAction.sendTelegramQuery.. i added a line telegramAction.sendTelegram... to send something with sendTelegram (in my case a unicode icon), because i think i did recongize that these problems only occur when using sendTelegramQuery

Because i have other stuff going on and it feels like there could be some connection

Ill give feedback if i learn something new

1 Like

OK after excessive long-term testing the Solution of @Baschtlwaschtl seems to be helpful
But i recognized that the reset of the telegram binding to be around the same time range as the message which shall be sent
So i delayed the telegram reset to ~ 2 Hours before the message shall be sent
If the time in between is too long, it causes problems again because the binding seems “to fall asleep” even if the binding was reset at the beginning of the day

1 Like

I spoke to soon, the original problem I’d had is still there. The firewall issue was just an extra "bonus’.

I sent a hourly message to telegram, usually it only arrives once in 2 hours.

I will also try Baschtlwaschtl solution.