IcingaDB 'max_allowed_packet' exceeded

Hello

Since the update to IcingaDB v1.2.1, we are experiencing Daemon failures in the IcingaDB every 5 minutes.

Dec 22 10:13:58 skinner2.backbone.admin icingadb[1507116]: Error 1105 (HY000): Parameter of prepared statement which is set through mysql_send_long_data() is longer than 'max_allowed_packet' bytes
                                                           can't perform "INSERT INTO \"state_history\" (\"state_type\", \"hard_state\", \"previous_soft_state\", \"check_attempt\", \"soft_state\", \"long_output\", \"object_type\", \"host_id\", \"check_source\", \"endpoint_id\", \"service_id\", \"event_time\", \"previous_hard_state\", \"output\", \"max_check_attempts\", \"id\", \"scheduling_source\", \"environment_id\") VALUES (:state_type,:hard_state,:previous_soft_state,:check_attempt,:soft_state,:long_output,:object_type,:host_id,:check_source,:endpoint_id,:service_id,:event_time,:previous_hard_state,:output,:max_check_attempts,:id,:scheduling_source,:environment_id) ON DUPLICATE KEY UPDATE \"id\" = VALUES(\"id\")"
                                                           github.com/icinga/icinga-go-library/database.CantPerformQuery
                                                                   github.com/icinga/icinga-go-library@v0.4.0/database/utils.go:16
                                                           github.com/icinga/icinga-go-library/database.(*DB).NamedBulkExec.func1.(*DB).NamedBulkExec.func1.1.2.1
                                                                   github.com/icinga/icinga-go-library@v0.4.0/database/db.go:535
                                                           github.com/icinga/icinga-go-library/retry.WithBackoff
                                                                   github.com/icinga/icinga-go-library@v0.4.0/retry/retry.go:65
                                                           github.com/icinga/icinga-go-library/database.(*DB).NamedBulkExec.func1.(*DB).NamedBulkExec.func1.1.2
                                                                   github.com/icinga/icinga-go-library@v0.4.0/database/db.go:530
                                                           golang.org/x/sync/errgroup.(*Group).Go.func1
                                                                   golang.org/x/sync@v0.10.0/errgroup/errgroup.go:78
                                                           runtime.goexit
                                                                   runtime/asm_amd64.s:1700
                                                           retry deadline exceeded
                                                           github.com/icinga/icinga-go-library/retry.WithBackoff
                                                                   github.com/icinga/icinga-go-library@v0.4.0/retry/retry.go:100
                                                           github.com/icinga/icinga-go-library/database.(*DB).NamedBulkExec.func1.(*DB).NamedBulkExec.func1.1.2
                                                                   github.com/icinga/icinga-go-library@v0.4.0/database/db.go:530
                                                           golang.org/x/sync/errgroup.(*Group).Go.func1
                                                                   golang.org/x/sync@v0.10.0/errgroup/errgroup.go:78
                                                           runtime.goexit
                                                                   runtime/asm_amd64.s:1700

On our server side, we already set ‘max_allowed_packet’ to 64MB and on the client side, we are at 64MB as well.

  • Icinga DB Web version: 2.12.2
  • Icinga Web 2 version: 1.1.13
  • Web browser: Firefox 128.0.5esr
  • Icinga 2 version: r2.14.3-1
  • Icinga DB version: v1.2.1
  • PHP version used: 8.1.2-1ubuntu2.20
  • Server operating system and version: Ubuntu 22.04.5 LTS

How shall we proceed?

FTR: our icingadb-redis-server had a memory usage of around ~300MB.

root@skinner1:~# redis-cli -p 6380 info | grep used_memory_human
used_memory_human:304.15M

After flushing out the Redis Store, our system no longer crashes.

redis-cli -p 6380 flushall

I’m assuming that during the upgrade the Redis Server was running on, while the IcingaDB was down and stored up too much data in the “buffer” and IcingaDB was no longer capable of syncing this data.

However, issue resolved.

Thanks for both reporting and solving this issue.
As a crash is undesired, I have taken another look at this issue.

Icinga DB always sets max_allowed_packet to 64 MiB, as this is what the underlying MySQL client library does, https://github.com/go-sql-driver/mysql/blob/4395c45fd098a81c5251667cda111f94c693ab14/dsn.go#L88. However, if I read the following MySQL bug - https://bugs.mysql.com/bug.php?id=83958 - correctly, prepared statements may easily exceed this limit, as it seems to be the case for your crash.

