Telegrambot Probleme - Nichts verändert, trotzdem Störung

Stargazer · 28 April 2017, 09:33:07

Hallo zusammen,

in den letzten Tagen habe ich erfolgreich meinen Telegrambot in Betrieb genommen. Alles lief gut.
Bis heute Morgen. Ich hatte heute Morgen noch 3 Befehle abgesetzt, die auch alle beantwortet wurden. 1 Minute später wollte ich noch einen Befehl absetzen. Doch seit dem bekomme ich vom Bot keine Antwort mehr. Auch vom Bot direkt kann ich keine Nachricht aufs Handy schicken.

Als PollingError erhalte ich folgende Meldung:

Callback returned no valid JSON: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "\r\n

Ich hatte da schon nach gesucht, aber nicht allzu schlüssiges gefunden. Oder ist deren Server überlastet ?
Hat da noch jemand Erfahrung mit gemacht ?

VG und besten Dank

André

viegener · 28 April 2017, 16:24:59

VObn serverüberlastung kann ich bei mir nichts erkennen. Wenn das Problem nicht gelöst ist, stelle bitte verbose auf 5, mache bitte ein List von Deinem Device und führe dann einen "set <bot> reset" aus. Dazu würde mich dann der Ausschnitt aus dem FHEM-Log interessieren, dann kann ich vielleicht mehr sagen.

Stargazer · 28 April 2017, 18:16:10

Hi,

habe das mal alles gemacht.

Hier schon einmal das List vom Device:

Code Auswählen

Internals: 
   FAILS      0 
   NAME       FHEM32584Bot 
   NR         357 
   OLDFAILS   267 
   OLD_POLLING 13 
   POLLING    0 
   SNAME      FHEM32584Bot 
   STATE      Polling 
   TYPE       TelegramBot 
   UPDATER    0 
   WAIT       0 
   me         Failed - see log file for details 
   sentLastResult Callback returned no valid JSON: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "<html>\r\n<head><tit...") at ./FHEM/50_TelegramBot.pm line 1986. 

   sentMsgId 
   sentMsgPeer Andre_XXXXXXXX
   sentMsgPeerId 3XXXXXXXXXX
   sentMsgText Test 
   Contacts: 
     3XXXXXXXXX  3XXXXXXXXX:Andre_XXXXXXX:@StarXXXXXXXXX
   Hu_do_params: 
     NAME 
     addr       https://api.telegram.org:443 
     boundary   TelegramBot_boundary-x0123 
     buf 
     code       400 
     data 
     displayurl <hidden> 
     header     agent: TelegramBot/1.0
 
User-Agent: TelegramBot/1.0
 
Accept: application/json
 
Accept-Charset: utf-8
 
Content-Type: multipart/form-data; boundary=TelegramBot_boundary-x0123 
     hideurl    1 
     host       api.telegram.org 
     httpheader HTTP/1.1 400 Bad Request
 
Server: nginx/1.10.0
 
Date: Fri, 28 Apr 2017 16:03:45 GMT
 
Content-Type: text/html
 
Content-Length: 173
 
Connection: close
 
Access-Control-Allow-Origin: *
 
Access-Control-Expose-Headers: Content-Length,Content-Type,Date,Server,Connection 
     loglevel   4 
     method     POST 
     path       /bot1e1mj42o6:1c20";7Dk=c$itFM9-lcS"A&<c/sendMessage 
     protocol   https 
     redirects  0 
     timeout    30 
     url        https://api.telegram.org/bot1e1mj42o6:1c20";7Dk=c$itFM9-lcS"A&<c/sendMessage 
     args: 
       @StarXXXXXXXXXX
       Test 
       undef 
       0 
       undef 
       1 
     Hash: 
     Sslargs: 
   Hu_upd_params: 
     NAME 
     addr       https://api.telegram.org:443 
     buf 
     code       400 
     conn 
     displayurl <hidden> 
     header     agent: TelegramBot/1.0
 
User-Agent: TelegramBot/1.0
 
Accept: application/json
 
Accept-Charset: utf-8 
     hideurl    1 
     host       api.telegram.org 
     httpheader HTTP/1.1 400 Bad Request
 
Server: nginx/1.10.0
 
Date: Fri, 28 Apr 2017 16:06:10 GMT
 
Content-Type: text/html
 
Content-Length: 173
 
Connection: close
 
Access-Control-Allow-Origin: *
 
