crycode-de / ioBroker.discord

ioBroker Discord bot integration
MIT License
6 stars 4 forks source link

Fewer log warnings for connection retry #49

Closed pafade89 closed 8 months ago

pafade89 commented 1 year ago

Is your feature request related to a problem? Please describe.

Make your adapter less aggressive with connection problems in the log.

Describe the solution you'd like

Is it possible if the connection is lost, first carry out a few retrys and treat the connection loss as info in the log. Only after several failed attempts then issue a warning. Unfortunately, the adapter currently spams the log immediately.

crycode-de commented 1 year ago

Can you provide some example logs? There may be some different log messages. On simple connect/disconnect/reconnect events the messages should be logged as debug messages only.

pafade89 commented 1 year ago
2023-07-03 10:33:50.035 - warn: discord.0 (234760) Discord client websocket error: Error: getaddrinfo EAI_AGAIN gateway.discord.gg
2023-07-03 10:33:50.053 - error: discord.0 (234760) Discord client websocket error (shardId:0) Error: getaddrinfo EAI_AGAIN gateway.discord.gg
2023-07-03 10:33:50.054 - info: discord.0 (234760) Terminated (START_IMMEDIATELY_AFTER_STOP): Discord client websocket error
2023-07-03 10:33:53.801 - info: discord.0 (318092) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:34:14.177 - error: discord.0 (318092) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:34:14.179 - info: discord.0 (318092) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:34:17.443 - info: discord.0 (318112) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:34:37.798 - error: discord.0 (318112) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:34:37.800 - info: discord.0 (318112) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:34:41.081 - info: discord.0 (318129) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:35:01.438 - error: discord.0 (318129) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:35:01.440 - info: discord.0 (318129) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:35:04.712 - info: discord.0 (318149) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:35:25.293 - error: discord.0 (318149) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:35:25.294 - info: discord.0 (318149) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:35:28.585 - info: discord.0 (318166) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:35:48.938 - error: discord.0 (318166) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:35:48.939 - info: discord.0 (318166) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:35:52.205 - info: discord.0 (318181) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:36:12.564 - error: discord.0 (318181) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:36:12.566 - info: discord.0 (318181) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:36:15.886 - info: discord.0 (318201) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:36:36.242 - error: discord.0 (318201) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:36:36.243 - info: discord.0 (318201) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:36:39.502 - info: discord.0 (318218) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:36:59.852 - error: discord.0 (318218) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:36:59.853 - info: discord.0 (318218) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:37:03.167 - info: discord.0 (318239) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:37:23.573 - error: discord.0 (318239) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo EAI_AGAIN discord.com
2023-07-03 10:37:23.574 - info: discord.0 (318239) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:37:26.868 - info: discord.0 (318254) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:37:32.253 - error: discord.0 (318254) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo ENOTFOUND discord.com
2023-07-03 10:37:32.254 - info: discord.0 (318254) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:37:35.526 - info: discord.0 (318271) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:37:35.859 - error: discord.0 (318271) Discord login error: FetchError: request to https://discord.com/api/v9/gateway/bot failed, reason: getaddrinfo ENOTFOUND discord.com
2023-07-03 10:37:35.860 - info: discord.0 (318271) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-07-03 10:37:39.156 - info: discord.0 (318286) starting. Version 1.1.6 in /opt/iobroker/node_modules/iobroker.discord, node: v18.16.0, js-controller: 4.0.24
2023-07-03 10:37:40.316 - info: discord.0 (318286) Discord client websocket connected (shardId:0)
2023-07-03 10:37:40.318 - info: discord.0 (318286) Logged in as ioBroker Bot#XXXX
crycode-de commented 1 year ago

Thank you! I'll check and optimize this for the v2.0 stable release.

pafade89 commented 1 year ago

Thank you. I look forward to the release.

crycode-de commented 1 year ago

@pafade89 The issue is now fixed on the main branch and will be included in the next release.

I had already a login error detection and some logic to handle these errors. Unfortunately, this didn't work with your type of error. EAI_AGAIN means there was a DNS error and the domain discord.com could not be resolved.

Now it's working as intended (no more adapter restart loops). Additionally the first four failed tries are logged as info only now. All following failed tries will be logged as warning.