Due to the temporary unavailability of Icinga DB, the backlog stored in the Redis outgrew this limit, resulting in a later crash. I created an issue for this, as I think we should be able to mitigate this bug within our code base.

Hello @apenning, we are now experiencing the same issue as from 2 years ago. Flushing the Redis DB is no longer working as expected. AFAICS there is no solution for this bug currently? Whatever shall we do?

I am sorry hearing that, @meuthak. To allow pinning this down, please share a few information about your setup with us: the log showing the crash, which Icinga components and DBMS you are using and in which version.

Could you elaborate? How are you flushing Redis and what does not work as expected anymore? Is it filling up again and crashes after some time?

We are having a problem, that some history sync cannot be written into icingadb.

Error 1105 (HY000): Parameter of prepared statement which is set
through mysql_send_long_data() is longer than 'max_allowed_packet' bytes"

When we look at the Redis DB, it is quite large:

redis-cli -p 6380 info | grep used_memory_human
used_memory_human:304.15M

After flushing it, icingadb can start up again and the sync is no longer an issue.

redis-cli -p 6380 flushall

We are using these icinga components:

icinga-l10n/icinga-jammy,now 1.4.0-1+ubuntu22.04 all [installed,automatic]
icinga-php-library/icinga-jammy,now 0.15.2-1+ubuntu22.04 all [installed]
icinga-php-thirdparty/icinga-jammy,now 0.12.1-1+ubuntu22.04 all [installed]
icinga2/icinga-jammy,now 2.16.5-1+ubuntu22.04 amd64 [installed]
icinga2-bin/icinga-jammy,now 2.16.5-1+ubuntu22.04 amd64 [installed]
icinga2-common/icinga-jammy,now 2.16.5-1+ubuntu22.04 all [installed]
icingacli/icinga-jammy,now 2.12.7-1+ubuntu22.04 all [installed]
icingadb/icinga-jammy,now 1.5.1-8+ubuntu22.04 amd64 [installed]
icingadb-redis/icinga-jammy,now 8.2.9-1+ubuntu22.04 amd64 [installed]
icingadb-web/icinga-jammy,now 1.1.4-1+ubuntu22.04 all [installed]
icingaweb2/icinga-jammy,now 2.12.7-1+ubuntu22.04 all [installed]
icingaweb2-common/icinga-jammy,now 2.12.7-1+ubuntu22.04 all [installed]
icingaweb2-module-monitoring/icinga-jammy,now 2.12.6-2+ubuntu22.04 all [installed,automatic]
monitoring-plugins/jammy,jammy,now 2.3.1-1ubuntu4 all [installed]
monitoring-plugins-basic/jammy,now 2.3.1-1ubuntu4 amd64 [installed]
monitoring-plugins-common/jammy,now 2.3.1-1ubuntu4 amd64 [installed]
monitoring-plugins-standard/jammy,now 2.3.1-1ubuntu4 amd64 [installed]
php-icinga/icinga-jammy,now 2.12.7-1+ubuntu22.04 all [installed]

We are aware, that icingadb-web is OutOfDate. However i do no think the issue lies there.

For our DB we are using a Galera Cluster, which is proxied through a Proxysql server. Do you need the versions of these?

Log message:

Sep  1 09:40:15 skinner1 icingadb[2362625]: database: Can't execute query. Retrying#011error="can't perform \"INSERT INTO \\\"service_state\\\" (\\\"service_id\\\", \\\"is_flapping\\\", \\\"
last_update\\\", \\\"severity\\\", \\\"normalized_performance_data\\\", \\\"previous_soft_state\\\", \\\"check_attempt\\\", \\\"is_handled\\\", \\\"state_type\\\", \\\"is_acknowledged\\\", \
\\"long_output\\\", \\\"check_timeout\\\", \\\"last_state_change\\\", \\\"check_commandline\\\", \\\"scheduling_source\\\", \\\"next_update\\\", \\\"last_comment_id\\\", \\\"execution_time\\
\", \\\"is_reachable\\\", \\\"performance_data\\\", \\\"is_problem\\\", \\\"latency\\\", \\\"is_sticky_acknowledgement\\\", \\\"host_id\\\", \\\"affects_children\\\", \\\"check_source\\\", \
\\"in_downtime\\\", \\\"output\\\", \\\"previous_hard_state\\\", \\\"acknowledgement_comment_id\\\", \\\"next_check\\\", \\\"properties_checksum\\\", \\\"environment_id\\\", \\\"id\\\", \\\"
hard_state\\\", \\\"soft_state\\\") VALUES (:service_id,:is_flapping,:last_update,:severity,:normalized_performance_data,:previous_soft_state,:check_attempt,:is_handled,:state_type,:is_ackno
wledged,:long_output,:check_timeout,:last_state_change,:check_commandline,:scheduling_source,:next_update,:last_comment_id,:execution_time,:is_reachable,:performance_data,:is_problem,:latenc
y,:is_sticky_acknowledgement,:host_id,:affects_children,:check_source,:in_downtime,:output,:previous_hard_state,:acknowledgement_comment_id,:next_check,:properties_checksum,:environment_id,:
id,:hard_state,:soft_state) ON DUPLICATE KEY UPDATE \\\"service_id\\\" = VALUES(\\\"service_id\\\"),\\\"is_flapping\\\" = VALUES(\\\"is_flapping\\\"),\\\"last_update\\\" = VALUES(\\\"last_up
date\\\"),\\\"severity\\\" = VALUES(\\\"severity\\\"),\\\"normalized_performance_data\\\" = VALUES(\\\"normalized_performance_data\\\"),\\\"previous_soft_state\\\" = VALUES(\\\"previous_soft
_state\\\"),\\\"check_attempt\\\" = VALUES(\\\"check_attempt\\\"),\\\"is_handled\\\" = VALUES(\\\"is_handled\\\"),\\\"state_type\\\" = VALUES(\\\"state_type\\\"),\\\"is_acknowledged\\\" = VA
LUES(\\\"is_acknowledged\\\"),\\\"long_output\\\" = VALUES(\\\"long_output\\\"),\\\"check_timeout\\\" = VALUES(\\\"check_timeout\\\"),\\\"last_state_change\\\" = VALUES(\\\"last_state_change
\\\"),\\\"check_commandline\\\" = VALUES(\\\"check_commandline\\\"),\\\"scheduling_source\\\" = VALUES(\\\"scheduling_source\\\"),\\\"next_update\\\" = VALUES(\\\"next_update\\\"),\\\"last_c
omment_id\\\" = VALUES(\\\"last_comment_id\\\"),\\\"execution_time\\\" = VALUES(\\\"execution_time\\\"),\\\"is_reachable\\\" = VALUES(\\\"is_reachable\\\"),\\\"performance_data\\\" = VALUES(
\\\"performance_data\\\"),\\\"is_problem\\\" = VALUES(\\\"is_problem\\\"),\\\"latency\\\" = VALUES(\\\"latency\\\"),\\\"is_sticky_acknowledgement\\\" = VALUES(\\\"is_sticky_acknowledgement\\
\"),\\\"host_id\\\" = VALUES(\\\"host_id\\\"),\\\"affects_children\\\" = VALUES(\\\"affects_children\\\"),\\\"check_source\\\" = VALUES(\\\"check_source\\\"),\\\"in_downtime\\\" = VALUES(\\\
"in_downtime\\\"),\\\"output\\\" = VALUES(\\\"output\\\"),\\\"previous_hard_state\\\" = VALUES(\\\"previous_hard_state\\\"),\\\"acknowledgement_comment_id\\\" = VALUES(\\\"acknowledgement_co
mment_id\\\"),\\\"next_check\\\" = VALUES(\\\"next_check\\\"),\\\"properties_checksum\\\" = VALUES(\\\"properties_checksum\\\"),\\\"environment_id\\\" = VALUES(\\\"environment_id\\\"),\\\"id
\\\" = VALUES(\\\"id\\\"),\\\"hard_state\\\" = VALUES(\\\"hard_state\\\"),\\\"soft_state\\\" = VALUES(\\\"soft_state\\\")\": Error 1105 (HY000): Parameter of prepared statement which is set 
through mysql_send_long_data() is longer than 'max_allowed_packet' bytes"
Sep  1 09:40:25 skinner1 icingadb[2362625]: config-sync: Aborted initial state sync after 5m2.602835192s
Sep  1 09:40:25 skinner1 icingadb[2362625]: Error 1105 (HY000): Parameter of prepared statement which is set through mysql_send_long_data() is longer than 'max_allowed_packet' bytes#012can't perform "INSERT INTO \"service_state\" (\"service_id\", \"is_flapping\", \"last_update\", \"severity\", \"normalized_performance_data\", \"previous_soft_state\", \"check_attempt\", \"is_handled\", \"state_type\", \"is_acknowledged\", \"long_output\", \"check_timeout\", \"last_state_change\", \"check_commandline\", \"scheduling_source\", \"next_update\", \"last_comment_id\", \"execution_time\", \"is_reachable\", \"performance_data\", \"is_problem\", \"latency\", \"is_sticky_acknowledgement\", \"host_id\", \"affects_children\", \"check_source\", \"in_downtime\", \"output\", \"previous_hard_state\", \"acknowledgement_comment_id\", \"next_check\", \"properties_checksum\", \"environment_id\", \"id\", \"hard_state\", \"soft_state\") VALUES (:service_id,:is_flapping,:last_update,:severity,:normalized_performance_data,:previous_soft_state,:check_attempt,:is_handled,:state_type,:is_acknowledged,:long_output,:check_timeout,:last_state_change,:check_commandline,:scheduling_source,:next_update,:last_comment_id,:execution_time,:is_reachable,:performance_data,:is_problem,:latency,:is_sticky_acknowledgement,:host_id,:affects_children,:check_source,:in_downtime,:output,:previous_hard_state,:acknowledgement_comment_id,:next_check,:properties_checksum,:environment_id,:id,:hard_state,:soft_state) ON DUPLICATE KEY UPDATE \"service_id\" = VALUES(\"service_id\"),\"is_flapping\" = VALUES(\"is_flapping\"),\"last_update\" = VALUES(\"last_update\"),\"severity\" = VALUES(\"severity\"),\"normalized_performance_data\" = VALUES(\"normalized_performance_data\"),\"previous_soft_state\" = VALUES(\"previous_soft_state\"),\"check_attempt\" = VALUES(\"check_attempt\"),\"is_handled\" = VALUES(\"is_handled\"),\"state_type\" = VALUES(\"state_type\"),\"is_acknowledged\" = VALUES(\"is_acknowledged\"),\"long_output\" = VALUES(\"long_output\"),\"check_timeout\" = VALUES(\"check_timeout\"),\"last_state_change\" = VALUES(\"last_state_change\"),\"check_commandline\" = VALUES(\"check_commandline\"),\"scheduling_source\" = VALUES(\"scheduling_source\"),\"next_update\" = VALUES(\"next_update\"),\"last_comment_id\" = VALUES(\"last_comment_id\"),\"execution_time\" = VALUES(\"execution_time\"),\"is_reachable\" = VALUES(\"is_reachable\"),\"performance_data\" = VALUES(\"performance_data\"),\"is_problem\" = VALUES(\"is_problem\"),\"latency\" = VALUES(\"latency\"),\"is_sticky_acknowledgement\" = VALUES(\"is_sticky_acknowledgement\"),\"host_id\" = VALUES(\"host_id\"),\"affects_children\" = VALUES(\"affects_children\"),\"check_source\" = VALUES(\"check_source\"),\"in_downtime\" = VALUES(\"in_downtime\"),\"output\" = VALUES(\"output\"),\"previous_hard_state\" = VALUES(\"previous_hard_state\"),\"acknowledgement_comment_id\" = VALUES(\"acknowledgement_comment_id\"),\"next_check\" = VALUES(\"next_check\"),\"properties_checksum\" = VALUES(\"properties_checksum\"),\"environment_id\" = VALUES(\"environment_id\"),\"id\" = VALUES(\"id\"),\"hard_state\" = VALUES(\"hard_state\"),\"soft_state\" = VALUES(\"soft_state\")"#012github.com/icinga/icinga-go-library/database.CantPerformQuery#012#011github.com/icinga/icinga-go-library@v0.8.2/database/utils.go:19#012github.com/icinga/icinga-go-library/database.(*DB).NamedBulkExec.func1.1.1.1#012#011github.com/icinga/icinga-go-library@v0.8.2/database/db.go:535#012github.com/icinga/icinga-go-library/retry.WithBackoff#012#011github.com/icinga/icinga-go-library@v0.8.2/retry/retry.go:65#012github.com/icinga/icinga-go-library/database.(*DB).NamedBulkExec.func1.1.1#012#011github.com/icinga/icinga-go-library@v0.8.2/database/db.go:530#012golang.org/x/sync/errgroup.(*Group).Go.func1#012#011golang.org/x/sync@v0.19.0/errgroup/errgroup.go:93#012runtime.goexit#012#011runtime/asm_amd64.s:1264#012retry deadline exceeded#012github.com/icinga/icinga-go-library/retry.WithBackoff#012#011github.com/icinga/icinga-go-library@v0.8.2/retry/retry.go:100#012github.com/icinga/icinga-go-library/database.(*DB).NamedBulkExec.func1.1.1#012#011github.com/icinga/icinga-go-library@v0.8.2/database/db.go:530#012golang.org/x/sync/errgroup.(*Group).Go.func1#012#011golang.org/x/sync@v0.19.0/errgroup/errgroup.go:93#012runtime.goexit#012#011runtime/asm_amd64.s:1264

We found out, that this is due to a check result being around 100 MB. The question is now, do we have to ensure that no result like this is possible across all check scripts, or are we missing a dial / switch somewhere?

Thanks for your detailed answer and pinning this down to an huge check result output. Honestly, even a two digit MB-check output is quite out of scope. Would it be possible to reduce the output?

just some information if you run into another problem

be aware that your packages are not the latest.
This is caused by the fact that icinga only supports the latest ubuntu LTS completely:

  • The latest version of each component receives full updates (new features, bug fixes, and security fixes).
  • The previous version of each component receives security updates only.
  • Older versions are no longer maintained.
    https://icinga.com/products/product-support-lifecycle/

your version of icingadb-web is 1.1.4 vs:

currently ubuntu 24.04 packages are still up to date

Hello

@apenning it certainly is possible to reduce output size in this check script. We are just wondering if we have to ensure that no result bigger than the max_allowed_packet is ever created, or if there is somehow an auto truncate or something. Because not all our scripts are on a shared codebase, and maybe we are missing one which could resurface this problem again.

@moreamazingnick yeah, we are running a bit behind on upgrading all our servers, it’s in the pipeline, we haven’t got around it just yet.

Thanks for your answers :grin:

@meuthak btw, i am curious. What kind of a check are you running that returns such a large plugin output?

It’s a Firewall Block Check, which just returns a condensed list of blocks in a timerange.

Large amount of blocks = Large Check Output.

The max_allowed_packet is MySQL’s upper limit and you cannot exceed it. Of course, you can try to tweak this setting on your machines, but I am unsure how well this will play out. Please note that replicating huge columns will get expensive.

Further reading: https://dev.mysql.com/doc/refman/8.4/en/replication-features-max-allowed-packet.html

Again, I would recommend checking your check plugins to ensure that the output is reasonable short or, at least, does not goes in the MBs. Icinga DB Web also truncates the output to ensure that the browser, or at least the tab, does not crash.

For future reference: This can be configured and behaves as documented in Configuration - Icinga DB Web

plugin_output_character_limit defaults to 10000. There are sometimes good reasons to change it, some checks return valid HTML to the plugin output, which actually gets rendered then. And for this it might make sense to increase that value.

Clean summary of this topic:

  • During sync from icingadb-redis into configured DB backend in icingadb, a crash CAN occur, when a statement or query exceeds the max_allowed_packet option from MySQL.
    • In my case, both times, icingadb had this error message:
      Error 1105 (HY000): Parameter of prepared statement which is set
      through mysql_send_long_data() is longer than 'max_allowed_packet' bytes"
  • The query is normally retried a few times, before the crash occurs. Good indicator for an issue of this Redis to DB sync, is the Redis DB size on your Icinga Node.
    • redis-cli -p 6380 info | grep used_memory_human
      
    • To just get rid of the large data, which can not be synced, flush the Redis DB on your Icinga Node. This will cause a few missed events, because Icinga DB missed to sync them.
      redis-cli -p 6380 flushall

  • To prevent this, make sure your plugin / check output are limited in size. There is no default way, to truncate or abbreviate a check result by icinga2.
    • Icinga DB Web truncates the output, but only when displaying on Icinga Web. Data is already stored in the Database at this moment.

I will remark this as the solution and close this discussion. Thank you for your answers.