[ZBX-19961] server crash: something impossible just happened in misc.c,deserialize_variant Created: 2021 Sep 15  Updated: 2024 Apr 10  Resolved: 2022 Jan 25

Status: Closed
Project: ZABBIX BUGS AND ISSUES
Component/s: Server (S)
Affects Version/s: 5.4.3, 6.0.0beta1
Fix Version/s: 5.4.10rc1, 6.0.0beta3, 6.0 (plan)

Type: Problem report Priority: Trivial
Reporter: Kevin Daudt Assignee: Andris Zeila
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File ZBX-19961-LLD-patch.diff     HTML File all-cases     File debug_5.4.5.patch     File item_trigger_link2.diff     File zabbix_crash_2021-09-14.log     File zabbix_server.objdump-1.xz     File zabbix_server_5.4.3.objdump.gz    
Issue Links:
Duplicate
is duplicated by ZBX-20649 Repeated crashes in History Syncer Closed
Team: Team A
Sprint: Sprint 84 (Jan 2022)
Story Points: 1

 Description   

Our zabbix server crashed, and got stuck in an endless loop:

zabbix_server [1950]: ERROR [file and function: <misc.c,deserialize_variant>, revision:68dc2b05cb, line:138] Something impossible has just happened.
  1950:20210914:184118.946 === Backtrace: ===
  1950:20210914:184118.947 14: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](zbx_backtrace+0x52) [0x55f65d5097d2]
  1950:20210914:184118.947 13: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](+0x22a832) [0x55f65d4f8832]
  1950:20210914:184118.947 12: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](zbx_eval_deserialize+0x17f) [0x55f65d4f8d00]
  1950:20210914:184118.947 11: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](zbx_eval_deserialize_dyn+0x67) [0x55f65d4f9c33]
  1950:20210914:184118.947 10: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](prepare_triggers+0x5a) [0x55f65d4dc1d5]
  1950:20210914:184118.947 9: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](+0x1b0825) [0x55f65d47e825]
  1950:20210914:184118.947 8: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](+0x1b44c5) [0x55f65d4824c5]
  1950:20210914:184118.947 7: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](zbx_sync_history_cache+0x8b) [0x55f65d483021]
  1950:20210914:184118.947 6: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](dbsyncer_thread+0x236) [0x55f65d338b2f]
  1950:20210914:184118.947 5: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](zbx_thread_start+0x3b) [0x55f65d51ad17]
  1950:20210914:184118.947 4: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](MAIN_ZABBIX_ENTRY+0xe4b) [0x55f65d325a9d]
  1950:20210914:184118.947 3: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](daemon_start+0x303) [0x55f65d509314]
  1950:20210914:184118.947 2: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](main+0x309) [0x55f65d324b34]
  1950:20210914:184118.947 1: /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3) [0x7fc7dcac40b3]
  1950:20210914:184118.947 0: /usr/sbin/zabbix_server: history syncer #8 [processed 0 values, 0 triggers in 0.000042 sec, syncing history](_start+0x2e) [0x55f65d32394e]
[..]
   622:20210914:184119.008 One child process died (PID:1950,exitcode/signal:1). Exiting ...
   622:20210914:184119.726 syncing history data...
   622:20210914:184119.785 syncing history data... 88.565022%
   622:20210914:184119.785 syncing history data... 88.565022%
   622:20210914:184119.785 syncing history data... 88.565022%
   622:20210914:184119.785 syncing history data... 88.565022%
  *endlessly repeating*

We had to manually stop the server (on stuck process) and restart it.

The relevant part of the logfile and the objdump have been attached.

 Comments   
Comment by Vladislavs Sokurenko [ 2021 Oct 01 ]

Could you please show output of the following command:

show create table triggers;
Comment by Kevin Daudt [ 2021 Oct 01 ] 
CREATE TABLE `triggers` (
  `triggerid` bigint(20) unsigned NOT NULL,
  `expression` varchar(2048) COLLATE utf8_bin NOT NULL DEFAULT '',
  `description` varchar(255) COLLATE utf8_bin NOT NULL DEFAULT '',
  `url` varchar(255) COLLATE utf8_bin NOT NULL DEFAULT '',
  `status` int(11) NOT NULL DEFAULT '0',
  `value` int(11) NOT NULL DEFAULT '0',
  `priority` int(11) NOT NULL DEFAULT '0',
  `lastchange` int(11) NOT NULL DEFAULT '0',
  `comments` text COLLATE utf8_bin NOT NULL,
  `error` varchar(2048) COLLATE utf8_bin NOT NULL DEFAULT '',
  `templateid` bigint(20) unsigned DEFAULT NULL,
  `type` int(11) NOT NULL DEFAULT '0',
  `state` int(11) NOT NULL DEFAULT '0',
  `flags` int(11) NOT NULL DEFAULT '0',
  `recovery_mode` int(11) NOT NULL DEFAULT '0',
  `recovery_expression` varchar(2048) COLLATE utf8_bin NOT NULL DEFAULT '',
  `correlation_mode` int(11) NOT NULL DEFAULT '0',
  `correlation_tag` varchar(255) COLLATE utf8_bin NOT NULL DEFAULT '',
  `manual_close` int(11) NOT NULL DEFAULT '0',
  `opdata` varchar(255) COLLATE utf8_bin NOT NULL DEFAULT '',
  `discover` int(11) NOT NULL DEFAULT '0',
  `event_name` varchar(2048) COLLATE utf8_bin NOT NULL DEFAULT '',
  `uuid` varchar(32) COLLATE utf8_bin NOT NULL DEFAULT '',
  PRIMARY KEY (`triggerid`),
  KEY `triggers_1` (`status`),
  KEY `c_triggers_1` (`templateid`),
  KEY `triggers_3` (`templateid`),
  KEY `triggers_2` (`value`,`lastchange`),
  CONSTRAINT `c_triggers_1` FOREIGN KEY (`templateid`) REFERENCES `triggers` (`triggerid`) ON DELETE CASCADE
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin
Comment by Vladislavs Sokurenko [ 2021 Oct 01 ]

Is it reoccurring issue or happened only one time ?

Comment by Kevin Daudt [ 2021 Oct 01 ]

So far, it happened only once.

Comment by Vladislavs Sokurenko [ 2021 Dec 17 ]

There is suspicion that it is caused by frequent trigger function updating when using LLD and frequent trigger deletion.
Please try following query:

select count(*) from triggers where error like 'Cannot evaluate expression: cannot parse trigger expression%';
Comment by Vladislavs Sokurenko [ 2021 Dec 17 ]

This issue happens when trying to retrieve triggers for item but triggers appear to be deleted, could either try increasing log level for affected process and seeing what item is processed before this should never happen or we could provide patch that will include this information when this should never happen occurs

Comment by Vladislavs Sokurenko [ 2022 Jan 13 ]

Fixed in:

Comment by Andris Zeila [ 2022 Jan 24 ]

Released ZBX-19961 in:

  • pre-5.4.10rc1 2834919b74
  • pre-6.0.0beta3 6d7176f480
Generated at Mon Apr 07 19:21:04 EEST 2025 using Jira 9.12.4#9120004-sha1:625303b708afdb767e17cb2838290c41888e9ff0.