Skip to content

Don't spam log messages on backend connection interrupt #515

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
wants to merge 1 commit into from
Closed

Don't spam log messages on backend connection interrupt #515

wants to merge 1 commit into from

Conversation

Al2Klimov
Copy link
Member

ex. at debug log level.

@cla-bot cla-bot bot added the cla/signed label Jul 20, 2022
@Al2Klimov
Copy link
Member Author

Redis

Before

2022-07-20T18:09:51.842+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:51.844+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:51.942+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:51.943+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:51.970+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:51.972+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:51.985+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:52.000+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:52.012+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:52.017+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:52.051+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:52.062+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:52.126+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:52.232+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:52.817+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:53.817+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:54.817+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:55.817+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:56.817+0200	INFO	history-sync	Synced 4 state history items
2022-07-20T18:09:56.817+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:57.816+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:09:57.940+0200	INFO	runtime-updates	Upserted 3 ServiceState items
2022-07-20T18:09:58.646+0200	INFO	redis	Reconnected to Redis	{"after": "6.629650002s", "attempts": 19}
2022-07-20T18:09:58.701+0200	INFO	redis	Reconnected to Redis	{"after": "6.68938941s", "attempts": 20}
2022-07-20T18:09:58.750+0200	INFO	redis	Reconnected to Redis	{"after": "6.90595378s", "attempts": 20}
2022-07-20T18:09:58.765+0200	INFO	redis	Reconnected to Redis	{"after": "6.793017568s", "attempts": 19}
2022-07-20T18:09:58.828+0200	INFO	redis	Reconnected to Redis	{"after": "6.828404053s", "attempts": 20}
2022-07-20T18:09:58.844+0200	INFO	redis	Reconnected to Redis	{"after": "6.87424164s", "attempts": 20}
2022-07-20T18:09:58.930+0200	INFO	redis	Reconnected to Redis	{"after": "6.945311563s", "attempts": 19}
2022-07-20T18:09:59.000+0200	INFO	redis	Reconnected to Redis	{"after": "6.938575345s", "attempts": 20}
2022-07-20T18:09:59.080+0200	INFO	redis	Reconnected to Redis	{"after": "6.955273047s", "attempts": 19}
2022-07-20T18:09:59.181+0200	INFO	redis	Reconnected to Redis	{"after": "6.950314086s", "attempts": 20}
2022-07-20T18:09:59.353+0200	INFO	redis	Reconnected to Redis	{"after": "7.302972238s", "attempts": 19}
2022-07-20T18:09:59.365+0200	INFO	redis	Reconnected to Redis	{"after": "7.422713103s", "attempts": 20}
2022-07-20T18:09:59.391+0200	INFO	redis	Reconnected to Redis	{"after": "7.449747129s", "attempts": 21}

After

2022-07-20T18:11:58.543+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:11:59.247+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:12:58.129+0200	WARN	heartbeat	Lost Icinga heartbeat	{"timeout": "1m0s"}
2022-07-20T18:12:58.129+0200	ERROR	high-availability	Lost heartbeat
2022-07-20T18:12:58.129+0200	WARN	icingadb	Handing over
2022-07-20T18:13:00.131+0200	WARN	redis	Can't connect to Redis. Retrying{"error": "dial tcp 127.0.0.1:6379: connect: connection refused"}
2022-07-20T18:13:09.355+0200	INFO	redis	Reconnected to Redis	{"after": "225.42803ms", "attempts": 9}
2022-07-20T18:13:09.460+0200	INFO	redis	Reconnected to Redis	{"after": "1m10.914749522s", "attempts": 106}

DB

Before

