windkh / node-red-contrib-telegrambot

Telegram bot nodes for node-red.
Other
256 stars 117 forks source link

Unhandled rejection RequestError: Error: getaddrinfo EAI_AGAIN api.telegram.org #369

Closed Smyl3 closed 2 weeks ago

Smyl3 commented 3 months ago

Hi, I have a Raspberry Pi Zero that has unstable wifi connection. It seems telegrambot node unable to handle connection errors. Time to time it unable to respond on telegram even when Raspberry connection is actually working. node-red-contrib-telegrambot ver: 15.1.7 Node-red ver: 3.1.0

Used to get 2 type of unhandled exception in log:

Mar 12 16:31:01 Zero node-red[13951]: Unhandled rejection RequestError: Error: getaddrinfo EAI_AGAIN api.telegram.org
Mar 12 16:31:01 Zero node-red[13951]:     at new RequestError (/mnt/dietpi_userdata/node-red/node_modules/request-promise-core/lib/errors.js:14:15)
Mar 12 16:31:01 Zero node-red[13951]:     at plumbing.callback (/mnt/dietpi_userdata/node-red/node_modules/request-promise-core/lib/plumbing.js:87:29)
Mar 12 16:31:01 Zero node-red[13951]:     at Request.RP$callback [as _callback] (/mnt/dietpi_userdata/node-red/node_modules/request-promise-core/lib/plumbing.js:46:31)
Mar 12 16:31:01 Zero node-red[13951]:     at self.callback (/mnt/dietpi_userdata/node-red/node_modules/request/request.js:185:22)
Mar 12 16:31:01 Zero node-red[13951]:     at Request.emit (node:events:513:28)
Mar 12 16:31:01 Zero node-red[13951]:     at Request.onRequestError (/mnt/dietpi_userdata/node-red/node_modules/request/request.js:877:8)
Mar 12 16:31:01 Zero node-red[13951]:     at ClientRequest.emit (node:events:513:28)
Mar 12 16:31:01 Zero node-red[13951]:     at TLSSocket.socketErrorListener (node:_http_client:481:9)
Mar 12 16:31:01 Zero node-red[13951]:     at TLSSocket.emit (node:events:513:28)
Mar 12 16:31:01 Zero node-red[13951]:     at emitErrorNT (node:internal/streams/destroy:151:8)
Mar 12 16:31:01 Zero node-red[13951]:     at emitErrorCloseNT (node:internal/streams/destroy:116:3)
Mar 12 16:31:01 Zero node-red[13951]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21)
Mar 12 17:15:00 Zero node-red[13951]: Unhandled rejection RequestError: Error: read ETIMEDOUT
Mar 12 17:15:00 Zero node-red[13951]:     at new RequestError (/mnt/dietpi_userdata/node-red/node_modules/request-promise-core/lib/errors.js:14:15)
Mar 12 17:15:00 Zero node-red[13951]:     at plumbing.callback (/mnt/dietpi_userdata/node-red/node_modules/request-promise-core/lib/plumbing.js:87:29)
Mar 12 17:15:00 Zero node-red[13951]:     at Request.RP$callback [as _callback] (/mnt/dietpi_userdata/node-red/node_modules/request-promise-core/lib/plumbing.js:46:31)
Mar 12 17:15:00 Zero node-red[13951]:     at self.callback (/mnt/dietpi_userdata/node-red/node_modules/request/request.js:185:22)
Mar 12 17:15:00 Zero node-red[13951]:     at Request.emit (node:events:513:28)
Mar 12 17:15:00 Zero node-red[13951]:     at Request.onRequestError (/mnt/dietpi_userdata/node-red/node_modules/request/request.js:877:8)
Mar 12 17:15:00 Zero node-red[13951]:     at ClientRequest.emit (node:events:513:28)
Mar 12 17:15:00 Zero node-red[13951]:     at TLSSocket.socketErrorListener (node:_http_client:481:9)
Mar 12 17:15:00 Zero node-red[13951]:     at TLSSocket.emit (node:events:513:28)
Mar 12 17:15:00 Zero node-red[13951]:     at emitErrorNT (node:internal/streams/destroy:151:8)
Mar 12 17:15:00 Zero node-red[13951]:     at emitErrorCloseNT (node:internal/streams/destroy:116:3)
Mar 12 17:15:00 Zero node-red[13951]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21)
windkh commented 3 months ago

@Smyl3 Can you reproduce that? Well, if I disconnect wifi from my laptop running node-red then it works as expected. But these errors are mostly reported from users that are running node-red on a raspi. ...

Smyl3 commented 3 months ago

@Smyl3 Can you reproduce that? Well, if I disconnect wifi from my laptop running node-red then it works as expected. But these errors are mostly reported from users that are running node-red on a raspi. ...

Yes, with an other Raspberry. I didnt do anything with it, only blocked its ip in the router's firewall to block its internet access. After that nothing happened for like 5-10 min. Telegram nodes acting like normal and showed polling and connected statuses even when I initiated Telegram message sending from Node-red. But after like 5-10 minutes, those error message came up in log:

