[ZBX-11213] DB Monitoring stopped working after upgrade to 3.2 Created: 2016 Sep 15 Updated: 2018 Jul 05 Resolved: 2016 Sep 30 |
|
Status: | Closed |
Project: | ZABBIX BUGS AND ISSUES |
Component/s: | Proxy (P), Server (S) |
Affects Version/s: | 3.2.0 |
Fix Version/s: | 2.2.16rc1, 3.0.6rc1, 3.2.2rc1, 3.4.0alpha1 |
Type: | Incident report | Priority: | Critical |
Reporter: | Alessandro Mariotti | Assignee: | Unassigned |
Resolution: | Fixed | Votes: | 6 |
Labels: | odbc, regression | ||
Remaining Estimate: | Not Specified | ||
Time Spent: | Not Specified | ||
Original Estimate: | Not Specified | ||
Environment: |
Virtual Machine (vSphere 5.5) Running CentOS7 x64 |
Attachments: | ZBX-11213.patch snapshot01.png | ||||||||||||||||||||||||||||||||||||
Issue Links: |
|
Description |
I have some item which query an Oracle DB. After upgrading to 3.2 from 3.0 (no issues regarding my zabbix postgresql DB upgrade) I have found that my ODBC Item is not working anymore. I perform simple query against an Oracle (RAC) user table using odbc. the same sql using isql is working fine: SELECT count (*),trunc(first_time) FROM v$loghist a where trunc( first_time)=trunc(sysdate) and THREAD# =1 group by trunc(first_time); This sql is used as item in db monitoring. Before upgrading it was working fine. With Best Regards, Alessandro |
Comments |
Comment by Alessandro Mariotti [ 2016 Sep 15 ] |
I forgot to put logs recorde in zabbix_server.log: 20850:20160915:160911.863 error reason for "BECSVR-X64RAC01:db.odbc.select[ArchiveLogPerHour,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] Thank you. |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 15 ] |
What do you mean by "not working"? What is the result of isql query? |
Comment by Alessandro Mariotti [ 2016 Sep 15 ] |
Sorry for not specifying better. I just receive an error on the format returned by query. The log written are similar to the following: Keep in mind that in all my sql I fetch to return just integer values. Before upgrading zabbix I also updated the system using yum update; 20850:20160915:160911.863 error reason for "BECSVR-X64RAC01:db.odbc.select[ArchiveLogPerHour,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20847:20160915:160914.156 error reason for "BECSVR-X64RAC01:db.odbc.select[UpTime,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20847:20160915:161211.446 error reason for "BECSVR-X64RAC01:db.odbc.select[FRAFreeSpaceLeft,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20846:20160915:161212.448 error reason for "BECSVR-X64RAC01:db.odbc.select[TBS_CARUSOLOG_usage,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20850:20160915:161213.448 error reason for "BECSVR-X64RAC01:db.odbc.select[TBS_SGR_DOC_usage,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20850:20160915:161215.463 error reason for "BECSVR-X64RAC01:db.odbc.select[TBS_SUITE_HIST_DATA_usage,RACDB1]" changed: Received value [?p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20848:20160915:161216.467 error reason for "BECSVR-X64RAC01:db.odbc.select[TBS_SUITE_usage,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20827:20160915:161342.540 cannot send list of active checks to "10.0.104.116": host [BECSVR-ORA10G] not monitored 20846:20160915:161538.645 error reason for "BECSVR-X64RAC01:db.odbc.select[ArchiveLogPerDay,RACDB1]" changed: Received value [Ø·p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20848:20160915:161632.940 error reason for "BECSVR-X64RAC01:db.odbc.select[H_SPE_ROWs,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20850:20160915:161633.957 error reason for "BECSVR-X64RAC01:db.odbc.select[ScribblingROWs,RACDB1]" changed: Received value ?p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20847:20160915:161635.969 error reason for "BECSVR-X64RAC01:db.odbc.select[H_GRT_CART_RADIO_ROWs,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20850:20160915:161637.978 error reason for "BECSVR-X64RAC01:db.odbc.select[h_rvd_griremovalvehdatas_ROWs,RACDB1]" changed: Received value [Ø·p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20846:20160915:161724.306 error reason for "BECSVR-X64RAC01:db.odbc.select[DATAFreeSpaceLeft,RACDB1]" changed: Received value [?p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20848:20160915:161726.318 error reason for "BECSVR-X64RAC01:db.odbc.select[DATASATAFreeSpaceLeft,RACDB1]" changed: Received value [??p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 20825:20160915:161842.570 cannot send list of active checks to "10.0.104.116": host [BECSVR-ORA10G] not monitored 20848:20160915:161912.030 error reason for "BECSVR-X64RAC01:db.odbc.select[ArchiveLogPerHour,RACDB1]" changed: Received value [?p] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] |
Comment by Alessandro Mariotti [ 2016 Sep 15 ] |
isql launched under user zabbix returns correct values: +---------------------------------------+ | Connected! | | | | sql-statement | | help [tablename] | | quit | | | +---------------------------------------+ SQL> SELECT count(*),trunc(first_time) FROM v$loghist a where trunc( first_time)=trunc(sysdate) and THREAD# =1 group by trunc(first_time); +-----------------------------------------+--------------------+ | COUNT(*) | TRUNC(FIRST_TIME) | +-----------------------------------------+--------------------+ | 9 | 2016-09-15 00:00:00| +-----------------------------------------+--------------------+ SQLRowCount returns -1 1 rows fetched SQL> |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 15 ] |
Looks like it is encoding-related... Just checking... Same versions of UnixODBC and Oracle ODBC driver for 3.0 and 3.2? |
Comment by Alessandro Mariotti [ 2016 Sep 15 ] |
Well I haven't changed Oracle ODBC version which is the same as previous installation: and this is the content of odbc.ini: [RACDB1] Unfortunately that trace file does not exist |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 15 ] |
Can you run isql as zabbix user? What are locale settings for zabbix user? I can see only one change related to ODBC in ChangeLog between 3.0.4 and 3.2.0, namely |
Comment by Alessandro Mariotti [ 2016 Sep 15 ] |
Sure: the following are some commands: su - zabbix Last login: Thu Sep 15 17:21:32 CEST 2016 on pts/0 -bash-4.2$ env XDG_SESSION_ID=1 HOSTNAME=pasrv-zabbix SHELL=/bin/bash TERM=xterm HISTSIZE=1000 USER=zabbix LD_LIBRARY_PATH=/usr/lib/oracle/12.1/client64/lib LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;05;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.axa=01;36:*.oga=01;36:*.spx=01;36:*.xspf=01;36: TNS_ADMIN=/usr/lib/oracle/12.1/client64/bin MAIL=/var/spool/mail/zabbix PATH=/usr/lib/oracle/12.1/client64/bin:/usr/lib/oracle/12.1/client64/lib:/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin PWD=/home/zabbix LANG=en_US.UTF-8 HISTCONTROL=ignoredups SHLVL=1 HOME=/home/zabbix LOGNAME=zabbix LESSOPEN=||/usr/bin/lesspipe.sh %s ORACLE_HOME=/usr/lib/oracle/12.1/client64 _=/bin/env -bash-4.2$ locale LANG=en_US.UTF-8 LC_CTYPE="en_US.UTF-8" LC_NUMERIC="en_US.UTF-8" LC_TIME="en_US.UTF-8" LC_COLLATE="en_US.UTF-8" LC_MONETARY="en_US.UTF-8" LC_MESSAGES="en_US.UTF-8" LC_PAPER="en_US.UTF-8" LC_NAME="en_US.UTF-8" LC_ADDRESS="en_US.UTF-8" LC_TELEPHONE="en_US.UTF-8" LC_MEASUREMENT="en_US.UTF-8" LC_IDENTIFICATION="en_US.UTF-8" LC_ALL= -bash-4.2$ isql -v racdb1 spotlight traff1c0 +---------------------------------------+ | Connected! | | | | sql-statement | | help [tablename] | | quit | | | +---------------------------------------+ SQL> select count(*) from gv$session where user# not in (0) and inst_id=1; +-----------------------------------------+ | COUNT(*) | +-----------------------------------------+ | 64 | +-----------------------------------------+ SQLRowCount returns -1 1 rows fetched SQL> |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 15 ] |
Thank you for the information! This line is suspicious: SQLRowCount returns -1 I'm not an expert in Oracle configuration, but shouldn't NLS_LANG variable be set for correct results? Could you provide us with a piece of log file where Zabbix performs ODBC item polling at DebugLevel=4? (You can enable it specifically for unreachable poller at runtime.) |
Comment by Alessandro Mariotti [ 2016 Sep 15 ] |
Sorry can you explain better where should I enable that setting? Is it a zabbix related setting or ODBC related? and which logfile? Zabbix? Thank you |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 15 ] |
NLS_LANG is environment variable from which Oracle derives locale settings. Yes, Zabbix log file. Either set DebugLevel=4 in configuration file or use zabbix_server -R log_level_increase="unreachable poller" (see section "Runtime control" here for details). |
Comment by Yustas [ 2016 Sep 16 ] |
I have exactly same issue, and the strange thing is: PostgreSQl ODBC items fails with same error. Received value [???/] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] |
Comment by Anton Alekseev [ 2016 Sep 16 ] |
Hello, I was able to reproduce the bug. The same db (Oracle 11.2.0.4), the same query. Before upgrade (zabbix 3.0.3): 2511:20160916:140622.057 In substitute_key_macros() data:'db.odbc.select[host.cpu.pct,{HOST.HOST}]' 2511:20160916:140622.058 In substitute_simple_macros() data:'{HOST.HOST}' 2511:20160916:140622.058 End substitute_simple_macros() data:'ora.zabbix.example.com_zabdb' 2511:20160916:140622.058 End of substitute_key_macros():SUCCEED data:'db.odbc.select[host.cpu.pct,ora.zabbix.example.com_zabdb]' 2511:20160916:140622.058 In substitute_simple_macros() data:'select value from v$sysmetric where metric_name = 'Host CPU Utilization (%)' and group_id=2;' 2511:20160916:140622.058 In substitute_simple_macros() data:'{$ORA_USER}' 2511:20160916:140622.058 In DCget_user_macro() macro:'{$ORA_USER}' 2511:20160916:140622.058 End of DCget_user_macro() 2511:20160916:140622.058 End substitute_simple_macros() data:'user' 2511:20160916:140622.058 In substitute_simple_macros() data:'{$ORA_PASS}' 2511:20160916:140622.058 In DCget_user_macro() macro:'{$ORA_PASS}' 2511:20160916:140622.058 End of DCget_user_macro() 2511:20160916:140622.058 End substitute_simple_macros() data:'password' 2511:20160916:140622.058 In get_value() key:'db.odbc.select[host.cpu.pct,{HOST.HOST}]' 2511:20160916:140622.058 In get_value_db() key_orig:'db.odbc.select[host.cpu.pct,{HOST.HOST}]' 2511:20160916:140622.058 In db_odbc_select() query:'select value from v$sysmetric where metric_name = 'Host CPU Utilization (%)' and group_id=2;' 2511:20160916:140622.058 In odbc_DBconnect() db_dsn:'ora.zabbix.example.com_zabdb' user:'user' 2511:20160916:140622.084 End of odbc_DBconnect():SUCCEED 2511:20160916:140622.084 In odbc_DBselect() query:'select value from v$sysmetric where metric_name = 'Host CPU Utilization (%)' and group_id=2;' 2511:20160916:140622.085 odbc_DBselect() selected 1 columns 2511:20160916:140622.085 End of odbc_DBselect() 2511:20160916:140622.085 In odbc_DBfetch() 2511:20160916:140622.087 odbc_DBfetch() fetched [0 col]: '15.3513971210838' 2511:20160916:140622.087 End of odbc_DBfetch() 2511:20160916:140622.089 End of db_odbc_select():SUCCEED 2511:20160916:140622.089 End of get_value_db():SUCCEED 2511:20160916:140622.089 End of get_value():SUCCEED 2511:20160916:140622.089 In activate_host() hostid:10108 itemid:345412 type:11 2511:20160916:140622.089 End of activate_host() 2511:20160916:140622.089 End of get_values():1 After upgrade (zabbix 3.2.0): 17007:20160916:143334.579 In substitute_key_macros() data:'db.odbc.select[host.cpu.pct,{HOST.HOST}]' 17007:20160916:143334.579 In substitute_simple_macros() data:'{HOST.HOST}' 17007:20160916:143334.579 End substitute_simple_macros() data:'ora.zabbix.example.com_zabdb' 17007:20160916:143334.579 End of substitute_key_macros():SUCCEED data:'db.odbc.select[host.cpu.pct,ora.zabbix.example.com_zabdb]' 17007:20160916:143334.579 In substitute_simple_macros() data:'select value from v$sysmetric where metric_name = 'Host CPU Utilization (%)' and group_id=2;' 17007:20160916:143334.579 In substitute_simple_macros() data:'{$ORA_USER}' 17007:20160916:143334.579 In DCget_user_macro() macro:'{$ORA_USER}' 17007:20160916:143334.579 End of DCget_user_macro() 17007:20160916:143334.579 End substitute_simple_macros() data:'user' 17007:20160916:143334.579 In substitute_simple_macros() data:'{$ORA_PASS}' 17007:20160916:143334.579 In DCget_user_macro() macro:'{$ORA_PASS}' 17007:20160916:143334.579 End of DCget_user_macro() 17007:20160916:143334.579 End substitute_simple_macros() data:'password' 17007:20160916:143334.579 In get_value() key:'db.odbc.select[host.cpu.pct,{HOST.HOST}]' 17007:20160916:143334.579 In get_value_db() key_orig:'db.odbc.select[host.cpu.pct,{HOST.HOST}]' 17007:20160916:143334.579 In db_odbc_select() query:'select value from v$sysmetric where metric_name = 'Host CPU Utilization (%)' and group_id=2;' 17007:20160916:143334.579 In odbc_DBconnect() db_dsn:'ora.zabbix.example.com_zabdb' user:'user' 17007:20160916:143334.655 End of odbc_DBconnect():SUCCEED 17007:20160916:143334.655 In odbc_DBselect() query:'select value from v$sysmetric where metric_name = 'Host CPU Utilization (%)' and group_id=2;' 17007:20160916:143334.657 odbc_DBselect() selected 1 columns 17007:20160916:143334.657 End of odbc_DBselect() 17007:20160916:143334.657 In odbc_DBfetch() 17007:20160916:143334.665 odbc_Diag(): rc_msg:'SQL_SUCCESS_WITH_INFO' rec_nr:1 sql_state:'01004' native_err_code:0 err_msg:'[Oracle][ODBC]String data, right truncated.' 17007:20160916:143334.666 odbc_DBfetch() fetched [0 col]: ▒▒d<' 17007:20160916:143334.666 End of odbc_DBfetch() 17007:20160916:143334.669 End of db_odbc_select():NOTSUPPORTED 17007:20160916:143334.669 End of get_value_db():NOTSUPPORTED 17007:20160916:143334.669 Item [ora.zabbix.example.com_zabdb:db.odbc.select[host.cpu.pct,{HOST.HOST}]] error: Received value ??d<] is not suitable for value type [Numeric (float)] 17007:20160916:143334.669 End of get_value():NOTSUPPORTED Setting NLS_LANG produces no effect. IMHO it wasn't supposed to, since we were asking for numeric data. As far as I could dig out, reversing the following change at odbc_DBselect (src/libs/zbxdbhigh/odbc.c) helps to get rid of the problem: < MAX_STRING_LEN, &pdbh->data_len[i]), rc, SQL_HANDLE_STMT, pdbh->hstmt, --- > pdbh->data_len[i], &pdbh->data_len[i]), rc, SQL_HANDLE_STMT, pdbh->hstmt, Seems like Oracle (and possibly PostgreSQL) ODBC driver sets buffer length to 0 during SQLColAttribute(..., SQL_DESC_OCTET_LENGTH, ...), which is incorrect and leaves no buffer to fit selected value in. |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 16 ] |
Dear akint, huge thanks for the logs! Now it's clear that we allocate less space that is actually needed for column contents. Looks like SQLColAttribute() with SQL_DESC_OCTET_LENGTH parameter returns required size without null-terminator (some docs). Can you give this simple patch a try? Index: src/libs/zbxdbhigh/odbc.c =================================================================== --- src/libs/zbxdbhigh/odbc.c (revision 62566) +++ src/libs/zbxdbhigh/odbc.c (working copy) @@ -315,7 +315,7 @@ for (i = 0; i < pdbh->col_num; i++) { - pdbh->row_data[i] = zbx_malloc(NULL, pdbh->data_len[i]); + pdbh->row_data[i] = zbx_malloc(NULL, ++pdbh->data_len[i]); if (0 != CALLODBC(SQLBindCol(pdbh->hstmt, (SQLUSMALLINT)(i + 1), SQL_C_CHAR, pdbh->row_data[i], pdbh->data_len[i], &pdbh->data_len[i]), rc, SQL_HANDLE_STMT, pdbh->hstmt, "Cannot bind column in ODBC result")) |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 16 ] |
Really? This is not nice... Can you point me to their documentation or bug tracker or wherever this information comes from? |
Comment by Alessandro Mariotti [ 2016 Sep 16 ] |
Hello, concerning the following line: it returns the same values in zabbix 3.0.4 using isql. SQL> select count(*) from v$session; +-----------------------------------------+ | COUNT(*) | +-----------------------------------------+ | 18 | +-----------------------------------------+ SQLRowCount returns -1 1 rows fetched That "SQLRowCount returns -1" returns even if I select/fetch many rows like this: SQLRowCount returns -1 18 rows fetched SQL> I don't know if this information might be helpful or not. regards. |
Comment by Anton Alekseev [ 2016 Sep 19 ] |
glebs.ivanovskis, the patch you provided did not work: Oracle 12948:20160919:140029.776 In substitute_key_macros() data:'db.odbc.select[test,{HOST.HOST}]' 12948:20160919:140029.776 In substitute_simple_macros() data:'{HOST.HOST}' 12948:20160919:140029.776 End substitute_simple_macros() data:'Oracle' 12948:20160919:140029.776 End of substitute_key_macros():SUCCEED data:'db.odbc.select[test,Oracle]' 12948:20160919:140029.776 In substitute_simple_macros() data:'select 1 from dual /* {HOST.HOST} */' 12948:20160919:140029.776 End substitute_simple_macros() data:'select 1 from dual /* Oracle */' 12948:20160919:140029.776 In substitute_simple_macros() data:EMPTY 12948:20160919:140029.776 In substitute_simple_macros() data:EMPTY 12948:20160919:140029.776 In get_value() key:'db.odbc.select[test,{HOST.HOST}]' 12948:20160919:140029.776 In get_value_db() key_orig:'db.odbc.select[test,{HOST.HOST}]' 12948:20160919:140029.776 In db_odbc_select() query:'select 1 from dual /* Oracle */' 12948:20160919:140029.777 In odbc_DBconnect() db_dsn:'Oracle' user:'' 12948:20160919:140029.807 End of odbc_DBconnect():SUCCEED 12948:20160919:140029.807 In odbc_DBselect() query:'select 1 from dual /* Oracle */' 12948:20160919:140029.808 odbc_DBselect() selected 1 columns 12948:20160919:140029.808 End of odbc_DBselect() 12948:20160919:140029.808 In odbc_DBfetch() 12948:20160919:140029.809 odbc_Diag(): rc_msg:'SQL_SUCCESS_WITH_INFO' rec_nr:1 sql_state:'01004' native_err_code:0 err_msg:'[Oracle][ODBC]String data, right truncated.' 12948:20160919:140029.809 odbc_DBfetch() fetched [0 col]: '▒▒▒d<' 12948:20160919:140029.809 End of odbc_DBfetch() 12948:20160919:140029.811 End of db_odbc_select():NOTSUPPORTED 12948:20160919:140029.811 End of get_value_db():NOTSUPPORTED 12948:20160919:140029.811 Item [Oracle:db.odbc.select[test,{HOST.HOST}]] error: Received value [???d<] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 12948:20160919:140029.811 End of get_value():NOTSUPPORTED PostgreSQL 12947:20160919:140228.908 In substitute_key_macros() data:'db.odbc.select[test,{HOST.HOST}]' 12947:20160919:140228.908 In substitute_simple_macros() data:'{HOST.HOST}' 12947:20160919:140228.908 End substitute_simple_macros() data:'PostgreSQL' 12947:20160919:140228.908 End of substitute_key_macros():SUCCEED data:'db.odbc.select[test,PostgreSQL]' 12947:20160919:140228.908 In substitute_simple_macros() data:'select 1 /* {HOST.HOST} */' 12947:20160919:140228.908 End substitute_simple_macros() data:'select 1 /* PostgreSQL */' 12947:20160919:140228.909 In substitute_simple_macros() data:EMPTY 12947:20160919:140228.909 In substitute_simple_macros() data:EMPTY 12947:20160919:140228.909 In get_value() key:'db.odbc.select[test,{HOST.HOST}]' 12947:20160919:140228.909 In get_value_db() key_orig:'db.odbc.select[test,{HOST.HOST}]' 12947:20160919:140228.910 In db_odbc_select() query:'select 1 /* PostgreSQL */' 12947:20160919:140228.911 In odbc_DBconnect() db_dsn:'PostgreSQL' user:'' 12947:20160919:140228.928 End of odbc_DBconnect():SUCCEED 12947:20160919:140228.928 In odbc_DBselect() query:'select 1 /* PostgreSQL */' 12947:20160919:140228.929 odbc_DBselect() selected 1 columns 12947:20160919:140228.929 End of odbc_DBselect() 12947:20160919:140228.929 In odbc_DBfetch() 12947:20160919:140228.929 odbc_Diag(): rc_msg:'SQL_SUCCESS_WITH_INFO' rec_nr:1 sql_state:'01004' native_err_code:-2 err_msg:'Fetched item was truncated.' 12947:20160919:140228.929 odbc_DBfetch() fetched [0 col]: '<D8><FE><98>d<' 12947:20160919:140228.929 End of odbc_DBfetch() 12947:20160919:140228.929 End of db_odbc_select():NOTSUPPORTED 12947:20160919:140228.930 End of get_value_db():NOTSUPPORTED 12947:20160919:140228.930 Item [PostgreSQL:db.odbc.select[test,{HOST.HOST}]] error: Received value [???d<] is not suitable for value type [Numeric (unsigned)] and data type [Decimal] 12947:20160919:140228.930 End of get_value():NOTSUPPORTED |
Comment by Anton Alekseev [ 2016 Sep 19 ] |
glebs.ivanovskis, I have slightly modified odbc_DBselect for debugging purposes: diff --git a/src/libs/zbxdbhigh/odbc.c b/src/libs/zbxdbhigh/odbc.c index 9678bb9..1db3e6d 100644 --- a/src/libs/zbxdbhigh/odbc.c +++ b/src/libs/zbxdbhigh/odbc.c @@ -281,7 +281,7 @@ ZBX_ODBC_RESULT odbc_DBselect(ZBX_ODBC_DBH *pdbh, char *query) ZBX_ODBC_RESULT result = NULL; SQLRETURN rc; - zabbix_log(LOG_LEVEL_DEBUG, "In %s() query:'%s'", __function_name, query); + zabbix_log(LOG_LEVEL_INFORMATION, "In %s() query:'%s'", __function_name, query); clean_odbc_strerror(); @@ -309,6 +309,7 @@ ZBX_ODBC_RESULT odbc_DBselect(ZBX_ODBC_DBH *pdbh, char *query) { goto end; } + zabbix_log(LOG_LEVEL_INFORMATION, "%s() data_len[%i]'s value after SQLColAttribute = %i", __function_name, i, pdbh->data_len[i]); } pdbh->row_data = zbx_malloc(pdbh->row_data, sizeof(char *) * (size_t)pdbh->col_num); @@ -317,11 +318,13 @@ ZBX_ODBC_RESULT odbc_DBselect(ZBX_ODBC_DBH *pdbh, char *query) { pdbh->row_data[i] = zbx_malloc(NULL, pdbh->data_len[i]); if (0 != CALLODBC(SQLBindCol(pdbh->hstmt, (SQLUSMALLINT)(i + 1), SQL_C_CHAR, pdbh->row_data[i], - pdbh->data_len[i], &pdbh->data_len[i]), rc, SQL_HANDLE_STMT, pdbh->hstmt, + MAX_STRING_LEN, &pdbh->data_len[i]), rc, SQL_HANDLE_STMT, pdbh->hstmt, "Cannot bind column in ODBC result")) { goto end; } + zabbix_log(LOG_LEVEL_INFORMATION, "%s() data_len[%i]'s value after SQLBindCol = %i", __function_name, i, pdbh->data_len[i]); + zabbix_log(LOG_LEVEL_INFORMATION, "%s() row_data[%i]'s actual length = %i", __function_name, i, sizeof(pdbh->row_data[i])); } zabbix_log(LOG_LEVEL_DEBUG, "%s() selected %i columns", __function_name, pdbh->col_num); After that I got the following messages in logs: 9259:20160919:124148.374 In odbc_DBselect() query:'select 1 /* PostgreSQL */' 9259:20160919:124148.375 odbc_DBselect() data_len[0]'s value after SQLColAttribute = 0 9259:20160919:124148.379 odbc_DBselect() data_len[0]'s value after SQLBindCol = 0 9259:20160919:124148.379 odbc_DBselect() row_data[0]'s actual length = 8 9263:20160919:124148.404 In odbc_DBselect() query:'select 1 from dual /* MySQL */' 9263:20160919:124148.405 odbc_DBselect() data_len[0]'s value after SQLColAttribute = 20 9263:20160919:124148.405 odbc_DBselect() data_len[0]'s value after SQLBindCol = 20 9263:20160919:124148.405 odbc_DBselect() row_data[0]'s actual length = 8 9261:20160919:124148.409 In odbc_DBselect() query:'select 1 from dual /* Oracle */' 9261:20160919:124148.410 odbc_DBselect() data_len[0]'s value after SQLColAttribute = 0 9261:20160919:124148.410 odbc_DBselect() data_len[0]'s value after SQLBindCol = 0 9261:20160919:124148.410 odbc_DBselect() row_data[0]'s actual length = 8 The only thing I could found about SQL_DESC_OCTET_LENGTH is this post:
|
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 19 ] |
Dear akint, this is very valuable information! As you can see, the problem is not entirely on Zabbix side. Please consider filing bug reports for Oracle and PostgreSQL ODBC driver maintainers. This is sad, but I guess we need to allocate the minimum of MAX_STRING_LEN and SQLColAttribute(..., SQL_DESC_OCTET_LENGTH, ...) to work around such driver behaviour. |
Comment by Denis Legostaev [ 2016 Sep 19 ] |
Could this also be the reason for this problem: https://www.zabbix.com/forum/showthread.php?p=189369 ? |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 19 ] |
Yes, looks like so. |
Comment by Eric [ 2016 Sep 20 ] |
Hi all, for information, I have this issue with odbc request on an Oracle 11 db server. This issue sometimes freeze zabbix server, I activate debug log, but nothing more than de the log in this bug report. I disable all odbc item and I don't have freeze anymore... |
Comment by Ilya Dinmukhametov [ 2016 Sep 21 ] |
Hello, glebs.ivanovskis This looks like the same problem with use Zabbix 3.2.0 (unixODBC + FreeTDS): 1. /etc/odbcinst.ini [FreeTDS] Description=TDS driver (Sybase/MS SQL) Driver=libtdsodbc.so Setup=libtdsS.so CPTimeout= CPReuse= UsageCount=4 2. Check connect isql -v smv ZabbixMonitoring Passwd +---------------------------------------+ | Connected! | | | | sql-statement | | help [tablename] | | quit | | | +---------------------------------------+ SQL> select sum(PostsCount) as PostsCount from [Buzz_Aggregates2].[dbo].[PostLimits] (nolock) where UserId = 1 and ReportId = 282 and [Timestamp] > dateadd(hour, -1, getutcdate()) +------------+ | PostsCount | +------------+ | 2110 | +------------+ 3. Debug info from zabbix_server.log 43914:20160920:180729.745 In substitute_simple_macros() data:'select sum(PostsCount) as PostsCount from [Buzz_Aggregates2].[dbo].[PostLimits] (nolock) where UserId = 1 and ReportId = 282 and [Timestamp] > dateadd(hour, -1, getutcdate())' 43914:20160920:180729.745 In substitute_simple_macros() data:'{$ZABBIX_L}' 43914:20160920:180729.745 In DCget_user_macro() macro:'{$ZABBIX_L}' 43914:20160920:180729.745 End of DCget_user_macro() 43914:20160920:180729.746 End substitute_simple_macros() data:'ZabbixMonitoring' 43914:20160920:180729.746 In substitute_simple_macros() data:'{$ZABBIX_P}' 43914:20160920:180729.746 In DCget_user_macro() macro:'{$ZABBIX_P}' 43914:20160920:180729.746 End of DCget_user_macro() 43914:20160920:180729.746 End substitute_simple_macros() data:'Passwd' 43914:20160920:180729.746 In get_value() key:'db.odbc.select[BzzUserDelay3,{$BLOGANSPRODDSN}]' 43914:20160920:180729.746 In get_value_db() key_orig:'db.odbc.select[BzzUserDelay3,{$BLOGANSPRODDSN}]' 43914:20160920:180729.746 In db_odbc_select() query:'select sum(PostsCount) as PostsCount from [Buzz_Aggregates2].[dbo].[PostLimits] (nolock) where UserId = 1 and ReportId = 282 and [Timestamp] > dateadd(hour, -1, getutcdate())' 43914:20160920:180729.746 In odbc_DBconnect() db_dsn:'smv' user:'ZabbixMonitoring' 43914:20160920:180729.780 End of odbc_DBconnect():SUCCEED 43914:20160920:180729.780 In odbc_DBselect() query:'select sum(PostsCount) as PostsCount from [Buzz_Aggregates2].[dbo].[PostLimits] (nolock) where UserId = 1 and ReportId = 282 and [Timestamp] > dateadd(hour, -1, getutcdate())' 43914:20160920:180729.794 odbc_DBselect() selected 1 columns 43914:20160920:180729.794 End of odbc_DBselect() 43914:20160920:180729.794 In odbc_DBfetch() 43914:20160920:180729.794 odbc_Diag(): rc_msg:'SQL_SUCCESS_WITH_INFO' rec_nr:1 sql_state:'01004' native_err_code:0 err_msg:'[FreeTDS][SQL Server]Data truncated' 43914:20160920:180729.794 odbc_DBfetch() fetched [0 col]: '211' 43914:20160920:180729.794 End of odbc_DBfetch() 43914:20160920:180729.796 End of db_odbc_select():SUCCEED 43914:20160920:180729.796 End of get_value_db():SUCCEED 43914:20160920:180729.796 End of get_value():SUCCEED 43914:20160920:180729.796 In activate_host() hostid:10547 itemid:46889 type:11 43914:20160920:180729.796 End of activate_host() 43914:20160920:180729.796 End of get_values():1 43914:20160920:180729.796 In get_values() 43914:20160920:180729.796 In DCconfig_get_poller_items() poller_type:0 43914:20160920:180729.797 End of DCconfig_get_poller_items():1 |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 21 ] |
Dear ericm, I think your issue is a bit different. Please consider creating a separate bug report. Dear idinmukhametov, thank you for sharing this information. Seems that in your case situation is not that bad (only the last character is truncated) and a simple fix I posted earlier can solve your problem. |
Comment by Ilya Dinmukhametov [ 2016 Sep 21 ] |
Dear glebs.ivanovskis odbc_Diag(): rc_msg:'SQL_SUCCESS_WITH_INFO' rec_nr:1 sql_state:'01004' native_err_code:0 err_msg:'[FreeTDS][SQL Server]Data truncated' tail -f zabbix_server.log | grep odbc_DBfetch 7234:20160921:162130.934 odbc_DBfetch() fetched [0 col]: '290' 7234:20160921:162130.934 End of odbc_DBfetch() 7237:20160921:162140.317 In odbc_DBfetch() 7237:20160921:162140.317 odbc_DBfetch() fetched [0 col]: '185' 7237:20160921:162140.317 End of odbc_DBfetch() 7236:20160921:162149.118 In odbc_DBfetch() 7236:20160921:162149.118 odbc_DBfetch() fetched [0 col]: '643' 7236:20160921:162149.118 End of odbc_DBfetch() 7238:20160921:162208.326 In odbc_DBfetch() 7238:20160921:162208.326 odbc_DBfetch() fetched [0 col]: '140' 7238:20160921:162208.326 End of odbc_DBfetch() 7237:20160921:162208.983 In odbc_DBfetch() 7237:20160921:162208.983 odbc_DBfetch() fetched [0 col]: '366' 7237:20160921:162208.984 End of odbc_DBfetch() 7234:20160921:162211.054 In odbc_DBfetch() 7234:20160921:162211.054 odbc_DBfetch() fetched [0 col]: '291' 7234:20160921:162211.055 End of odbc_DBfetch() 7236:20160921:162211.349 In odbc_DBfetch() 7236:20160921:162211.349 odbc_DBfetch() fetched [0 col]: '419' 7236:20160921:162211.349 End of odbc_DBfetch() 7238:20160921:162212.128 In odbc_DBfetch() 7238:20160921:162212.128 odbc_DBfetch() fetched [0 col]: '116' 7238:20160921:162212.128 End of odbc_DBfetch() 7236:20160921:162216.581 In odbc_DBfetch() 7236:20160921:162216.581 odbc_DBfetch() fetched [0 col]: '328' 7236:20160921:162216.581 End of odbc_DBfetch() 7234:20160921:162217.624 In odbc_DBfetch() 7234:20160921:162217.624 odbc_DBfetch() fetched [0 col]: '204' |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 21 ] |
Dear idinmukhametov, so far you've shown that 4 character result "2110" gets truncated to 3 character "211" and that other (unknown to me) results get truncated to 3 characters too. To prove that I am wrong regarding last character truncation, please provide an example where more that 4 character result gets truncated to 3 characters by Zabbix. |
Comment by Ilya Dinmukhametov [ 2016 Sep 21 ] |
Dear glebs.ivanovskis root@:~# isql -v pzmvblog ZabbixMonitoring Pass +---------------------------------------+ | Connected! | | | | sql-statement | | help [tablename] | | quit | | | +---------------------------------------+ SQL> select [Value] = Cnt from [ADMIN].dbo.PostDeleteForZabbix +------------+ | Value | +------------+ | 25478790 | +------------+ SQLRowCount returns 1 1 rows fetched 26975:20160921:170859.007 In get_value() key:'db.odbc.select[GetPrizmaPostForDelete,pzmvblog]' 26975:20160921:170859.007 In get_value_db() key_orig:'db.odbc.select[GetPrizmaPostForDelete,pzmvblog]' 26975:20160921:170859.007 In db_odbc_select() query:'select [Value] = Cnt from [ADMIN].dbo.PostDeleteForZabbix' 26975:20160921:170859.007 In odbc_DBconnect() db_dsn:'pzmvblog' user:'ZabbixMonitoring' 26975:20160921:170859.066 End of odbc_DBconnect():SUCCEED 26975:20160921:170859.066 In odbc_DBselect() query:'select [Value] = Cnt from [ADMIN].dbo.PostDeleteForZabbix' 26975:20160921:170859.071 odbc_DBselect() selected 1 columns 26975:20160921:170859.071 End of odbc_DBselect() 26975:20160921:170859.071 In odbc_DBfetch() 26975:20160921:170859.071 odbc_Diag(): rc_msg:'SQL_SUCCESS_WITH_INFO' rec_nr:1 sql_state:'01004' native_err_code:0 err_msg:'[FreeTDS][SQL Server]Data truncated' 26975:20160921:170859.071 odbc_DBfetch() fetched [0 col]: '254' 26975:20160921:170859.071 End of odbc_DBfetch() 26975:20160921:170859.075 End of db_odbc_select():SUCCEED 26975:20160921:170859.075 End of get_value_db():SUCCEED 26975:20160921:170859.075 End of get_value():SUCCEED |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 21 ] |
Thank you! |
Comment by Ilya Dinmukhametov [ 2016 Sep 21 ] |
Dear glebs.ivanovskis, |
Comment by Glebs Ivanovskis (Inactive) [ 2016 Sep 21 ] |
I am attaching the patch which reverts destructive |
Comment by Anton Alekseev [ 2016 Sep 22 ] |
glebs.ivanovskis, I have done some more digging, hopefully it could save some time for you.
https://msdn.microsoft.com/en-us/library/ms711786(v=vs.85).aspx
So it seems that returning zero as SQL_DESC_OCTET_LENGTH for numeric types is a correct behaviour. But even for those, who returns actual size in bytes, I suppose, the length of character representation should be taken, since all columns are bound as an SQL_C_CHAR. I have done some tests:
A bit strange, that PostgreSQL didn't give precision for int4 type, but it seems to me that SQLDescribeCol probably may be considered as a source of column's size. I have tested it like this and it seems to be working for me: diff --git a/src/libs/zbxdbhigh/odbc.c b/src/libs/zbxdbhigh/odbc.c index 9678bb9..a666c81 100644 --- a/src/libs/zbxdbhigh/odbc.c +++ b/src/libs/zbxdbhigh/odbc.c @@ -303,8 +303,8 @@ ZBX_ODBC_RESULT odbc_DBselect(ZBX_ODBC_DBH *pdbh, char *query) for (i = 0; i < pdbh->col_num; i++) { - if (0 != CALLODBC(SQLColAttribute(pdbh->hstmt, (SQLUSMALLINT)(i + 1), SQL_DESC_OCTET_LENGTH, NULL, 0, - NULL, &pdbh->data_len[i]), rc, SQL_HANDLE_STMT, pdbh->hstmt, + if (0 != CALLODBC(SQLDescribeCol(pdbh->hstmt, (SQLUSMALLINT)(i + 1), NULL, 0, + NULL, NULL, &pdbh->data_len[i], NULL, NULL), rc, SQL_HANDLE_STMT, pdbh->hstmt, "Cannot execute ODBC query")) { goto end; @@ -315,7 +315,7 @@ ZBX_ODBC_RESULT odbc_DBselect(ZBX_ODBC_DBH *pdbh, char *query) for (i = 0; i < pdbh->col_num; i++) { - pdbh->row_data[i] = zbx_malloc(NULL, pdbh->data_len[i]); + pdbh->row_data[i] = zbx_malloc(NULL, ++pdbh->data_len[i]); if (0 != CALLODBC(SQLBindCol(pdbh->hstmt, (SQLUSMALLINT)(i + 1), SQL_C_CHAR, pdbh->row_data[i], pdbh->data_len[i], &pdbh->data_len[i]), rc, SQL_HANDLE_STMT, pdbh->hstmt, "Cannot bind column in ODBC result")) |
Comment by Andris Zeila [ 2016 Sep 22 ] |
I tried using SQLDescribeCol with larger data (80k) and it still returned 8190 column size. But we could use SQLGetData to retrieve data after fetching rather than binding columns. wiper Apparently it's not so simple. While using SQLGetData with SQL_C_CHAR type worked as expected with postgresql, mysql decided that converting text data to hex format is a good idea. |
Comment by Andris Zeila [ 2016 Sep 23 ] |
Fixed in development branch svn://svn.zabbix.com/branches/dev/ZBX-11213 |
Comment by Sandis Neilands (Inactive) [ 2016 Sep 27 ] |
The correction seems reasonable. We encourage proactive testing by community since there is still a risk that there are differing interpretations of the ODBC API (which admittedly is quite wide). As a mitigation for this risk (e.g. workaround) we could introduce hidden (by default) configuration parameters:
glebs.ivanovskis FYI isql uses the following logic: static SQLUINTEGER OptimalDisplayWidth( SQLHSTMT hStmt, SQLINTEGER nCol, int nUserWidth ) { SQLUINTEGER nLabelWidth = 10; SQLULEN nDataWidth = 10; SQLUINTEGER nOptimalDisplayWidth = 10; SQLCHAR szColumnName[MAX_DATA_WIDTH+1]; *szColumnName = '\0'; SQLColAttribute( hStmt, nCol, SQL_DESC_DISPLAY_SIZE, NULL, 0, NULL, (SQLLEN*)&nDataWidth ); SQLColAttribute( hStmt, nCol, SQL_DESC_LABEL, szColumnName, sizeof(szColumnName), NULL, NULL ); nLabelWidth = strlen((char*) szColumnName ); /* * catch sqlserver var(max) types */ if ( nDataWidth == 0 ) { nDataWidth = max_col_size; } nOptimalDisplayWidth = max( nLabelWidth, nDataWidth ); if ( nUserWidth > 0 ) nOptimalDisplayWidth = min( nOptimalDisplayWidth, nUserWidth ); if ( nOptimalDisplayWidth > max_col_size ) nOptimalDisplayWidth = max_col_size; return nOptimalDisplayWidth; } |
Comment by Sandis Neilands (Inactive) [ 2016 Sep 27 ] |
Tested. |
Comment by Anton Alekseev [ 2016 Sep 28 ] |
svn://svn.zabbix.com/branches/dev/ZBX-11213 contains the fix for v2.2. Am I right to guess that I have to wait until 3.2.1rc2 or 3.2.1 is released to test the fix on v3.2 database? sandis.neilands The correction will be merged to 3.0, 3.2, trunk branches shortly (you'll see message in this thread from wiper when this is done). If you compile from sources you don't have to wait until the official releases. |
Comment by Marvin [ 2016 Sep 30 ] |
When will this problem be solved? |
Comment by Andris Zeila [ 2016 Sep 30 ] |
Released in:
|
Comment by Marvin [ 2016 Sep 30 ] |
Thank you. And when the deb package will be made? |
Comment by Andris Zeila [ 2016 Sep 30 ] |
The fix is commited to the source brances, but will be included only in next releases. |
Comment by Mark Chan [ 2016 Nov 03 ] |
Could anyone tell me how to fix it by myself? Change code at somewhere? |
Comment by richlv [ 2016 Nov 08 ] |
mark.chan, you might want to discuss that in the channels listed at http://zabbix.org/wiki/Getting_help |
Comment by Mark Chan [ 2016 Nov 11 ] |
Thank you richlv, however my computer cannot connect to the channels=.=" |
Comment by Nikolay Samosvat [ 2016 Nov 11 ] |
This problem exists in version 3.0.5 (when using MSSQL): [SQL_ERROR] : [22003] [0] [Microsoft] [ODBC Driver 13 for SQL Server] Numeric value out of ] | |
Comment by Ruslan Eremenko [ 2016 Nov 13 ] |
[SQL_ERROR] : [22003] [0] [Microsoft] [ODBC Driver 13 for SQL Server] Numeric value out of ] |
Comment by Andris Zeila [ 2016 Nov 14 ] |
Yes,
means that the fix was merged in 3.0.6 release candidate branch and will be released with 3.0.6 If somebody wants to compile the 3.0.5 version with this fix:
|
Comment by Mariusz Litwińczuk [ 2016 Dec 05 ] |
Problem are still alive. More about this problem here: https://www.zabbix.com/forum/showpost.php?p=192795&postcount=14 |
Comment by Glebs Ivanovskis (Inactive) [ 2017 Oct 05 ] |
Just letting all the watchers know that ODBC code was refactored and hopefully improved in |