Access-Control-Expose-Headers: Content-Length,Content-Type,Date,Server,Connection 
     hu_blocking 0 
     hu_filecount 1 
     hu_portSfx 
     isPolling  update 
     loglevel   4 
     method     GET 
     offset     0 
     path       /bot1e1mj42o6:1c20";7Dk=c$itFM9-lcS"A&<c/getUpdates?offset=0&limit=5&timeout=60 
     protocol   https 
     redirects  0 
     timeout    125 
     url        https://api.telegram.org/bot1e1mj42o6:1c20";7Dk=c$itFM9-lcS"A&<c/getUpdates?offset=0&limit=5&timeout=60 
     Hash: 
     Sslargs: 
   Readings: 
     2017-04-26 08:36:18   Contacts        3XXXXXXXX:Andre_XXXXXX:@StarXXXXXXXX
     2017-04-28 18:06:10   PollingErrCount 358 
     2017-04-28 18:06:10   PollingLastError Callback returned no valid JSON: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "<html>\r\n<head><tit...") at ./FHEM/50_TelegramBot.pm line 1986. 

     2017-04-26 19:51:23   StoredCommands  FHEM set Badheizer on 
FHEM set Badsteckdose on 
FHEM set Badsteckdose_Taster on 
FHEM Barometer 
FHEM Telegram 
FHEM Verbrauch 
FHEM set Badsteckdose_Taster off 

     2017-04-28 07:08:36   msgChat         Andre_XXXXXX
     2017-04-28 07:08:36   msgChatId       3XXXXXXXXX
     2017-04-28 07:08:36   msgFileId 
     2017-04-28 07:08:36   msgId           474 
     2017-04-28 07:08:36   msgPeer         Andre_XXXXXXX
     2017-04-28 07:08:36   msgPeerId       3XXXXXXXX
     2017-04-28 07:08:36   msgReplyMsgId 
     2017-04-28 07:08:36   msgText         Wetter 
     2017-04-28 07:08:36   prevMsgChat     Andre_XXXXXXX
     2017-04-28 07:08:36   prevMsgFileId 
     2017-04-28 07:08:36   prevMsgId       471 
     2017-04-28 07:08:36   prevMsgPeer     Andre_XXXXXXX
     2017-04-28 07:08:36   prevMsgPeerId   3XXXXXXXX
     2017-04-28 07:08:36   prevMsgReplyMsgId 
     2017-04-28 07:08:36   prevMsgText     Astro 
     2017-04-28 18:03:45   sentMsgId 
     2017-04-28 18:03:45   sentMsgPeerId   3XXXXXXXX
     2017-04-28 18:03:45   sentMsgResult   Callback returned no valid JSON: malformed JSON string, neither tag, array, object, number, string or atom, at character offset 0 (before "<html>\r\n<head><tit...") at ./FHEM/50_TelegramBot.pm line 1986. 

Attributes: 
   allowUnknownContacts 0 
   cmdKeyword FHEM 
   cmdRestrictedPeer 3XXXXX 
   defaultPeer @StargXXXXX
   pollingTimeout 60 
   room       FHEMBot 
   verbose    5

Ich habe gerade versucht, das Log aufzurufen. Doch wird das in Monaten angelegt und ist derzeit schon recht voll.
Irgendwie kommt er bis zum 18.4. und dann lädt er nicht mehr nach.

VG

André

viegener · 28 April 2017, 18:44:55

Kannst Du noch etwas versenden? --> also einfach ein

Code Auswählen

set FHEM32584Bot msg test

Stargazer · 28 April 2017, 19:26:24

Hi,

nein, das geht leider auch nicht. Als MsgResult schreibt er: WAITING und unten drunter steht dann der Text, den ich eingegeben hatte.

Das ist ja das komische. Das sind ja eigenlich "Basics" vom Modul.

Viele Grüße

André

viegener · 28 April 2017, 19:56:58

Kannst Du mal versuchen über den BotFather einen neuen API token für Deinen Bot zu erzeugen und dann mit set ... token ... in dem Device einzusetzen?
Ich wüsste zwar nicht wie der kaputt gehen konnte, abereinen Versuch ist es wert

Stargazer · 28 April 2017, 20:22:20

HA ! das wars... viegener !

Ich danke dir recht Herzlich !

Hätte ich nicht gedacht. Wieder etwas gelernt !

Manchmal ist es echt komisch. Ich behalte das mal im Auge... .

Viele Grüße und einen schönen Abend wünscht,

André

viegener · 28 April 2017, 20:51:03

Ja, bitte im Auge behalten, dass habe ich nur aus dem list geschlossen. ie das token in fhem kaputtgehen kann ist mir völlig unklar. Wenn das nochmal passiert bitte melden.

Stargazer · 28 April 2017, 21:52:16

Das ist es, in der Tat.

Wie gesagt. Von ein auf die andere Minute, kann man sagen. Heute morgen um 7.08 Uhr alles gut. Um 7.09 Uhr war alles hin.
Und nichts am Modul oder FHEM oder Bot gemacht.