2024-03-12T21:10:27.040679000Z 12 Mar 22:10:27 - [error] [telegram sender:95fd94dd7db5ba7a] Caught exception in sender node:
2024-03-12T21:10:27.042444000Z Error: EFATAL: Error: connect ETIMEDOUT 149.154.167.220:443
2024-03-12T21:10:27.042755000Z when processing message: 
2024-03-12T21:10:27.043018000Z _msgid=11e65f38c7fba90e payload={"type":"message","chatId":380964289,"content":"Fűtés: BEkapcsolva","options":{"chat_id":380964289,"text":"Fűtés: BEkapcsolva"}} topic=
2024-03-12T21:10:27.049427000Z Unhandled rejection RequestError: Error: connect ETIMEDOUT 149.154.167.220:443
2024-03-12T21:10:27.049969000Z     at new RequestError (/data/node_modules/request-promise-core/lib/errors.js:14:15)
2024-03-12T21:10:27.050248000Z     at Request.plumbing.callback (/data/node_modules/request-promise-core/lib/plumbing.js:87:29)
2024-03-12T21:10:27.050505000Z     at Request.RP$callback [as _callback] (/data/node_modules/request-promise-core/lib/plumbing.js:46:31)
2024-03-12T21:10:27.050776000Z     at self.callback (/data/node_modules/request/request.js:185:22)
2024-03-12T21:10:27.051019000Z     at Request.emit (node:events:513:28)
2024-03-12T21:10:27.051262000Z     at Request.onRequestError (/data/node_modules/request/request.js:877:8)
2024-03-12T21:10:27.051502000Z     at ClientRequest.emit (node:events:513:28)
2024-03-12T21:10:27.051755000Z     at TLSSocket.socketErrorListener (node:_http_client:494:9)
2024-03-12T21:10:27.051994000Z     at TLSSocket.emit (node:events:513:28)
2024-03-12T21:10:27.052265000Z     at emitErrorNT (node:internal/streams/destroy:157:8)
2024-03-12T21:10:27.052503000Z     at emitErrorCloseNT (node:internal/streams/destroy:122:3)
2024-03-12T21:10:27.052739000Z     at processTicksAndRejections (node:internal/process/task_queues:83:21)
2024-03-12T21:11:57.142325000Z 12 Mar 22:11:57 - [error] [telegram sender:95fd94dd7db5ba7a] Caught exception in sender node:
2024-03-12T21:11:57.143961000Z Error: EFATAL: Error: connect ETIMEDOUT 149.154.167.220:443
2024-03-12T21:11:57.144262000Z when processing message: 
2024-03-12T21:11:57.144558000Z _msgid=087aee62a96c1a52 payload={"type":"message","chatId":380964289,"content":"Fűtés: KIkapcsolva","options":{"chat_id":380964289,"text":"Fűtés: KIkapcsolva"}} topic=
2024-03-12T21:11:57.144807000Z Unhandled rejection RequestError: Error: connect ETIMEDOUT 149.154.167.220:443
2024-03-12T21:11:57.145072000Z     at new RequestError (/data/node_modules/request-promise-core/lib/errors.js:14:15)
2024-03-12T21:11:57.145384000Z     at Request.plumbing.callback (/data/node_modules/request-promise-core/lib/plumbing.js:87:29)
2024-03-12T21:11:57.145633000Z     at Request.RP$callback [as _callback] (/data/node_modules/request-promise-core/lib/plumbing.js:46:31)
2024-03-12T21:11:57.145902000Z     at self.callback (/data/node_modules/request/request.js:185:22)
2024-03-12T21:11:57.146142000Z     at Request.emit (node:events:513:28)
2024-03-12T21:11:57.146381000Z     at Request.onRequestError (/data/node_modules/request/request.js:877:8)
2024-03-12T21:11:57.146620000Z     at ClientRequest.emit (node:events:513:28)
2024-03-12T21:11:57.146864000Z     at TLSSocket.socketErrorListener (node:_http_client:494:9)
2024-03-12T21:11:57.147119000Z     at TLSSocket.emit (node:events:513:28)
2024-03-12T21:11:57.147352000Z     at emitErrorNT (node:internal/streams/destroy:157:8)
2024-03-12T21:11:57.147588000Z     at emitErrorCloseNT (node:internal/streams/destroy:122:3)
2024-03-12T21:11:57.147823000Z     at processTicksAndRejections (node:internal/process/task_queues:83:21)
2024-03-12T21:11:59.189402000Z 12 Mar 22:11:59 - [error] [telegram sender:95fd94dd7db5ba7a] Caught exception in sender node:
2024-03-12T21:11:59.191023000Z Error: EFATAL: Error: connect ETIMEDOUT 149.154.167.220:443
2024-03-12T21:11:59.191360000Z when processing message: 
2024-03-12T21:11:59.191634000Z _msgid=0180ad9a31570798 payload={"type":"message","chatId":380964289,"content":"Fűtés: BEkapcsolva","options":{"chat_id":380964289,"text":"Fűtés: BEkapcsolva"}} topic=
2024-03-12T21:11:59.193058000Z Unhandled rejection RequestError: Error: connect ETIMEDOUT 149.154.167.220:443
2024-03-12T21:11:59.193520000Z     at new RequestError (/data/node_modules/request-promise-core/lib/errors.js:14:15)
2024-03-12T21:11:59.193815000Z     at Request.plumbing.callback (/data/node_modules/request-promise-core/lib/plumbing.js:87:29)
2024-03-12T21:11:59.194069000Z     at Request.RP$callback [as _callback] (/data/node_modules/request-promise-core/lib/plumbing.js:46:31)
2024-03-12T21:11:59.194316000Z     at self.callback (/data/node_modules/request/request.js:185:22)
2024-03-12T21:11:59.194577000Z     at Request.emit (node:events:513:28)
2024-03-12T21:11:59.194823000Z     at Request.onRequestError (/data/node_modules/request/request.js:877:8)
2024-03-12T21:11:59.195066000Z     at ClientRequest.emit (node:events:513:28)
2024-03-12T21:11:59.195312000Z     at TLSSocket.socketErrorListener (node:_http_client:494:9)
2024-03-12T21:11:59.195560000Z     at TLSSocket.emit (node:events:513:28)
2024-03-12T21:11:59.195818000Z     at emitErrorNT (node:internal/streams/destroy:157:8)
2024-03-12T21:11:59.196055000Z     at emitErrorCloseNT (node:internal/streams/destroy:122:3)
2024-03-12T21:11:59.196306000Z     at processTicksAndRejections (node:internal/process/task_queues:83:21)