2022-07-20T18:58:26.890+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:27.545+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:27.733+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:27.733+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:31.584+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:31.584+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:32.612+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:32.612+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:34.670+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:34.670+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:34.888+0200	INFO	history-sync	Synced 533 state history items
2022-07-20T18:58:34.888+0200	INFO	history-sync	Synced 508 notification history items
2022-07-20T18:58:35.732+0200	INFO	runtime-updates	Upserted 2 HostState items
2022-07-20T18:58:40.833+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:40.833+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T18:58:42.885+0200	WARN	database	Can't connect to database. Retrying	{"error": "driver: bad connection"}
2022-07-20T18:58:42.885+0200	WARN	database	Can't connect to database. Retrying	{"error": "driver: bad connection"}
2022-07-20T18:58:43.166+0200	INFO	database	Reconnected to database{"after": "282.517574ms", "attempts": 3}
2022-07-20T18:58:43.182+0200	INFO	database	Reconnected to database{"after": "299.08291ms", "attempts": 3}
2022-07-20T18:58:43.831+0200	INFO	database	Reconnected to database{"after": "11.219157082s", "attempts": 8}
2022-07-20T18:58:43.932+0200	INFO	database	Reconnected to database{"after": "3.100050762s", "attempts": 6}
2022-07-20T18:58:43.977+0200	INFO	database	Reconnected to database{"after": "12.393890199s", "attempts": 8}
2022-07-20T18:58:44.330+0200	INFO	database	Reconnected to database{"after": "3.497544757s", "attempts": 6}
2022-07-20T18:58:44.491+0200	INFO	database	Reconnected to database{"after": "12.907883083s", "attempts": 8}
2022-07-20T18:58:46.062+0200	INFO	database	Reconnected to database{"after": "11.392859139s", "attempts": 8}
2022-07-20T18:58:46.179+0200	INFO	database	Reconnected to database{"after": "13.567149382s", "attempts": 8}
2022-07-20T18:58:47.070+0200	INFO	database	Reconnected to database{"after": "12.401063412s", "attempts": 8}
2022-07-20T18:58:51.997+0200	INFO	database	Reconnected to database{"after": "24.263937809s", "attempts": 9}
2022-07-20T18:58:52.274+0200	INFO	database	Reconnected to database{"after": "24.729871372s", "attempts": 9}
2022-07-20T18:58:52.946+0200	INFO	database	Reconnected to database{"after": "25.213256658s", "attempts": 9}
2022-07-20T18:58:54.888+0200	INFO	history-sync	Synced 13 state history items
2022-07-20T18:58:54.888+0200	INFO	history-sync	Synced 13 notification history items
2022-07-20T18:58:55.733+0200	INFO	runtime-updates	Upserted 14 HostState items
2022-07-20T18:58:57.255+0200	INFO	database	Reconnected to database{"after": "30.365984794s", "attempts": 9}

After

2022-07-20T18:59:50.171+0200	WARN	database	Can't connect to database. Retrying	{"error": "driver: bad connection"}
2022-07-20T18:59:50.636+0200	WARN	database	Can't connect to database. Retrying	{"error": "dial tcp 127.0.0.1:6833: connect: connection refused"}
2022-07-20T19:00:01.634+0200	INFO	history-sync	Synced 13 notification history items
2022-07-20T19:00:01.635+0200	INFO	history-sync	Synced 13 state history items
2022-07-20T19:00:01.951+0200	INFO	runtime-updates	Upserted 4 HostState items
2022-07-20T19:00:49.077+0200	INFO	database	Reconnected to database{"after": "7.196378845s", "attempts": 7}
2022-07-20T19:00:49.367+0200	INFO	database	Reconnected to database{"after": "50.003121044s", "attempts": 10}

@oxzi
Copy link
Member

oxzi commented May 13, 2025

In the meantime, the relevant code was moved to the IGL and has an exponential jitter within the retry.WIthBackoff function. Thanks anyways!

@oxzi oxzi closed this May 13, 2025
@oxzi oxzi deleted the conn-lost-spam branch May 13, 2025 07:50
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
cla/signed
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
2 participants
@Al2Klimov @oxzi