[ZBX-9959] Message: zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened. Created: 2015 Oct 15  Updated: 2020 Apr 17  Resolved: 2015 Oct 29

Status: Closed
Project: ZABBIX BUGS AND ISSUES
Component/s: Proxy (P), Server (S)
Affects Version/s: 2.4.6
Fix Version/s: 2.4.7rc1, 3.0.0alpha4

Type: Incident report Priority: Minor
Reporter: Philippe Assignee: Unassigned
Resolution: Fixed Votes: 0
Labels: error, json
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   

My Zabbix server is running at the 2.4.3 level.
past few days I have the following kind of messages in zabbix_server.log file:

zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25642]: ERROR [file:json.c,line:611] Something impossible has just happened.

I upgraded the zabbix client to V 2.4.3 (same of the server) for my Linux clients and it seems work well.
I tried to increase the trapper loglevel without more information, or I can't understand it.
I think there is something wrong but where and what ?
How to know what are the error data and where did they come from?

 Comments   
Comment by Aleksandrs Saveljevs [ 2015 Oct 15 ]

Could you please increase the logging level (either set DebugLevel=4 and restart the server or use "-R log_level_increase" at runtime) and show the JSON that the server receives?

Comment by Philippe [ 2015 Oct 15 ]

Here is a part of loglevel 4 log:

 26174:20151015:153650.959 End of get_hostid_by_host():SUCCEED
 26174:20151015:153650.959 query [txnlev:0] [select itemid from items where type=7 and flags<>2 and hostid=10484]
 26236:20151015:153650.960 trapper #98 [processing data]
 26174:20151015:153650.961 In substitute_key_macros() data:'agent.version'
 26174:20151015:153650.961 End of substitute_key_macros():SUCCEED data:'agent.version'
 26174:20151015:153650.961 In substitute_key_macros() data:'perf_counter[\Disque logique(_Total)\1482,10]'
 26174:20151015:153650.961 End of substitute_key_macros():SUCCEED data:'perf_counter[\Disque logique(_Total)\1482,10]'
 26174:20151015:153650.961 In substitute_key_macros() data:'perf_counter[\Disque logique(_Total)\1484,10]'
 26174:20151015:153650.961 End of substitute_key_macros():SUCCEED data:'perf_counter[\Disque logique(_Total)\1484,10]'
 26174:20151015:153650.961 In substitute_key_macros() data:'perf_counter[\Disque logique(_Total)\206,10]'
 26174:20151015:153650.961 End of substitute_key_macros():SUCCEED data:'perf_counter[\Disque logique(_Total)\206,10]'
 26174:20151015:153650.961 In substitute_key_macros() data:'perf_counter[\Disque logique(_Total)\218,10]'
 26236:20151015:153650.961 trapper got '{"request":"agent data","data":[{"host":"qavpl103104","key":"PC_Free","value":"45","clock":1444916205,"ns":871492412},{"host":"qavpl103104","key":"PC_RAM_Available","value":"77","clock":1444916205,"ns":877895040},{"host":"qavpl103104","key":"PC_Swap","value":"0","clock":1444916205,"ns":888034757},{"host":"qavpl103104","key":"PC_Systprog","value":"22","clock":1444916206,"ns":898511933},{"host":"qavpl103104","key":"proc.num[ntpd]","value":"1","clock":1444916206,"ns":915258228},{"host":"qavpl103104","key":"proc.num[,,run]","value":"1","clock":1444916206,"ns":928885244},{"host":"qavpl103104","key":"proc.num[sshd]","value":"1","clock":1444916206,"ns":945772683},{"host":"qavpl103104","key":"proc.num[,,,syslog]","value":"1","clock":1444916206,"ns":952327491},{"host":"qavpl103104","key":"system.cpu.load[,avg1]","value":"0.000000","clock":1444916206,"ns":952353397},{"host":"qavpl103104","key":"system.cpu.load[,avg15]","value":"0.000000","clock":1444916206,"ns":952370566},{"host":"qavpl103104","key":"system.cpu.load[,avg5]","value":"0.000000","clock":1444916206,"ns":952390297},{"host":"qavpl103104","key":"system.cpu.util[,idle,avg1]","value":"99.400100","clock":1444916206,"ns":952401003},{"host":"qavpl103104","key":"system.cpu.util[,iowait,avg1]","value":"0.016664","clock":1444916206,"ns":952406860},{"host":"qavpl103104","key":"system.cpu.util[,nice,avg1]","value":"0.000000","clock":1444916206,"ns":952411110},{"host":"qavpl103104","key":"system.cpu.util[,system,avg1]","value":"0.283286","clock":1444916206,"ns":952415428},{"host":"qavpl103104","key":"system.cpu.util[,user,avg1]","value":"0.283286","clock":1444916206,"ns":952420240},{"host":"qavpl103104","key":"system.users.num","value":"0","clock":1444916206,"ns":955983153}],"clock":1444916210,"ns":956649268}'
 26174:20151015:153650.961 End of substitute_key_macros():SUCCEED data:'perf_counter[\Disque logique(_Total)\218,10]'
 26236:20151015:153650.961 In recv_agenthistory()
 26174:20151015:153650.961 In substitute_key_macros() data:'perf_counter[\Interface réseau(*)\388,10]'
 26236:20151015:153650.962 In process_hist_data()
 26174:20151015:153650.962 End of substitute_key_macros():SUCCEED data:'perf_counter[\Interface réseau(*)\388,10]'
 26174:20151015:153650.962 In substitute_key_macros() data:'perf_counter[\Interface réseau(*)\542,10]'
 26174:20151015:153650.962 End of substitute_key_macros():SUCCEED data:'perf_counter[\Interface réseau(*)\542,10]'
 26174:20151015:153650.962 In substitute_key_macros() data:'perf_counter[\Interface réseau(*)\544,10]'
 26236:20151015:153650.962 In process_mass_data()
 26174:20151015:153650.962 End of substitute_key_macros():SUCCEED data:'perf_counter[\Interface réseau(*)\544,10]'
 26174:20151015:153650.962 In substitute_key_macros() data:'perf_counter["\Interface réseau(Intel[R] PRO_1000 MT Network Cnnection)\542",10]'
 26174:20151015:153650.962 End of substitute_key_macros():SUCCEED data:'perf_counter["\Interface réseau(Intel[R] PRO_1000 T Network Connection)\542",10]'
 26236:20151015:153650.962 End of process_mass_data()
 26174:20151015:153650.962 In substitute_key_macros() data:'perf_counter["\Interface réseau(Intel[R] PRO_1000 MT Network Cnnection)\544",10]'
 26174:20151015:153650.962 End of substitute_key_macros():SUCCEED data:'perf_counter["\Interface réseau(Intel[R] PRO_1000 T Network Connection)\544",10]'
 26236:20151015:153650.962 End of process_hist_data():SUCCEED
 26236:20151015:153650.962 In zbx_send_response()
 26174:20151015:153650.962 In substitute_key_macros() data:'perf_counter["\Interface réseau(Intel[R] PRO_1000 MT Network Cnnection)\Octets envoyés/s",10]'
 26236:20151015:153650.962 zbx_send_response() '{"response":"success","info":"processed: 17; failed: 0; total: 17; seconds spent: 0.000547"}'
 26174:20151015:153650.962 End of substitute_key_macros():SUCCEED data:'perf_counter["\Interface réseau(Intel[R] PRO_1000 T Network Connection)\Octets envoyés/s",10]'
 26174:20151015:153650.962 In substitute_key_macros() data:'perf_counter["\Interface réseau(Intel[R] PRO_1000 MT Network Cnnection)\Octets reçus/s",10]'
 26236:20151015:153650.962 End of zbx_send_response():SUCCEED
 26236:20151015:153650.962 End of recv_agenthistory()
 26174:20151015:153650.962 End of substitute_key_macros():SUCCEED data:'perf_counter["\Interface réseau(Intel[R] PRO_1000 T Network Connection)\Octets reçus/s",10]'
 26236:20151015:153650.962 trapper #98 [processed data in 0.002323 sec, waiting for connection]
 26174:20151015:153650.963 In substitute_key_macros() data:'perf_counter[\Mémoire\Lectures de pages/s,10]'
 26174:20151015:153650.963 End of substitute_key_macros():SUCCEED data:'perf_counter[\Mémoire\Lectures de pages/s,10]'
 26174:20151015:153650.963 In substitute_key_macros() data:'perf_counter[\Mémoire\Pages/s,10]'
 26174:20151015:153650.963 End of substitute_key_macros():SUCCEED data:'perf_counter[\Mémoire\Pages/s,10]'
 26174:20151015:153650.963 In substitute_key_macros() data:'perf_counter["\Processeur(_Total)\142",10]'
 26174:20151015:153650.963 End of substitute_key_macros():SUCCEED data:'perf_counter["\Processeur(_Total)\142",10]'
 26174:20151015:153650.963 In substitute_key_macros() data:'perf_counter["\Processeur(_Total)\144",10]'
 26174:20151015:153650.963 End of substitute_key_macros():SUCCEED data:'perf_counter["\Processeur(_Total)\144",10]'
 26174:20151015:153650.963 In substitute_key_macros() data:'perf_counter["\Processeur(_Total)\6",10]'
 26174:20151015:153650.963 End of substitute_key_macros():SUCCEED data:'perf_counter["\Processeur(_Total)\6",10]'
 26174:20151015:153650.963 In substitute_key_macros() data:'perf_counter["\Processeur(_Total)\698",10]'
 26174:20151015:153650.963 End of substitute_key_macros():SUCCEED data:'perf_counter["\Processeur(_Total)\698",10]'
 26174:20151015:153650.963 In substitute_key_macros() data:'perf_counter["\Système\Changements de contexte/s",10]'
 26174:20151015:153650.963 End of substitute_key_macros():SUCCEED data:'perf_counter["\Système\Changements de contexte/s",0]'
 26174:20151015:153650.963 In substitute_key_macros() data:'perf_counter["\Système\Longueur de la file du processeur",10]'
 26174:20151015:153650.963 End of substitute_key_macros():SUCCEED data:'perf_counter["\Système\Longueur de la file du procsseur",10]'
 26174:20151015:153650.964 In substitute_key_macros() data:'perf_counter[\TCPv4\642,10]'
 26174:20151015:153650.964 End of substitute_key_macros():SUCCEED data:'perf_counter[\TCPv4\642,10]'
 26174:20151015:153650.964 In substitute_key_macros() data:'perf_counter[\TCPv4\648,10]'
 26174:20151015:153650.964 End of substitute_key_macros():SUCCEED data:'perf_counter[\TCPv4\648,10]'
 26174:20151015:153650.964 In substitute_key_macros() data:'perf_counter[\TCPv4\650,10]'
 26174:20151015:153650.964 End of substitute_key_macros():SUCCEED data:'perf_counter[\TCPv4\650,10]'
 26174:20151015:153650.964 In substitute_key_macros() data:'service_state["Dhcp"]'
 26174:20151015:153650.964 End of substitute_key_macros():SUCCEED data:'service_state["Dhcp"]'
 26174:20151015:153650.964 In substitute_key_macros() data:'service_state["Dnscache"]'
 26174:20151015:153650.964 End of substitute_key_macros():SUCCEED data:'service_state["Dnscache"]'
 26174:20151015:153650.964 In substitute_key_macros() data:'service_state["EventSystem"]'
 26174:20151015:153650.964 End of substitute_key_macros():SUCCEED data:'service_state["EventSystem"]'
 26174:20151015:153650.964 In substitute_key_macros() data:'service_state["lanmanserver"]'
 26174:20151015:153650.964 End of substitute_key_macros():SUCCEED data:'service_state["lanmanserver"]'
 26174:20151015:153650.964 In substitute_key_macros() data:'service_state["nxlog"]'
 26174:20151015:153650.964 End of substitute_key_macros():SUCCEED data:'service_state["nxlog"]'
 26174:20151015:153650.965 In substitute_key_macros() data:'service_state["PolicyAgent"]'
 26174:20151015:153650.965 End of substitute_key_macros():SUCCEED data:'service_state["PolicyAgent"]'
 26174:20151015:153650.965 In substitute_key_macros() data:'service_state["RpcSs"]'
 26174:20151015:153650.965 End of substitute_key_macros():SUCCEED data:'service_state["RpcSs"]'
 26174:20151015:153650.965 In substitute_key_macros() data:'service_state["Schedule"]'
 26174:20151015:153650.965 End of substitute_key_macros():SUCCEED data:'service_state["Schedule"]'
 26174:20151015:153650.965 In substitute_key_macros() data:'service_state["Symantec Endpoint Protection"]'
 26174:20151015:153650.965 End of substitute_key_macros():SUCCEED data:'service_state["Symantec Endpoint Protection"]'
 26174:20151015:153650.965 In substitute_key_macros() data:'service_state["W32Time"]'
 26174:20151015:153650.965 End of substitute_key_macros():SUCCEED data:'service_state["W32Time"]'
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
 26174:20151015:153650.965 In substitute_key_macros() data:'service_state["winmgmt"]'
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]:  26174:20151015:153650.965 End of substitute_key_macros():SUCCEED data:'service_state["winmgmt"]'
ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened. 26174:20151015:153650.965 In substitute_key_macros() data:'service_state["wuauserv"]'

zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]:  26174:20151015:153650.965 End of substitute_key_macros():SUCCEED data:'service_state["wuauserv"]'
ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
 26174:20151015:153650.966 In substitute_key_macros() data:'service_state["Zabbix Agent"]'
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened. 26174:20151015:153650.966 End of substitute_key_macros():SUCCEED data:'service_state["Zabbix Agent"]'

zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
 26174:20151015:153650.966 In substitute_key_macros() data:'system.cpu.num'
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]:  26174:20151015:153650.966 End of substitute_key_macros():SUCCEED data:'system.cpu.num'
ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
zabbix_server [25756]: ERROR [file:json.c,line:611] Something impossible has just happened.
Comment by Aleksandrs Saveljevs [ 2015 Oct 15 ]

Lines with "Something impossible has just happened" are written by the process with PID 25756, but the log above does not contain any other lines by this PID. Could you please attach a more complete log where it would be seen which JSON does that particular process try to process? Note that attaching a log is preferred over pasting it in the comments, so that any unprintable characters are retained.

Comment by Philippe [ 2015 Oct 16 ]

Here is the entire logfile in zip format. Sorry

Comment by Aleksandrs Saveljevs [ 2015 Oct 16 ]

Thank you, Philippe! We have identified the problem. You might now wish to remove the attached log so that it does not take space and so that any private information is not on the Internet.