The 149.154.167.220 ip address is api.telegram.org

It seems those codes has plenty of unhandled exceptions, but I don't think so that I able to reproduce those other type of errors because don't know how happened. In the log I had other types of unhandled exception errors either:

2024-03-12T01:10:32.731656000Z Unhandled rejection Error: ETELEGRAM: 429 Too Many Requests: retry after 5
2024-03-12T01:10:32.733562000Z     at /data/node_modules/node-telegram-bot-api/src/telegram.js:299:15
2024-03-12T01:10:32.733844000Z     at tryCatcher (/data/node_modules/bluebird/js/release/util.js:16:23)
2024-03-12T01:10:32.734132000Z     at Promise._settlePromiseFromHandler (/data/node_modules/bluebird/js/release/promise.js:547:31)
2024-03-12T01:10:32.734376000Z     at Promise._settlePromise (/data/node_modules/bluebird/js/release/promise.js:604:18)
2024-03-12T01:10:32.734605000Z     at Promise._settlePromise0 (/data/node_modules/bluebird/js/release/promise.js:649:10)
2024-03-12T01:10:32.734857000Z     at Promise._settlePromises (/data/node_modules/bluebird/js/release/promise.js:729:18)
2024-03-12T01:10:32.735119000Z     at _drainQueueStep (/data/node_modules/bluebird/js/release/async.js:93:12)
2024-03-12T01:10:32.735352000Z     at _drainQueue (/data/node_modules/bluebird/js/release/async.js:86:9)
2024-03-12T01:10:32.735600000Z     at Async._drainQueues (/data/node_modules/bluebird/js/release/async.js:102:5)
2024-03-12T01:10:32.735844000Z     at Immediate.Async.drainQueues [as _onImmediate] (/data/node_modules/bluebird/js/release/async.js:15:14)
2024-03-12T01:10:32.736080000Z     at processImmediate (node:internal/timers:466:21)
2024-03-12T01:10:35.761633000Z Unhandled rejection Error: ETELEGRAM: 502 Bad Gateway
2024-03-12T01:10:35.763324000Z     at /data/node_modules/node-telegram-bot-api/src/telegram.js:299:15
2024-03-12T01:10:35.763714000Z     at tryCatcher (/data/node_modules/bluebird/js/release/util.js:16:23)
2024-03-12T01:10:35.764006000Z     at Promise._settlePromiseFromHandler (/data/node_modules/bluebird/js/release/promise.js:547:31)
2024-03-12T01:10:35.764266000Z     at Promise._settlePromise (/data/node_modules/bluebird/js/release/promise.js:604:18)
2024-03-12T01:10:35.764509000Z     at Promise._settlePromise0 (/data/node_modules/bluebird/js/release/promise.js:649:10)
2024-03-12T01:10:35.764763000Z     at Promise._settlePromises (/data/node_modules/bluebird/js/release/promise.js:729:18)
2024-03-12T01:10:35.765015000Z     at _drainQueueStep (/data/node_modules/bluebird/js/release/async.js:93:12)
2024-03-12T01:10:35.765274000Z     at _drainQueue (/data/node_modules/bluebird/js/release/async.js:86:9)
2024-03-12T01:10:35.765732000Z     at Async._drainQueues (/data/node_modules/bluebird/js/release/async.js:102:5)
2024-03-12T01:10:35.765981000Z     at Immediate.Async.drainQueues [as _onImmediate] (/data/node_modules/bluebird/js/release/async.js:15:14)
2024-03-12T01:10:35.766272000Z     at processImmediate (node:internal/timers:466:21)
windkh commented 2 weeks ago

please try with new version 16.0.0