[dev.icinga.com #9244] String escape problem with PostgreSQL >= 9.1 and standard_conforming_strings=on

[icinga-migration]

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

Created by cramm on 2015-05-09 12:27:23 +00:00

Assignee: mfriedrich
Status: Resolved (closed on 2015-09-05 12:10:04 +00:00)
Target Version: 2.3.10
Last Update: 2015-09-05 13:36:16 +00:00 (in Redmine)

Icinga Version: 2.3.4
Backport?: Already backported
Include in Changelog: 1

---

Scenario:

• Master v2.3.4, Debian Wheezy (debmon packages)
  * Postgres IDO module in use
• Windows 2008 R2 monitored via agent 2.3.4 from http://packages.icinga.org/windows/

Steps

Create a service for a general disk space check:

object service "disk space usage" {
  import "generic-service"
  host_name = "fs1"
  check_command = "disk"
  command_endpoint = "fs1.domain"
}

icinga2.log excerpt:

[2015-05-09 09:12:40 -0300] information/ApiClient: Reconnecting to API endpoint 'fs1.domain' via host '192.168.100.20' and port '5665'
[2015-05-09 09:12:40 -0300] information/IdoPgsqlConnection: pgSQL IDO instance id: 1 (schema version: '1.13.0')
[2015-05-09 09:12:40 -0300] information/ConfigItem: Activated all objects.
[2015-05-09 09:12:40 -0300] information/ApiListener: New client connection for identity 'fs1.domain'
...
[2015-05-09 09:19:17 -0300] critical/IdoPgsqlConnection: Error "ERROR:  syntax error at or near "16384"
LINE 1: ...access drive at E:\', TO_TIMESTAMP(1431173957), E'16384', 72...
                                                             ^
" when executing query "INSERT INTO icinga_logentries (endpoint_object_id, entry_time, entry_time_usec, instance_id, logentry_data, logentry_time, logentry_type, ob
ject_id) VALUES (1, TO_TIMESTAMP(1431173957), E'749639', 1, E'SERVICE ALERT: f1;disk space usage;UNKNOWN;SOFT;2;Failed to access drive at E:\', TO_TIMESTAMP
(1431173957), E'16384', 7208)"
[2015-05-09 09:19:17 -0300] warning/IdoPgsqlConnection: Exception during database operation: Verify that your database is operational!
[2015-05-09 09:19:19 -0300] information/IdoPgsqlConnection: pgSQL IDO instance id: 1 (schema version: '1.13.0')
[2015-05-09 09:19:19 -0300] critical/IdoPgsqlConnection: Error "ERROR:  syntax error at or near "1"
LINE 1: ...access drive at E:\',  passive_checks_enabled = E'1',  perce...
                                                             ^
" when executing query "UPDATE icinga_servicestatus SET acknowledgement_type = E'0',  active_checks_enabled = E'1',  check_command = E'disk',  check_source = E'mon.domain',  check_type = E'0',  current_check_attempt = E'2',  current_notification_number = E'0',  current_state = E'3',  endpoint_object_id = 1,  event_
handler = E'',  event_handler_enabled = E'1',  execution_time = E'0.062000036239624023',  flap_detection_enabled = E'0',  has_been_checked = E'1',  instance_id = 1,
  is_flapping = E'0',  is_reachable = E'1',  last_check = TO_TIMESTAMP(1431173957),  last_hard_state = E'0',  last_hard_state_change = TO_TIMESTAMP(1431173590),  la
st_state_change = TO_TIMESTAMP(1431173957),  last_time_ok = TO_TIMESTAMP(1431173890),  last_time_unknown = TO_TIMESTAMP(1431173957),  latency = E'0',  long_output =
 E'',  max_check_attempts = E'5',  modified_service_attributes = E'0',  next_check = TO_TIMESTAMP(1431174017),  next_notification = TO_TIMESTAMP(1431175365),  norma
l_check_interval = E'1',  notifications_enabled = E'1',  output = E'Failed to access drive at E:\',  passive_checks_enabled = E'1',  percent_state_change = E'0',  p
erfdata = E'',  problem_has_been_acknowledged = E'0',  process_performance_data = E'1',  retry_check_interval = E'0.5',  scheduled_downtime_depth = E'0',  service_o
bject_id = 7208,  should_be_scheduled = E'1',  state_type = E'0',  status_update_time = TO_TIMESTAMP(1431173959) WHERE service_object_id = 7208"
Context:
        (0) Reconnecting to PostgreSQL IDO database 'ido-pgsql

Note how the check_disk Windows plugin sends in its output a ``'Failed to access drive at E:\'`` error message (which doesn't happen when one executes it manually, but that's another topic possible for another issue).

That message somehow reachs the IDO DB unescaped.

Changesets

2015-09-05 12:08:35 +00:00 by mfriedrich fa6c0fe

Fix string escape problem with PostgreSQL >= 9.1 and standard_conforming_strings=on

fixes #9244

2015-09-05 13:27:41 +00:00 by mfriedrich e06375d

Fix string escape problem with PostgreSQL >= 9.1 and standard_conforming_strings=on

fixes #9244

---

Relations:

• duplicates #9244

[icinga-migration]

Updated by gbeutner on 2015-05-11 05:54:23 +00:00

• Status changed from New to Feedback
• Assigned to set to cramm

Which PostgreSQL version are you using?

[icinga-migration]

Updated by gbeutner on 2015-05-11 06:09:47 +00:00

• Subject changed from Windows Agent disk check + Postgres IDO module: Miissing \ escaping to Postgres IDO module does not properly escape backslashes

This probably has to do with the fact that the default value for standard_conforming_strings was changed to ON in PostgreSQL 9.1 - which would indicate that this is most likely a bug in Icinga.

[icinga-migration]

Updated by cramm on 2015-05-11 14:40:31 +00:00

PostgreSQL version is 9.1 (9.1.15-0+deb7u1 Debian package.)

[icinga-migration]

Updated by mfriedrich on 2015-06-18 09:05:56 +00:00

• Status changed from Feedback to New
• Assigned to deleted cramm
• Priority changed from Normal to High

[icinga-migration]

Updated by mfriedrich on 2015-06-23 13:30:50 +00:00

• Target Version set to Backlog

[icinga-migration]

Updated by mfriedrich on 2015-07-20 11:18:31 +00:00

Setting standard_conforming_strings=off in postgresql.conf makes it work again:

[2015-07-20 11:34:52 +0200] information/ExternalCommandListener: Executing external command: [1437384892] PROCESS_HOST_CHECK_RESULT;5872-router;1;Failed to access drive at E:\
[2015-07-20 11:34:52 +0200] debug/IdoPgsqlConnection: Query: INSERT INTO icinga_externalcommands (command_args, command_name, command_type, endpoint_object_id, entry_time, instance_id) VALUES (E'5872-router;1;Failed to access drive at E:\\', E'PROCESS_HOST_CHECK_RESULT', E'87', 1, TO_TIMESTAMP(1437384892), 1)
[2015-07-20 11:34:52 +0200] debug/IdoPgsqlConnection: Query: INSERT INTO icinga_logentries (endpoint_object_id, entry_time, entry_time_usec, instance_id, logentry_data, logentry_time, logentry_type, object_id) VALUES (1, TO_TIMESTAMP(1437384892), E'107100', 1, E'HOST ALERT: 5872-router;DOWN;SOFT;2;Failed to access drive at E:\\', TO_TIMESTAMP(1437384892), E'2048', 100)
[2015-07-20 11:34:52 +0200] debug/IdoPgsqlConnection: Query: UPDATE icinga_hoststatus SET acknowledgement_type = E'0',  active_checks_enabled = E'1',  check_command = E'hostalive',  check_source = E'nbmif.int.netways.de',  check_type = E'0',  current_check_attempt = E'2',  current_notification_number = E'0',  current_state = E'1',  endpoint_object_id = 1,  event_handler = E'',  event_handler_enabled = E'1',  execution_time = E'0',  flap_detection_enabled = E'0',  has_been_checked = E'1',  host_object_id = 100,  instance_id = 1,  is_flapping = E'0',  is_reachable = E'1',  last_check = TO_TIMESTAMP(1437384892),  last_hard_state = E'0',  last_hard_state_change = TO_TIMESTAMP(1437384864),  last_state_change = TO_TIMESTAMP(1437384892),  last_time_down = TO_TIMESTAMP(1437384892),  last_time_up = TO_TIMESTAMP(1437384864),  latency = E'0',  long_output = E'',  max_check_attempts = E'3',  modified_host_attributes = E'0',  next_check = TO_TIMESTAMP(1437385164),  normal_check_interval = E'5',  notifications_enabled = E'1',  output = E'Failed to access drive at E:\\',  passive_checks_enabled = E'1',  percent_state_change = E'0',  perfdata = E'',  problem_has_been_acknowledged = E'0',  process_performance_data = E'1',  retry_check_interval = E'1',  scheduled_downtime_depth = E'0',  should_be_scheduled = E'1',  state_type = E'0',  status_update_time = TO_TIMESTAMP(1437384892) WHERE host_object_id = 100
[2015-07-20 11:34:52 +0200] debug/IdoPgsqlConnection: Query: INSERT INTO icinga_statehistory (check_source, current_check_attempt, endpoint_object_id, instance_id, last_hard_state, last_state, long_output, max_check_attempts, object_id, output, state, state_change, state_time, state_time_usec, state_type) VALUES (E'nbmif.int.netways.de', E'2', 1, 1, E'0', E'0', E'', E'3', 100, E'Failed to access drive at E:\\', E'1', E'1', TO_TIMESTAMP(1437384892), E'0', E'0')

Using the default on postgresql-9.4.4-1.fc22.x86_64 the error is reproducible:

[2015-07-20 11:38:09 +0200] critical/IdoPgsqlConnection: Error "FEHLER:  Syntaxfehler bei „1“
LINE 1: ...access drive at E:\',  passive_checks_enabled = E'1',  perce...
                                                             ^
" when executing query "UPDATE icinga_hoststatus SET acknowledgement_type = E'0',  active_checks_enabled = E'1',  check_command = E'hostalive',  check_source = E'nbmif.int.netways.de',  check_type = E'0',  current_check_attempt = E'2',  current_notification_number = E'0',  current_state = E'1',  endpoint_object_id = 1,  event_handler = E'',  event_handler_enabled = E'1',  execution_time = E'0',  flap_detection_enabled = E'0',  has_been_checked = E'1',  host_object_id = 100,  instance_id = 1,  is_flapping = E'0',  is_reachable = E'1',  last_check = TO_TIMESTAMP(1437385081),  last_hard_state = E'0',  last_hard_state_change = TO_TIMESTAMP(1437384864),  last_state_change = TO_TIMESTAMP(1437385081),  last_time_down = TO_TIMESTAMP(1437385081),  last_time_up = TO_TIMESTAMP(1437385013),  latency = E'0',  long_output = E'',  max_check_attempts = E'3',  modified_host_attributes = E'0',  next_check = TO_TIMESTAMP(1437385381),  normal_check_interval = E'5',  notifications_enabled = E'1',  output = E'Failed to access drive at E:\',  passive_checks_enabled = E'1',  percent_state_change = E'0',  perfdata = E'',  problem_has_been_acknowledged = E'0',  process_performance_data = E'1',  retry_check_interval = E'1',  scheduled_downtime_depth = E'0',  should_be_scheduled = E'1',  state_type = E'0',  status_update_time = TO_TIMESTAMP(1437385089) WHERE host_object_id = 100"
Context:
    (0) Reconnecting to PostgreSQL IDO database 'ido-pgsql'

[2015-07-20 11:38:09 +0200] warning/IdoPgsqlConnection: Exception during database operation: Verify that your database is operational!

The problem here is the backslash at the end of the string, which gets taken into account as quote escaping.

Proposed solution

standard_conforming_strings=off on connect.

[icinga-migration]

Updated by mfriedrich on 2015-08-03 13:22:19 +00:00

• Relates set to 9808

[icinga-migration]

Updated by mfriedrich on 2015-08-04 07:40:56 +00:00

• Relates deleted 9808

[icinga-migration]

Updated by mfriedrich on 2015-08-04 07:41:02 +00:00

• Duplicated set to 9808

[icinga-migration]

Updated by mfriedrich on 2015-09-05 12:08:09 +00:00

• Subject changed from Postgres IDO module does not properly escape backslashes to String escape problem with PostgreSQL >= 9.1 and standard_conforming_strings=on
• Status changed from New to Assigned
• Assigned to set to mfriedrich
• Target Version changed from Backlog to 2.4.0

More references:

http://grokbase.com/t/postgresql/pgsql-general/094qmjcvw2/standard-conforming-strings-and-pg-escape-string
http://lists.alioth.debian.org/pipermail/pkg-dspam-commits/2013-November/000487.html

I've already implemented and tested a fix on my F22 box with PostgreSQL 9.4.

[icinga-migration]

Updated by mfriedrich on 2015-09-05 12:10:04 +00:00

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

Applied in changeset fa6c0fe.

[icinga-migration]

Updated by mfriedrich on 2015-09-05 13:36:16 +00:00

• Target Version changed from 2.4.0 to 2.3.10
• Backport? changed from TBD to Yes