[dev.icinga.com #5416] Oracle: logentry errors logged in syslog

[icinga-migration]

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

Created by Tommi on 2014-01-05 12:09:19 +00:00

Assignee: Tommi
Status: Assigned (closed on 2014-02-21 17:27:39 +00:00)
Target Version: Backlog
Last Update: 2015-08-09 19:03:30 +00:00 (in Redmine)

Icinga Version: 1.13.2
OS Version: any

---

found suspicious messages in syslog, maybe caused by a wrong used variable in bind.

Jan  5 12:50:10 xxx ido2db: OCILIB - MSG Name or position ':X9' previously binded with different datatype at pos 0 in QUERY 'INSERT INTO logentries (id, instance_id, logentry_time, entry_time, entry_time_usec, logentry_type, logentry_data,realtime_data, inferred_data_extracted, object_id) VALUES (seq_logentries.nextval, :X1, unixts2localts(:X2), unixts2localts(:X3), :X4, :X5, :X6, :X7, :X8, :X9)' -->9 BindVars: [Name:':X1', Type:uInt, Value:'1'][Name:':X2', Type:uInt, Value:'1388421448'][Name:':X3', Type:uInt, Value:'1388421448'][Name:':X4', Type:uInt, Value:'53936'][Name:':X5', Type:uInt, Value:'2048'][Name:':X7', Type:uInt, Value:'1'][Name:':X8', Type:uInt, Value:'1'][Name:':X9', Type:Text, Value:'OCILIB',Text Size:6][Name:':X6', Type:CLob, Value:(n/a) Size: 0]
Jan  5 12:50:10 xxx ido2db: OCILIB - MSG Name or position ':X9' previously binded with different datatype at pos 0 in QUERY 'INSERT INTO logentries (id, instance_id, logentry_time, entry_time, entry_time_usec, logentry_type, logentry_data,realtime_data, inferred_data_extracted, object_id) VALUES (seq_logentries.nextval, :X1, unixts2localts(:X2), unixts2localts(:X3), :X4, :X5, :X6, :X7, :X8, :X9)' -->9 BindVars: [Name:':X1', Type:uInt, Value:'1'][Name:':X2', Type:uInt, Value:'1388421498'][Name:':X3', Type:uInt, Value:'1388421498'][Name:':X4', Type:uInt, Value:'182589'][Name:':X5', Type:uInt, Value:'8192'][Name:':X7', Type:uInt, Value:'1'][Name:':X8', Type:uInt, Value:'1'][Name:':X9', Type:Text, Value:'<9E><93>Ȟ#177', Text Size:6][Name:':X6', Type:CLob, Value:(n/a) Size: 0]
Jan  5 12:50:10 xxx ido2db: OCILIB - MSG Name or position ':X9' previously binded with different datatype at pos 0 in QUERY 'INSERT INTO logentries (id, instance_id, logentry_time, entry_time, entry_time_usec, logentry_type, logentry_data,realtime_data, inferred_data_extracted, object_id) VALUES (seq_logentries.nextval, :X1,  unixts2localts(:X2), unixts2localts(:X3), :X4, :X5, :X6, :X7, :X8, :X9)' -->9 BindVars: [Name:':X1', Type:uInt, Value:'1'][Name:':X2', Type:uInt, Value:'1388421518'][Name:':X3', Type:uInt, Value:'1388421518'][Name:':X4', Type:uInt, Value:'239289'][Name:':X5', Type:uInt, Value:'2048'][Name:':X7', Type:uInt, Value:'1'][Name:':X8', Type:uInt, Value:'1'][Name:':X9', Type:Text, Value:'1388421518.239289', Text Size:17][Name:':X6', Type:CLob, Value:(n/a) Size: 0]
Jan  5 12:50:11 xxx ido2db: OCILIB - MSG Name or position ':X9' previously binded with different datatype at pos 0 in QUERY 'INSERT INTO logentries (id, instance_id, logentry_time, entry_time, entry_time_usec, logentry_type, logentry_data,realtime_data, inferred_data_extracted, object_id) VALUES (seq_logentries.nextval, :X1, unixts2localts(:X2), unixts2localts(:X3), :X4, :X5, :X6, :X7, :X8, :X9)' -->9 BindVars: [Name:':X1', Type:uInt, Value:'1'][Name:':X2', Type:uInt, Value:'1388421558'][Name:':X3', Type:uInt, Value:'1388421558'][Name:':X4', Type:uInt, Value:'84517'][Name:':X5', Type:uInt, Value:'16384'][Name:':X7', Type:uInt, Value:'1'][Name:':X8', Type:uInt, Value:'1'][Name:':X9', Type:Text, Value:'', Text Size:0][Name:':X6', Type:CLob, Value:(n/a) Size: 0]

Changesets

2015-04-20 16:33:35 +00:00 by Tommi 0feec2f

idoutils: fix logentries inserts (oracle only)

fixes issues when inserting rows into logentries
-bind clob instead of simple string
-pointer reference errors
-bind null value

refs #5416

[icinga-migration]

Updated by Tommi on 2014-01-19 21:04:29 +00:00

• Is Private changed from 0 to 1

looks strange. supplied object_id as :X9 should be an uint, but is sometimes crap
[Name:':X9', Type:Text, Value:'1390164524.214501 -> a timestamp?
[Name:':X9', Type:Text, Value:'0' ->maybe oK, but such objectid should not exist
[Name:':X9', Type:Text, Value:'1390164604' ->a timestamp again?
[Name:':X9', Type:Text, Value:'ipsesx' ->this is a host name
[Name:':X9', Type:Text, Value:'ds1812' -> this is also a host name

From the code point of view looks normal. object_id is retrieved with the same function all other data section are handled without any similar symptoms. Maybe pointer vor object_id has been overwritten before binding or executing the statement? Needs more investigation.
Will set this issue as private

[icinga-migration]

Updated by Tommi on 2014-02-21 17:27:40 +00:00

• Status changed from Assigned to Rejected

locks very special for my environment, couldnt found this outside. If there are no other complains, i will not spend more time for this issue.

[icinga-migration]

Updated by mfriedrich on 2014-12-08 14:38:20 +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

[icinga-migration]

Updated by Tommi on 2015-04-18 20:27:54 +00:00

• Status changed from Rejected to Assigned
• Target Version set to 1.14
• Done % changed from 0 to 50
• Is Private changed from 1 to 0
• Icinga Version changed from 1 to 1

Found (hopefully) the reason for this issue and going to prepare a fix

[icinga-migration]

Updated by Tommi on 2015-04-19 15:42:21 +00:00

• Status changed from Assigned to 8
• Assigned to changed from Tommi to mfriedrich
• Done % changed from 50 to 100

After some hours running proper it looks solved.
one problem was the missing implementation for clobs
second it looks like the already known pointer casting problem as mentioned in #2646. object_id was not handover in the proper way when it has been casted into void * first.
third ocilib complained about changing the bind type for number variables when the first time use was utilizing the bind_null function. This one makes a dummy string bind. The correct way is bind the variable with the right type and not only an empty pointer first, then use the oci_bindsetnull function direct afterwards when the column should be set to NULL.

added patch to fix/oracle_logentries-5416 (commit a75d19fbbdc7a385a6ea944a7bf5c491c6be9a0a)

[icinga-migration]

Updated by mfriedrich on 2015-04-20 07:50:41 +00:00

• Status changed from 8 to Assigned
• Assigned to changed from mfriedrich to Tommi
• Done % changed from 100 to 0

I don't see any commit.

[icinga-migration]

Updated by Tommi on 2015-04-20 16:45:46 +00:00

• Status changed from Assigned to 8
• Assigned to changed from Tommi to mfriedrich
• Done % changed from 0 to 100

no glue, why it is disappeared.
next try, this time also with changelog entry:
To git@git.icinga.org:icinga-core.git
d17663f..0feec2f fix/oracle_logentries-5416 -> fix/oracle_logentries-5416

[icinga-migration]

Updated by mfriedrich on 2015-04-29 18:21:50 +00:00

• Status changed from 8 to Assigned
• Assigned to changed from mfriedrich to Tommi
• Target Version deleted 1.14
• Done % changed from 100 to 0

The commit diff touches too many lines which makes it hard to understand what it exactly does (keep space fixes out of that). Furthermore the indent is wrong, as seen in the diff. Also, don't add Changelog entries for fix commits. We'll deal with that on the release date.

[icinga-migration]

Updated by Tommi on 2015-04-29 19:31:51 +00:00

• Assigned to changed from Tommi to mfriedrich

And now, what should i do?

The fix touches exactly 2 functions. It repairs wrong pointer conversions for objectid, changes the variable types to better fit ocilib reqs and adds the required clob bind instead of the string bind. Also it repairs binding of null values for number type. And yes, it is a bigger change which hopefully now adresses all kind of logentry errors and took a lot of hours of investigation and to resolv.

indention is not consistent across many files. It may look nasty, but caused by different tools used for editing which are interpreting the spaces in a different way.

[icinga-migration]

Updated by mfriedrich on 2015-05-01 11:39:35 +00:00

• Assigned to changed from mfriedrich to Tommi

Tommi wrote:

And now, what should i do?

Review your commit and fix it for being merged into a bugfix release :)

The fix touches exactly 2 functions. It repairs wrong pointer conversions for objectid, changes the variable types to better fit ocilib reqs and adds the required clob bind instead of the string bind. Also it repairs binding of null values for number type. And yes, it is a bigger change which hopefully now adresses all kind of logentry errors and took a lot of hours of investigation and to resolv.

It also removes OCI_Commit at 2 stages where it does not make sense (a query commit must happen before fetching the result set, right?)

-       OCI_Commit(idi->dbinfo.oci_connection);
+       /* retrieve results */

-       /* commit statement */
-       OCI_Commit(idi->dbinfo.oci_connection);
+       //free lobs
+       if (lob_i != NULL) OCI_LobFree(lob_i);

This whitespace removal is also not correct according to our code style. Makes the diff huge though.

-       if (!OCI_BindUnsignedInt(idi->dbinfo.oci_statement_logentries_insert, MT(":X1"), (uint *) data[0])) {
+       if (!OCI_BindUnsignedInt(idi->dbinfo.oci_statement_logentries_insert, MT(":X1"),(uint *) data[0])) {

Further, if you remove obsolete code please do so entirely. Commenting it out will turn into confusion.

-       data[8] = (void *) &object_id;
+//     data[8] = (void *) &object_id;

indention is not consistent across many files. It may look nasty, but caused by different tools used for editing which are interpreting the spaces in a different way.

That argument is invalid, sorry. Just because the current indent quality is not good does not qualify your commit for making it worse. Indentation is something I've been fixing for years and it is something we should not give up at this stage of Icinga development.

There are several editors out there treating tabs and spaces right. vim does that for example, and Komodo Edit with tabs = 8 spaces as well.

Probably if you're using vim/git you would also want to highlight extra whitespaces.

http://www.legendiary.at/2010/07/13/removeshow-trailing-whitespaces-with-vim/
http://www.legendiary.at/2013/06/24/detect-trailing-whitespaces-in-vim-revisited/
http://www.legendiary.at/2014/06/14/remove-trailing-whitespaces-on-save-in-komodo-edit-8/

Kind regards,
Michael

[icinga-migration]

Updated by berk on 2015-05-18 12:17:55 +00:00

• Target Version set to Backlog

[icinga-migration]

Updated by mfriedrich on 2015-08-04 19:00:53 +00:00

Any updates on this?

[icinga-migration]

Updated by Tommi on 2015-08-09 19:03:30 +00:00

not really. started, but busy with $work.