Telegram sending error on 14.0.0.1 (and master 14.0.0 also) #21464

nikvostro · 2024-05-21T17:52:31Z

PROBLEM DESCRIPTION

Telegram returns error when sending message on 14.0.0.1 (and master 14.0.0 also).
Sending via Telegram API using webquery works for master 14.0.0 build (which I've initially compiled and updated one of my tasmotas) but don't work for dev.

REQUESTED INFORMATION

20:20:03.624 RSL: RESULT = {"NAME":"ESP32-DevKit","GPIO":[1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,1,0,1,1,1,0,1,1,1,0,0,0,0,1,1,1,1,1,0,0,1],"FLAG":0,"BASE":1}
20:20:03.851 RSL: RESULT = {"Module":{"1":"ESP32-DevKit"}}
20:20:04.059 RSL: RESULT = {"GPIO0":{"0":"None"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO5":{"0":"None"},"GPIO6":{"0":"None"},"GPIO7":{"0":"None"},"GPIO8":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO11":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"0":"None"},"GPIO14":{"0":"None"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"},"GPIO17":{"0":"None"},"GPIO18":{"0":"None"},"GPIO19":{"0":"None"},"GPIO20":{"0":"None"},"GPIO21":{"0":"None"},"GPIO22":{"0":"None"},"GPIO23":{"0":"None"},"GPIO24":{"0":"None"},"GPIO25":{"0":"None"},"GPIO26":{"0":"None"},"GPIO27":{"0":"None"},"GPIO32":{"0":"None"},"GPIO33":{"0":"None"},"GPIO34":{"0":"None"},"GPIO35":{"0":"None"},"GPIO36":{"0":"None"},"GPIO37":{"0":"None"},"GPIO38":{"0":"None"},"GPIO39":{"0":"None"}}

~~- [ ] If using rules, provide the output of this command: Backlog Rule1; Rule2; Rule3:~~

Provide the output of this command: Status 0:

20:20:28.289 RSL: STATUS = {"Status":{"Module":1,"DeviceName":"Tasmota","FriendlyName":["Tasmota"],"Topic":"tasmota_C6CAB8","ButtonTopic":"0","Power":"0","PowerLock":"0","PowerOnState":0,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":0,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0,"StatusRetain":0}}
20:20:28.322 RSL: STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota32/release/tasmota32.bin","RestartReason":"Software reset CPU","Uptime":"0T00:01:58","StartupUTC":"2024-05-21T17:18:30","Sleep":50,"CfgHolder":4617,"BootCount":1,"BCResetTime":"2024-05-21T20:18:35","SaveCount":6}}
20:20:28.355 RSL: STATUS2 = {"StatusFWR":{"Version":"14.0.0.1(tasmota32)","BuildDateTime":"2024-05-21T20:16:28","Core":"3_0_0","SDK":"5.1.3.240430","CpuFrequency":160,"Hardware":"ESP32-D0WD-V3 v3.1","CR":"401/699"}}
20:20:28.377 RSL: STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["domuk",""],"TelePeriod":0,"Resolution":"558180C0","SetOption":["00008000","1405C80005000600003C5A0A192800000000","00800080","00006000","00004001","00000000"]}}
20:20:28.413 RSL: STATUS4 = {"StatusMEM":{"ProgramSize":1366,"Free":1513,"Heap":158,"StackLowMark":3,"PsrMax":4096,"PsrFree":4085,"ProgramFlashSize":16384,"FlashSize":16384,"FlashChipId":"1840C8","FlashFrequency":40,"FlashMode":"DIO","Features":["0809","978A159F","0009A001","B7F7BFCF","05DA9BC4","60360C47","4808C0D2","20200000","D4BC4825","810A80B1","00000014"],"Drivers":"1,!2,!3,!4,!5,!8,9,10,11,!12,!14,!16,!17,!24,29,!34,38,40,50,!59,!60,62,!63,!66,!67,!68,!73,82,!86,!87,!88,!121","Sensors":"1,2,3,5,6,7,8,9,10,11,12,13,14,15,17,18,19,20,21,22,26,31,34,37,39,40,42,43,45,51,52,55,56,58,59,64,66,67,74,85,92,95,98,103,105,109,127","I2CDriver":"7,8,9,10,11,12,13,14,15,17,18,20,24,29,31,36,41,42,44,46,48,58,62,65,69,76,77,82"}}
20:20:28.478 RSL: STATUS5 = {"StatusNET":{"Hostname":"tasmota-C6CAB8-2744","IPAddress":"192.168.11.179","Gateway":"192.168.11.1","Subnetmask":"255.255.255.0","DNSServer1":"192.168.11.1","DNSServer2":"0.0.0.0","Mac":"08:D1:ww:xx:yy:zz","IP6Global":"","IP6Local":"fe80::ad1:f9ff:fec6:cab8%st1","Ethernet":{"Hostname":"","IPAddress":"0.0.0.0","Gateway":"0.0.0.0","Subnetmask":"0.0.0.0","DNSServer1":"192.168.11.1","DNSServer2":"0.0.0.0","Mac":"00:00:00:00:00:00","IP6Global":"","IP6Local":""},"Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":16.0}}
20:20:28.522 RSL: STATUS7 = {"StatusTIM":{"UTC":"2024-05-21T17:20:28Z","Local":"2024-05-21T20:20:28","StartDST":"2024-03-31T02:00:00","EndDST":"2024-10-27T03:00:00","Timezone":"+03:00","Sunrise":"04:06","Sunset":"20:44"}}
20:20:28.546 RSL: STATUS10 = {"StatusSNS":{"Time":"2024-05-21T20:20:28"}}
20:20:28.551 RSL: STATUS11 = {"StatusSTS":{"Time":"2024-05-21T20:20:28","Uptime":"0T00:01:58","UptimeSec":118,"Heap":158,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":0,"Wifi":{"AP":1,"SSId":"[mywifinet]","BSSId":"7C:10:ww:xx:yy:zz","Channel":11,"Mode":"HT20","RSSI":78,"Signal":-61,"LinkCount":1,"Downtime":"0T00:00:04"}}}```

Set weblog to 4 and then, when you experience your issue, provide the output of the Console log:

20:23:40.590 CMD: tmstate 2
20:23:40.592 SRC: WebConsole from 192.168.11.80
20:23:40.594 CMD: Grp 0, Cmd 'TMSTATE', Idx 1, Len 1, Pld 2, Data '2'
20:23:40.597 RSL: RESULT = {"TmState":{"Send":"ON","Receive":"OFF","Echo":"OFF"}}
20:23:42.439 CMD: tmstate 3
20:23:42.440 SRC: WebConsole from 192.168.11.80
20:23:42.442 CMD: Grp 0, Cmd 'TMSTATE', Idx 1, Len 1, Pld 3, Data '3'
20:23:42.444 RSL: RESULT = {"TmState":{"Send":"ON","Receive":"ON","Echo":"OFF"}}
20:24:40.636 CMD: tmtoken [mybottokenhere]
20:24:40.637 SRC: WebConsole from 192.168.11.80
20:24:40.638 CMD: Grp 0, Cmd 'TMTOKEN', Idx 1, Len 45, Pld 984067856, Data '[mybottokenhere]'
20:24:40.641 CFG: CR 446/699, Busy 0
20:24:40.643 RSL: RESULT = {"TmToken":"[mybottokenhere]"}
20:25:32.619 CMD: tmchatid [myprivatechatID]
20:25:32.621 SRC: WebConsole from 192.168.11.80
20:25:32.622 CMD: Grp 0, Cmd 'TMCHATID', Idx 1, Len 9, Pld [myprivatechatID], Data '[myprivatechatID]'
20:25:32.625 CFG: CR 455/699, Busy 0
20:25:32.626 RSL: RESULT = {"TmChatId":"[myprivatechatID]"}
20:26:33.594 CMD: so132
20:26:33.596 SRC: WebConsole from 192.168.11.80
20:26:33.598 CMD: Grp 0, Cmd 'SO', Idx 132, Len 0, Pld -99, Data ''
20:26:33.599 RSL: RESULT = {"SetOption132":"OFF"}
20:26:36.546 CMD: so132 1
20:26:36.548 SRC: WebConsole from 192.168.11.80
20:26:36.549 CMD: Grp 0, Cmd 'SO', Idx 132, Len 1, Pld 1, Data '1'
20:26:36.551 RSL: RESULT = {"SetOption132":"ON"}
[Tasmota has restarted here]
...
20:26:43.518 TGM: getUpdates
20:26:43.524 WIF: DNS resolved 'api.telegram.org' (149.154.167.220) in 6 ms
20:26:43.670 TGM: Response ''
20:26:46.531 QPC: Reset
20:26:48.522 APP: Boot Count 2
20:26:49.335 CFG: Saved, Count 13, Bytes 4096
20:26:56.519 TGM: getUpdates
20:26:56.521 WIF: DNS resolved 'api.telegram.org' (149.154.167.220) in 0 ms
20:26:56.655 TGM: Response ''

20:28:07.829 CMD: tmsend "test"
20:28:07.830 SRC: WebConsole from 192.168.11.80
20:28:07.831 CMD: Grp 0, Cmd 'TMSEND', Idx 1, Len 6, Pld -99, Data '"test"'
20:28:07.833 TGM: sendMessage
20:28:07.834 WIF: DNS resolved 'api.telegram.org' (149.154.167.220) in 0 ms
20:28:07.968 RSL: RESULT = {"TmSend":"Failed"}

TO REPRODUCE

Build tasmtota32 standard env using dev 21.05.2024 with -DUSE_TELEGRAM
Set telegram parameters: token, chatid, state
SO132 1 (Force TLS fingerprint validation instead of CA)
Try to send message via tmsend command

EXPECTED BEHAVIOUR

Telegram sends message

SCREENSHOTS

n/a

ADDITIONAL CONTEXT

Telegram was working fine with every release lower than v14 with on many Tasmota devices.

Manual sending via webquery worked for the master branch 14.0.0.1 but don't work for dev 14.0.0.1:

20:50:04.548 CMD: webquery https://api.telegram.org/bot[mybottokenhere]/sendMessage?text=test&chat_id=[myprivatechatID]
20:50:04.551 SRC: WebConsole from 192.168.11.80
20:50:04.553 CMD: Grp 0, Cmd 'WEBQUERY', Idx 1, Len 113, Pld -99, Data 'https://api.telegram.org/bot[mybottokenhere]/sendMessage?text=test&chat_id=[myprivatechatID]'
20:50:04.665 RSL: RESULT = {"WebQuery":"Done"}

After "Done" nothing comes to the telegram chat. At the same time this query works on another tasmotas and PC.
(Please, remember to close the issue when the problem has been addressed)

The text was updated successfully, but these errors were encountered:

inode- · 2024-05-23T07:34:01Z

I can confirm, just build 13.4.0 and work correctly, on 14.x it's not working anymore

s-hadinger · 2024-05-23T18:57:44Z

I'm not familiar with the time it normally makes, but it seems the two log lines are very close to each other:

20:28:07.833 TGM: sendMessage
20:28:07.834 WIF: DNS resolved 'api.telegram.org' (149.154.167.220) in 0 ms
20:28:07.968 RSL: RESULT = {"TmSend":"Failed"}

It's maybe linked to #21442

The timeout value changed from seconds to milliseconds in the Core3 API. This could explain why the "Failed" messages happens only 134ms after the actual command (which is shorter than a full TLS handshake)

arendst · 2024-05-23T21:10:39Z

It consistently replies:

23:08:44.996 TGM: getUpdates
connect(api.telegram.org,443)
connect(149.154.167.220,443)
_connectSSL: start connection
_wait_for_handshake: failed
Couldn't connect. Error = 1
23:08:45.101 TGM: Response ''

even with a timeout of 10000 ms (being default in code)

s-hadinger · 2024-05-23T21:25:29Z

I'm still surprised how quickly it returns the error, 105 ms including the logging

arendst · 2024-05-23T21:27:15Z

From what I see above it doesn't connect at all as _wait_for_handshake: failed returns immediatly.

and no heap usage either:

23:27:31.958 TGM: getUpdates
connect(api.telegram.org,443)
connect(149.154.167.220,443)
> Heap Before calling _connectSSL = 3712
> Heap _connectSSL.start = 3712
> Heap Thunk allocated = 3712
_connectSSL: start connection
> Heap _connectSSL before DecoderContext allocation = 3712
> Heap _connectSSL after DecoderContext allocation = 3712
> Heap _connectSSL before PrivKey allocation = 3712
_wait_for_handshake: failed
Couldn't connect. Error = 1
> Heap _connectSSL.end = 3712
> Heap _connectSSL after release of Priv Key = 3712
23:27:32.103 TGM: Response ''

s-hadinger · 2024-05-23T21:31:58Z

Unrelated issue:

GoDaddy Daddy Secure Certificate Authority - G2, RSA 2048 bits SHA 256, valid until 20220523

It seems that the GoDaddy Authority is long expired. Although I understand you don't use it and use fingerprint instead

arendst · 2024-05-23T21:34:00Z

Yep. That was the reason we had to use SO132 1 for fingerprint.

arendst · 2024-05-27T14:03:03Z

I'm still looking into the Telegram issue. As a test I started to reuse an ESP8266 but it fails there too. So for now we can rule out core3.

How about the fingerprint? Where can I see if the fingerprint is still valid?

s-hadinger · 2024-05-27T14:22:10Z

Invalid fingerprint would generate a TLS error. It's not the case here.
You can also reset the fingerprint with all zeroes to accept any value

arendst · 2024-05-27T15:51:42Z

Adding some more debug info doesn't ring my bells:

17:50:08.675-014 CMD: tmsend hello
17:50:08.677-014 SRC: Serial
17:50:08.680-014 CMD: Grp 0, Cmd 'TMSEND', Idx 1, Len 5, Pld -99, Data 'hello'
17:50:08.683-014 TGM: Connect start 'bot1179906608:AAE-3UfPJt3u8d-gbGXslnFO96o3DahG6EM/sendMessage?chat_id=139920293&text=hello'
connect(api.telegram.org,443)
connect(149.154.167.220,443)
_connectSSL: start connection
_run_until: BR_SSL_CLOSED
_wait_for_handshake: failed
Couldn't connect. Error = 1
17:50:08.812-014 TGM: Connect failed
17:50:08.814-014 TGM: Response 
17:50:08.818-011 MQT: stat/wemos4/RESULT = {"TmSend":"Failed"}

I'm lost for now.

s-hadinger · 2024-05-27T16:01:15Z

Ah, it is a TLS connection error after all. Let me first update the CA.

s-hadinger · 2024-05-27T20:12:19Z

I updated the CA from Telegram, but now I get error 49: BR_ERR_X509_UNSUPPORTED - certificate contains unsupported features that cannot be ignored.

This would be a lot of work to allow unsupported features, hence I'm in favor of removing CA verification in Telegram (which wasn't working anyways).

The Fingerprint seems to have changed, it is now:
4E 7F F5 6D 1E 29 40 58 AB 84 DE 63 69 7B CD DF 44 2E D2 F6

arendst · 2024-05-27T20:12:46Z

With latest change in CA and SO132 1 (and fingerprint set 0's):

22:10:45.362-017 TGM: Connect start 'bot1179906608:AAE-3UfPJt3u8d-gbGXslnFO96o3DahG6EM/getUpdates?offset=0'
connect(api.telegram.org,443)
connect(149.154.167.220,443)
_connectSSL: start connection
_run_until: BR_SSL_CLOSED
_wait_for_handshake: failed
Couldn't connect. Error = 1
22:10:45.487-015 TGM: Connect failed

with SO132 0:

22:11:03.340-017 TGM: Connect start 'bot1179906608:AAE-3UfPJt3u8d-gbGXslnFO96o3DahG6EM/getUpdates?offset=0'
connect(api.telegram.org,443)
connect(149.154.167.220,443)
_connectSSL: start connection
_run_until: BR_SSL_CLOSED
_wait_for_handshake: failed
Couldn't connect. Error = 49
22:11:03.993-015 TGM: Connect failed

arendst · 2024-05-27T20:16:43Z

Yep! Succes. The changed fingerprint workx.

s-hadinger mentioned this issue May 27, 2024

Fix Telegram TLS fingerprint, remove CA validation #21514

Merged

6 tasks

s-hadinger closed this as completed in #21514 May 27, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Telegram sending error on 14.0.0.1 (and master 14.0.0 also) #21464

Telegram sending error on 14.0.0.1 (and master 14.0.0 also) #21464

nikvostro commented May 21, 2024 •

edited

Loading

inode- commented May 23, 2024

s-hadinger commented May 23, 2024

arendst commented May 23, 2024

s-hadinger commented May 23, 2024

arendst commented May 23, 2024 •

edited

Loading

s-hadinger commented May 23, 2024

arendst commented May 23, 2024

arendst commented May 27, 2024

s-hadinger commented May 27, 2024

arendst commented May 27, 2024

s-hadinger commented May 27, 2024

s-hadinger commented May 27, 2024

arendst commented May 27, 2024

arendst commented May 27, 2024

Telegram sending error on 14.0.0.1 (and master 14.0.0 also) #21464

Telegram sending error on 14.0.0.1 (and master 14.0.0 also) #21464

Comments

nikvostro commented May 21, 2024 • edited Loading

PROBLEM DESCRIPTION

REQUESTED INFORMATION

TO REPRODUCE

EXPECTED BEHAVIOUR

SCREENSHOTS

ADDITIONAL CONTEXT

inode- commented May 23, 2024

s-hadinger commented May 23, 2024

arendst commented May 23, 2024

s-hadinger commented May 23, 2024

arendst commented May 23, 2024 • edited Loading

s-hadinger commented May 23, 2024

arendst commented May 23, 2024

arendst commented May 27, 2024

s-hadinger commented May 27, 2024

arendst commented May 27, 2024

s-hadinger commented May 27, 2024

s-hadinger commented May 27, 2024

arendst commented May 27, 2024

arendst commented May 27, 2024

nikvostro commented May 21, 2024 •

edited

Loading

arendst commented May 23, 2024 •

edited

Loading