Ich behalte das im Auge. Sollte da noch was kommen, poste ich es hier wieder.

Besten Dank nochmal...

VG
André

DS_Starter · 01 Mai 2017, 20:55:08

Hallo Stargazer & viegener,

genau das gleiche Phänomen hatte ich im Abstand von ca. 3 Wochen ebenfalls schon beobachtet. Das letzte mal heute. Ich kann auch keine äußere Ursache dafür erkennen. Da ich momentan im Urlaub bin und deswegen auch nichts im FHEM ändere, update, anpasse usw. können auch Änderungen in der FHEM-Umgebung dafür nicht in Frage kommen.
Es hat einfach heute morgen nicht mehr funktioniert so wie Stargazer schrieb und nachdem ich meinen API-Key wieder angegeben hatte klappt es nun wieder wie gewohnt.

EDIT: Die Meldung war eine etwa andere und man sieht auch den Timestamp ab wann:

Code Auswählen

2017.05.01 05:45:00.132 3: TelegramBot_Callback teleBot: resulted in NonBlockingGet: returned <hidden>: malformed or unsupported URL from SendIt

Grüße
Heiko

viegener · 01 Mai 2017, 22:23:52

Da das Token nur geändert wird, wenn explizit gesetzt, kann ich mir nur zwei Dinge vorstellen
Entweder wird aus irgendeinem Grund dder Token überschrieben oder die Decodierung geht aus ungeklärten Gründen schief.
Interessant wäre es herauszufinden, was in diesem Fall in der Datei uniqueID in FHEM/FhemUtils steht.
ABER ACHTUNG: Diese Datei hier nicht posten, denn sie enthält Kennworte!!!

In uniqueID müsste eine Zeile stehen die ungefähr so aussieht:

Code Auswählen

TelegramBot_einbot_token:012536741d42614044704b623b05550e0a05560204704b62b4905b705424906

Wobei statt einbot dann der Name des Bots steht und dahinter ein Text nur aus Ziffern beziehungsweise Buchstaben a-f steht

Könnt Ihr überprüfen, wenn alles gut geht, was in uniqueid steht und dann im Fehlerfall nochmals überprüfen?

DS_Starter · 24 Mai 2017, 13:00:19

Hallo viegener,
habe gerade festgestellt dass es heute wieder soweit ist und seit ca. 5 Uhr:

TelegramBot_readToken: Error: No API token in file

erscheint.
Bin gerade unterwegs und schaue heute Abend nach dem unique File.
Habe bis jetzt auch keine Idee wie das Problem plötzlich auftreten kann.

Grüße
Heiko

DS_Starter · 24 Mai 2017, 20:33:56

Hallo viegener,

also das Token TelegramBot_teleBot_token war nicht mehr in der Datei.
Ich kann mir aber nicht vorstellen, das es an telegramBot liegt. Habe zwar nicht in den Code geschaut, aber vermute du schreibst den Token beim Setup einmalig dort rein und wird dann nur noch gelesen, oder ?
Heute Nacht 0:25 war die Datei noch ok., 06:25 war dann der Tokeneintrag raus. Das sehe ich anhand von Filesicherungen die regelmäßig auf der NAS laufen.

Eine Idee habe ich aber nach wie vor nicht wie das passieren kann.

Grüße
Heiko

viegener · 24 Mai 2017, 21:53:22

Ich kann mir momentan auch nicht vorstellen, wie das Modul bei Dir den Eintrag in der uniqueid löschen könnte.
Der einzige Punkt, bei dem ein Token gelöscht wird ist bei der Umbenennung des device, aber das wird ja nicht nächtlich und schon gar nicht mit identischem Namen passieren, oder?

Allerdings kann ein anderes Modul oder ein problematischer Aufruf von setKeyValue diesen Eintrag entfernen.

Gibt es andere Einträge in der Datei, die nicht verschwinden?
Nutzt Du selber setKeyValue?

DS_Starter · 24 Mai 2017, 22:07:47

Ja, in SMAEM und SSCam. Allerdings habe ich die auch auf anderen Instanzen laufen (Entwicklung und Test) und habe dort dieses Verhalten noch nie festgestellt. SSCam liest allerdings nur einmal beim Start, würde ich ausschließen.
SMAEM schreibt auch. Allerdings ist zum Beispiel die FHEMId auch noch in der Datei vorhanden. Interessant wäre noch die Info von Stargazer wie es bei ihm aussieht ... er hat ja das gleiche Problem gehabt.
Werde das Mal durchdenken, ergibt für mich noch kein richtiges Bild.

Grüße
Heiko