Skip to content
This repository has been archived by the owner on Jan 15, 2019. It is now read-only.

[dev.icinga.com #4196] mysql: output/perfdata limits cut escaped string leaving '\' at the end #1281

Closed
icinga-migration opened this issue May 17, 2013 · 17 comments
Milestone

Comments

@icinga-migration
Copy link

This issue has been migrated from Redmine: https://dev.icinga.com/issues/4196

Created by tontonitch on 2013-05-17 12:33:31 +00:00

Assignee: mfriedrich
Status: Resolved (closed on 2013-06-22 18:43:18 +00:00)
Target Version: 1.9.2
Last Update: 2014-12-08 14:38:07 +00:00 (in Redmine)

Icinga Version: 1.10.0
OS Version: any

Hi,
I've upgraded our icinga environment from 1.8.4 to 1.9.0, and I now receive the following error message via syslog from ido2db:

May 16 08:05:00 server ido2db: IDO2DB buffer sizes: left=4096, right=0 May 16 08:05:20 server ido2db: IDO2DB buffer sizes: left=494, right=0 May 16 08:06:00 server ido2db: IDO2DB buffer sizes: left=451, right=0 May 16 08:06:20 server ido2db: IDO2DB buffer sizes: left=736, right=0 May 16 08:06:30 server ido2db: Error: database query failed for 'UPDATE icinga_servicestatus SET instance_id=1, service_object_id=797, status_update_time=FROM_UNIXTIME(1368684390), output='OK - 147 port\(s\), 76 free, 76 AdminUp and free, 204 graphed <a href=\"https://xxxxxx\.xxxxxxxxxxxxxx\.xxxx/interfacetable_v3t/tables/xxxxxxxQ2DxQ2DxxxQ2D0xxxx-Interfacetable\.html\" target=\"_self\">\[details\]</a>', long_output='', perfdata='Interface_global::check_interface_table_global::time=2s;;;; uptime=1382877970s;;;; watched=204;;;; useddelta=600s;;;; ports=147;;;; freeports=76;;;; adminupfree=76;;;; If_GigabitEthernet1/1::check_interface_table_port::OperStatus=1;;;0; BpsIn=1523400\.64;1000000000;1000000000;0;1000000000 BpsOut=141885\.28;1000000000;1000000000;0;1000000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_GigabitEthernet1/2::check_interface_table_port::OperStatus=2;;;0; BpsIn=0;1000000000;1000000000;0;1000000000 BpsOut=0;1000000000;1000000000;0;1000000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_FastEthernet2/1::check_interface_table_port::OperStatus=2;;;0; BpsIn=0;100000000;100000000;0;100000000 BpsOut=0;100000000;100000000;0;100000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_FastEthernet2/2::check_interface_table_port::OperStatus=1;;;0; BpsIn=19\.6;100000000;100000000;0;100000000 BpsOut=628\.4;100000000;100000000;0;100000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_FastEthernet2/3::check_interface_table_port::OperStatus=1;;;0; BpsIn=60\.24;100000000;100000000;0;100000000 BpsOut=626\.72;100000000;100000000;0;100000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_FastEthernet2/4::check_interface_table_port::OperStatus=1;;;0; BpsIn=60\.24;100000000;100000000;0;100000000 BpsOut=626\.72;100000000;100000000;0;100000000 PpsInErr= May 16 08:06:30 server ido2db: Error: database query failed for 'UPDATE icinga_servicestatus SET instance_id=1, service_object_id=797, status_update_time=FROM_UNIXTIME(1368684390), output='OK - 147 port\(s\), 76 free, 76 AdminUp and free, 204 graphed <a href=\"https://xxxxxx\.xxxxxxxxxxxxxx\.xxxx/interfacetable_v3t/tables/xxxxxxxQ2DxQ2DxxxQ2D0xxxx-Interfacetable\.html\" target=\"_self\">\[details\]</a>', long_output='', perfdata='Interface_global::check_interface_table_global::time=2s;;;; uptime=1382877970s;;;; watched=204;;;; useddelta=600s;;;; ports=147;;;; freeports=76;;;; adminupfree=76;;;; If_GigabitEthernet1/1::check_interface_table_port::OperStatus=1;;;0; BpsIn=1523400\.64;1000000000;1000000000;0;1000000000 BpsOut=141885\.28;1000000000;1000000000;0;1000000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_GigabitEthernet1/2::check_interface_table_port::OperStatus=2;;;0; BpsIn=0;1000000000;1000000000;0;1000000000 BpsOut=0;1000000000;1000000000;0;1000000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_FastEthernet2/1::check_interface_table_port::OperStatus=2;;;0; BpsIn=0;100000000;100000000;0;100000000 BpsOut=0;100000000;100000000;0;100000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_FastEthernet2/2::check_interface_table_port::OperStatus=1;;;0; BpsIn=19\.6;100000000;100000000;0;100000000 BpsOut=628\.4;100000000;100000000;0;100000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_FastEthernet2/3::check_interface_table_port::OperStatus=1;;;0; BpsIn=60\.24;100000000;100000000;0;100000000 BpsOut=626\.72;100000000;100000000;0;100000000 PpsInErr=0;100;500;0; PpsOutErr=0;100;500;0; PpsInDiscard=0;100;500;0; PpsOutDiscard=0;100;500;0; If_FastEthernet2/4::check_interface_table_port::OperStatus=1;;;0; BpsIn=60\.24;100000000;100000000;0;100000000 BpsOut=626\.72;100000000;100000000;0;100000000 PpsInErr= May 16 08:06:40 server ido2db: IDO2DB buffer sizes: left=1476, right=0 May 16 08:07:00 server ido2db: IDO2DB buffer sizes: left=772, right=0 May 16 08:07:20 server ido2db: IDO2DB buffer sizes: left=738, right=0 May 16 08:07:40 server ido2db: IDO2DB buffer sizes: left=680, right=0

It appears 3-4 times a day. Always the same check (personnal plugin interfacetable_v3t) on the same host. What looks also strange is that it appears only 3-4 times a day, whereas the check is scheduled each 10 minutes.

Do you have an idea of why the update cannot be done? Is there a way I can help / investigate that problem? Debug level in ido2db ahs been set to 2, hope that it will not generate too huge debug files.

Regards,
Yannick

Attachments

Changesets

2013-06-03 18:20:37 +00:00 by (unknown) 3d896c5

idoutils: fix mysql: output/perfdata limits cut escaped string leaving '\' at the end

... and therefore escaping the single quote for the query asprintf.
wouldn't happen with prepared statements, but we can't use that with
libdbi.

refs #4196

Relations:

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-05-18 14:21:01 +00:00

how big does the output/longoutput get? (debug log for the query itsself!)

@icinga-migration
Copy link
Author

Updated by tontonitch on 2013-05-18 14:49:42 +00:00

I also thought about a problem of lenght but I'm not sure that it is the longer I have.
I checked the data type of the output column (TEXT) but it should be sufficient to store the output of the check.
It may be a problem of a truncated query. I will try to test the max output length before facing such a problem.
Concerning your question, I don't have access to the concerned server until next tuesday. I will give you the info then.
Regards,
Yannick

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-05-18 16:34:31 +00:00

yep, and it will allow you to manually run the query once (best against a backup database). maybe the query length exceeds a buffer limit, or similar. sure that you did not change anything related to that in your my.cnf?

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-05-18 16:34:40 +00:00

  • Status changed from New to Feedback

@icinga-migration
Copy link
Author

Updated by tontonitch on 2013-05-21 13:28:53 +00:00

From today:

  • output: 213 characters
  • longoutput: 0 characters
  • perfdata: 47016 characters

I've tested with a perfdata of 100000 characters: no issue.
So, until now, I have not been able to reproduce the issue manually. Still trying...
The debug is not possible until i find a way to reproduce the issue, as it occurs only a few times a day.

No change in my.cnf

Yannick

@icinga-migration
Copy link
Author

Updated by tontonitch on 2013-05-22 15:07:46 +00:00

Hi,

Finally reproduced the problem and identified the issue.

In the generated UPDATE statement, the perfdata column is updated with a value coming from a truncation of the performance data: the value corresponds to the first 32768 characters, including any backslashes (\) used to escape dots (.) for example.
The truncation is already a problem for my plugin, as its output can be up to such a limit (for example, a monitored Cisco device with 223 ports can produces more or less 47000 characters of performance data (with the coming new version of the plugin)).

Also, usually the UPDATE succeeds even if the performance data are truncated, as the UPDATE statement is still valid most of the time. I faced the UPDATE error message because the truncation occured just after an escape character (backslash). Indeed, the quote making the end of the value to insert as perfdata was escaped, malforming the UPDATE statement. Extract of the bad UPDATE:

BpsIn=1003905\.6;1000000000;1000000000;0;1000000000 BpsOut=1435232\', current_state=0, has_been_checked=1,

For the first point, is there any way to extend the possible size of the perfdata to be inserted in the perfdata column of the icinga_servicestatus table?

For the 2nd point, a rule to remove any backslashes at the end of the perfdata to insert would be a good workaround. Same for output and longoutput.

Regards,
Yannick

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-05-22 15:49:06 +00:00

interesting.

try

$ grep IDO2DB_MYSQL_MAX_TEXT_LEN module/idoutils/include/ido2db.h
#define IDO2DB_MYSQL_MAX_TEXT_LEN               32768

for the escape fix - there must be sort of safety logic for detecting '\\x' and 'c\x' then, when looking for possible escaped characters.

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-05-22 15:54:48 +00:00

idomod limits that as well with IDOMOD_MAX_TEXT_LEN - because the overall IDOMOD_MAX_BUFLEN would lead to undeterministic behaviour when cutting the string with the api headers in it. see #2342 for details.

by default, the core already limits the plugin output to 8k - did you change that?

$ grep MAX_PLUGIN_OUTPUT_LENGTH include/*
include/icinga.h:#define MAX_PLUGIN_OUTPUT_LENGTH                8192    /* max length of plugin output (including perf data) */

@icinga-migration
Copy link
Author

Updated by tontonitch on 2013-05-22 17:23:52 +00:00

Yes, I always change a couple of variables in icinga.h and common.h.
For the use of the plugin, as it generates a lot of performance data, I usually recommend to extend the MAX_PLUGIN_OUTPUT_LENGTH variable to 32768. But it appears to be not enough also...
So it seems that I have 3 solutions:

  • to increase MAX_PLUGIN_OUTPUT_LENGTH, IDOMOD_MAX_TEXT_LEN and IDO2DB_MYSQL_MAX_TEXT_LEN to a quite high value (taking in account the limit of the datatype TEXT)
  • to write the performance data in a spool file to be processed by the graphing solution (already an option of the plugin, but presented as an alternative for people installing nagios/icinga from distribution packages)
  • ... to reduce the amount of performance data :-( (new version of the plugin introduced war/crit/max values for part of the stats, which of course increase quickly the size of the performance data...)

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-05-22 17:37:21 +00:00

don't forget the IDOMOD_MAX_BUFLEN setting, which limits the data packet being sent over the socket.

seems the plugin case is very special, flushing everything as perfdata onto the core. i'm not sure how to resolve this here (and i not not really want to change buffer sizes here nor expose them to users via config options).

@icinga-migration
Copy link
Author

Updated by tontonitch on 2013-05-24 08:15:59 +00:00

A comment about MAX_PLUGIN_OUTPUT_LENGTH: it seems to not limit the length of the output anymore, as even if I changed it to 32768 it should be not enough to deal with a 47232 characters output. But icinga core and classicui seems to deal correctly with all the output, as

*I can see the complete output + perfdata in the service details on classicui
*all the perfdata are sent to the service-perfdata spool files
I should do a test to confirm that.

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-05-29 09:13:08 +00:00

could be related to #3517 - though, more tests required. thank you.

@icinga-migration
Copy link
Author

Updated by tontonitch on 2013-06-03 15:03:16 +00:00

  • File added bugfix_issue_4196_idoutils_dbqueries.patch

Hi Michael,
Attached a patch for the escape problem.
Regards,
Yannick

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-06-03 17:39:33 +00:00

  • Status changed from Feedback to Assigned
  • Assigned to set to mfriedrich
  • Target Version set to 1.9.2

Ok thanks. I need to create some test configuration, hitting the '\' then.

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-06-03 18:09:57 +00:00

  • Subject changed from ido2db fails query for updating icinga_servicestatus to mysql: output/perfdata limits cut escaped string leaving '' at the end

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2013-06-22 18:43:18 +00:00

  • Status changed from Assigned to Resolved
  • Done % changed from 0 to 100

@icinga-migration
Copy link
Author

Updated by mfriedrich on 2014-12-08 14:38:07 +00:00

  • Project changed from 18 to Core, Classic UI, IDOUtils
  • Category changed from 79 to IDOUtils
  • Icinga Version changed from 1 to 1
  • OS Version set to any

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

1 participant