This error happens when the server receives the following JSON:

{
"data":[
{ "{#IISASP}":"\_\_total\_\_"},
{ "{#IISASP}":"\_lm\_w3svc\_2\_root\_e5c37cc17a904755977eeab316379308"},
{ "{#IISASP}":"\_lm\_w3svc\_2\_root\_7961381a851842f3a0c40deedd1e3412"},
{ "{#IISASP}":"\_lm\_w3svc\_2\_root\_securitytokenserviceapplication"},
{ "{#IISASP}":"\_lm\_w3svc\_2\_root\_24b0f613d6274e47ae38c88d0967e03f"},
{ "{#IISASP}":"\_lm\_w3svc\_2\_root\_79d8f6659e5a437d842015300ee8baec"}
]
}

This JSON does not seem to be correct, because backslashes should be escaped (or, alternatively, "_" should not be escaped), see http://json.org/ for syntax and http://jsonlint.com/ for validation. This is something you might wish to fix on your side.

However, there is something to fix on Zabbix side, too, because it is wrong to log "Something impossible has just happened" line when processing invalid user input.

Comment by Philippe [ 2015 Oct 16 ]

Thank you very much for your quick response. We will modify the procedure to remove backslash.

How to do to remove the attached log ?

Comment by Aleksandrs Saveljevs [ 2015 Oct 16 ]

We removed the attachment. Thank you!

Comment by dimir [ 2015 Oct 21 ]

This is caused by ZBX-5546. The check for invalid escape sequences in JSON was removed in that issue. In result, JSON validation was passing but when replacing LLD macros in prototypes invalid escape sequences were causing that error message (however, objects were created without the escape character).

Version 2.2 works as expected, the affected versions are 2.4 and 3.0 .

The check for invalid escape sequences during JSON validation brought back.

Fixed in svn://svn.zabbix.com/branches/dev/ZBX-9959.

Comment by Andris Zeila [ 2015 Oct 27 ]

Successfully tested

Comment by dimir [ 2015 Oct 27 ]

Fixed in pre-2.4.7rc1 (r56396), pre-3.0.0alpha4 (r56397).

Comment by lucas hall [ 2017 Aug 24 ]

See this: JSON Formatter https://jsonformatter-online.com for JSON validation

Generated at Fri Apr 26 10:46:26 EEST 2024 using Jira 9.12.4#9120004-sha1:625303b708afdb767e17cb2838290c41888e9ff0.