2023-07-09 15:42:41.492  - info: discord.0 (3001) Discord login error: Error: getaddrinfo EAI_AGAIN discord.com
2023-07-09 15:42:41.498  - info: discord.0 (3001) Wait 5 seconds before next login try (#2) ...
2023-07-09 15:42:52.747  - info: discord.0 (3001) Discord login error: Error: getaddrinfo EAI_AGAIN discord.com
2023-07-09 15:42:52.748  - info: discord.0 (3001) Wait 10 seconds before next login try (#3) ...
2023-07-09 15:43:06.139  - info: discord.0 (3001) Discord login error: Error: getaddrinfo EAI_AGAIN discord.com
2023-07-09 15:43:06.140  - info: discord.0 (3001) Wait 30 seconds before next login try (#4) ...
2023-07-09 15:43:38.439  - info: discord.0 (3001) Discord login error: Error: getaddrinfo EAI_AGAIN discord.com
2023-07-09 15:43:38.445  - info: discord.0 (3001) Wait 60 seconds before next login try (#5) ...
2023-07-09 15:44:40.298  - warn: discord.0 (3001) Discord login error: Error: getaddrinfo EAI_AGAIN discord.com
2023-07-09 15:44:40.300  - info: discord.0 (3001) Wait 120 seconds before next login try (#6) ...
2023-07-09 15:46:40.319  - warn: discord.0 (3001) Discord login error: Error: getaddrinfo EAI_AGAIN discord.com
2023-07-09 15:46:40.320  - info: discord.0 (3001) Wait 120 seconds before next login try (#7) ...

The wait time will increase up to 10 minutes (10+ failed tries).

Thank you again for reporting this!

pafade89 commented 1 year ago

Perfect, I will test it as soon as the release is available. Thanks for the support.

crycode-de commented 1 year ago

v2.1.0 is now released on NPM and should be in the latest repo tomorrow. :)

pafade89 commented 9 months ago

@crycode-de I think it's not working as expected. Here the router gets a new IP and it looks like this:

2023-09-24 00:23:43.424 - warn: discord.0 (78338) Discord client websocket error: Error: getaddrinfo EAI_AGAIN gateway-us-east1-b.discord.gg
2023-09-24 00:23:43.440 - error: discord.0 (78338) Discord client websocket error (shardId:0) Error: getaddrinfo EAI_AGAIN gateway-us-east1-b.discord.gg
2023-09-24 00:23:43.442 - info: discord.0 (78338) Terminated (START_IMMEDIATELY_AFTER_STOP): Discord client websocket error
2023-09-24 00:23:56.962 - info: discord.0 (149988) starting. Version 2.1.2 in /opt/iobroker/node_modules/iobroker.discord, node: v18.17.1, js-controller: 4.0.24
2023-09-24 00:24:07.311 - info: discord.0 (149988) Discord login error: ConnectTimeoutError: Connect Timeout Error
2023-09-24 00:24:07.312 - info: discord.0 (149988) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-09-24 00:24:10.480 - info: discord.0 (150008) starting. Version 2.1.2 in /opt/iobroker/node_modules/iobroker.discord, node: v18.17.1, js-controller: 4.0.24
2023-09-24 00:24:20.824 - info: discord.0 (150008) Discord login error: ConnectTimeoutError: Connect Timeout Error
2023-09-24 00:24:20.825 - info: discord.0 (150008) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-09-24 00:24:24.019 - info: discord.0 (150023) starting. Version 2.1.2 in /opt/iobroker/node_modules/iobroker.discord, node: v18.17.1, js-controller: 4.0.24
2023-09-24 00:24:34.350 - info: discord.0 (150023) Discord login error: ConnectTimeoutError: Connect Timeout Error
2023-09-24 00:24:34.351 - info: discord.0 (150023) Terminated (START_IMMEDIATELY_AFTER_STOP): No connection to Discord
2023-09-24 00:24:37.577 - info: discord.0 (150041) starting. Version 2.1.2 in /opt/iobroker/node_modules/iobroker.discord, node: v18.17.1, js-controller: 4.0.24
2023-09-24 00:24:43.692 - info: discord.0 (150041) Discord client websocket connected (shardId:0)
2023-09-24 00:24:43.694 - info: discord.0 (150041) Logged in as ioBroker Bot

Can you maybe take another look?

Thank you =)

crycode-de commented 9 months ago

@pafade89 Oh... the ConnectTimeoutError is new and currently not handled. Thank you for reporting. I'll add this to the possibly expected errors.

Also the "Discord client websocket error" is handled twice but differently. :thinking: I'll check this too.

crycode-de commented 8 months ago

@pafade89 Release v2.2.0 is out now and includes an optimized error handling. The adapter should no longer restart in case of a network related error. Instead it tries to (re)connect automatically and the info.connection state is set to false. Once a connection was established to the Discord servers, a connection error will be logged only once as warning. All further (same) errors are only logged as debug to not spam the normal log.

v2.2.0 should be available in the latest repo tomorrow. If there are no bugs reported after some time, this will go to the stable repo. :)

pafade89 commented 8 months ago

@crycode-de

Thank you very much for your effort. I will start testing the version from tomorrow and will get back to you if necessary.

Cheers P

pafade89 commented 7 months ago

@crycode-de

Yesterday, my internet briefly went down, and I only got this warning:

Screenshot_2023-11-26-08-31-36-498_com.android.chrome-edit.jpg

No more spam. Thanks for the quick fix!

crycode-de commented 7 months ago

@pafade89 Thank you for your reply!

v2.2.0 will be in the stable repo soon. 🙂