Uploaded image for project: 'ZABBIX BUGS AND ISSUES'
  1. ZABBIX BUGS AND ISSUES
  2. ZBX-19029

Missing lastlogsize information

    XMLWordPrintable

    Details

    • Team:
      Team A
    • Sprint:
      Sprint 73 (Feb 2021)
    • Story Points:
      1

      Description

      When logrt[/tmp/test.log,,,,skip,,,mtime-noreread] log item has JavaScript processing step like:

      var test = /555|666/;
      if (test.test(value)) {return null;}
      return value;
      

      Fields lastlogsize and mtime are not updated independent of result (new value or only metadata come).

      Item without processing step:
      agent log (active checks):

       2759:20210216:124659.529 In send_buffer() host:'zabbix-proxy-sqlite3' port:10051 entries:1/100
        2759:20210216:124659.529 JSON before sending [{"request":"agent data","session":"e8e4a10ad342f6f361a85a14f8df1383","data":[{"host":"zabbix_test","key":"logrt[/tmp/test.log,,,,skip,,,mtime-noreread]","value":"Tue Feb 16 12:46:54 EST 2021","lastlogsize":29,"mtime":1613497614,"id":9,"clock":1613497619,"ns":528956564}],"clock":1613497619,"ns":529549373}]
        2759:20210216:124659.529 JSON back [{"response":"success","info":"processed: 1; failed: 0; total: 1; seconds spent: 0.000087"}]
        2759:20210216:124659.529 In check_response() response:'{"response":"success","info":"processed: 1; failed: 0; total: 1; seconds spent: 0.000087"}'
      

      proxy log (history syncer):

         156:20210216:124700.526 In zbx_sync_history_cache() history_num:1
         156:20210216:124700.526 query [txnlev:1] [begin;]
         156:20210216:124700.526 In DCmass_proxy_add_history()
         156:20210216:124700.526 query [txnlev:1] [insert into proxy_history (itemid,clock,ns,timestamp,source,severity,value,logeventid,lastlogsize,mtime,flags,write_clock) values (32653,1613497619,528956564,0,'',0,'Tue Feb 16 12:46:54 EST 2021',0,29,1613497614,1,1613497620);
      ]
         159:20210216:124700.526 zbx_setproctitle() title:'history syncer #4 [processed 0 values in 0.000125 sec, syncing history]'
         159:20210216:124700.526 In zbx_sync_history_cache() history_num:1
         159:20210216:124700.526 zbx_setproctitle() title:'history syncer #4 [processed 0 values in 0.000082 sec, idle 1 sec]'
         158:20210216:124700.526 zbx_setproctitle() title:'history syncer #3 [processed 0 values in 0.000185 sec, syncing history]'
         158:20210216:124700.526 In zbx_sync_history_cache() history_num:1
         158:20210216:124700.526 zbx_setproctitle() title:'history syncer #3 [processed 0 values in 0.000033 sec, idle 1 sec]'
         156:20210216:124700.526 End of DCmass_proxy_add_history()
         156:20210216:124700.526 In DCmass_proxy_update_items()
         156:20210216:124700.526 query [txnlev:1] [update item_rtdata set lastlogsize=29,mtime=1613497614 where itemid=32653;
      ]
         156:20210216:124700.526 End of DCmass_proxy_update_items()
      

      Proxy DB:

      sqlite> select * from item_rtdata;
      32653|29|0|1613497614|
      sqlite> select * from proxy_history;
      8|32653|1613497619|0||0|Tue Feb 16 12:46:54 EST 2021|0|528956564|0|29|1613497614|1|1613497620
      

      Then processing step added. Sending values "test555test" and "test" (first one must be ignored):
      agent log:

        2759:20210216:125259.690 End of need_meta_update():FAIL
        2759:20210216:125259.690 In send_buffer() host:'zabbix-proxy-sqlite3' port:10051 entries:1/100
        2759:20210216:125259.691 JSON before sending [{"request":"agent data","session":"e8e4a10ad342f6f361a85a14f8df1383","data":[{"host":"zabbix_test","key":"logrt[/tmp/test.log,,,,skip,,,mtime-noreread]","value":"test555test","lastlogsize":41,"mtime":1613497960,"id":10,"clock":1613497979,"ns":690608163}],"clock":1613497979,"ns":691148160}]
        2759:20210216:125259.691 JSON back [{"response":"success","info":"processed: 1; failed: 0; total: 1; seconds spent: 0.000118"}]
        2759:20210216:125259.691 In check_response() response:'{"response":"success","info":"processed: 1; failed: 0; total: 1; seconds spent: 0.000118"}'
        2759:20210216:125259.691 info from server: 'processed: 1; failed: 0; total: 1; seconds spent: 0.000118'
      ....
        2759:20210216:125459.746 In send_buffer() host:'zabbix-proxy-sqlite3' port:10051 entries:1/100
        2759:20210216:125459.746 JSON before sending [{"request":"agent data","session":"e8e4a10ad342f6f361a85a14f8df1383","data":[{"host":"zabbix_test","key":"logrt[/tmp/test.log,,,,skip,,,mtime-noreread]","value":"test","lastlogsize":46,"mtime":1613498073,"id":11,"clock":1613498099,"ns":746200933}],"clock":1613498099,"ns":746754628}]
        2759:20210216:125459.747 JSON back [{"response":"success","info":"processed: 1; failed: 0; total: 1; seconds spent: 0.000109"}]
        2759:20210216:125459.747 In check_response() response:'{"response":"success","info":"processed: 1; failed: 0; total: 1; seconds spent: 0.000109"}'
        2759:20210216:125459.747 info from server: 'processed: 1; failed: 0; total: 1; seconds spent: 0.000109'
      

      proxy log:

         157:20210216:125300.687 In zbx_sync_history_cache() history_num:1
         157:20210216:125300.687 query [txnlev:1] [begin;]
         157:20210216:125300.687 In DCmass_proxy_add_history()
         157:20210216:125300.687 query [txnlev:1] [insert into proxy_history (itemid,clock,ns,value,flags,write_clock) values (32653,1613497979,690608163,'',2,1613497980);
      ]
         157:20210216:125300.688 End of DCmass_proxy_add_history()
      ...
         157:20210216:125500.743 In DCmass_proxy_add_history()
         157:20210216:125500.743 query [txnlev:1] [insert into proxy_history (itemid,clock,ns,timestamp,source,severity,value,logeventid,lastlogsize,mtime,flags,write_clock) values (32653,1613498099,746200933,0,'',0,'test',0,0,0,0,1613498100);
      ]
         157:20210216:125500.743 End of DCmass_proxy_add_history()
         157:20210216:125500.743 In DCmass_proxy_update_items()
         157:20210216:125500.743 End of DCmass_proxy_update_items()
         157:20210216:125500.743 query [txnlev:1] [commit;]
         157:20210216:125500.744 zbx_setproctitle() title:'history syncer #2 [processed 1 values in 0.001067 sec, idle 1 sec]'
      

      Proxy DB:

      sqlite> select * from item_rtdata;
      32653|29|0|1613497614|
      sqlite> select * from proxy_history;
      8|32653|1613497619|0||0|Tue Feb 16 12:46:54 EST 2021|0|528956564|0|29|1613497614|1|1613497620
      9|32653|1613497979|0||0||0|690608163|0|0|0|2|1613497980
      ...
      sqlite> select * from item_rtdata;
      32653|29|0|1613497614|
      sqlite> select * from proxy_history;
      8|32653|1613497619|0||0|Tue Feb 16 12:46:54 EST 2021|0|528956564|0|29|1613497614|1|1613497620
      9|32653|1613497979|0||0||0|690608163|0|0|0|2|1613497980
      10|32653|1613498099|0||0|test|0|746200933|0|0|0|0|1613498100
      

      So when such JavaScript processing is added, it does not matter value is filtered out or not, rttdata is not updated anymore.

        Attachments

          Activity

            People

            Assignee:
            vso Vladislavs Sokurenko
            Reporter:
            dotneft Alexey Pustovalov
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: