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

"preprocessing manager" may start too late -> zabbix server/proxy Exits

    XMLWordPrintable

Details

    • Team A
    • Sprint 77 (Jun 2021), Sprint 78 (Jul 2021), Sprint 81 (Oct 2021)
    • 1

    Description

      I have debug (only) level log of proxy. Each attempt to start the proxy finishes after a minute. Here are some details:

      Both failed processes exited when tried to connect to IPC socket:

      # egrep " 20107" zabbix-proxy-8.log
       20107:20210517:141038.612 proxy #220 started [poller #203]
       20107:20210517:141049.946 zbx_setproctitle() title:'poller #203 [connecting to the database]'
       20107:20210517:141049.946 In DBconnect() flag:0
       20107:20210517:141049.984 End of DBconnect():0
       20107:20210517:141049.984 zbx_setproctitle() title:'poller #203 [got 0 values in 0.000000 sec, getting values]'
       20107:20210517:141049.984 In get_values()
       20107:20210517:141049.984 In DCconfig_get_poller_items() poller_type:0
       20107:20210517:141049.984 End of DCconfig_get_poller_items():1
       20107:20210517:141049.985 In substitute_key_macros_impl() data:'net.tcp.service[http]'
       20107:20210517:141049.985 End of substitute_key_macros_impl():SUCCEED data:'net.tcp.service[http]'
       20107:20210517:141049.985 In substitute_simple_macros_impl() data:EMPTY
       20107:20210517:141049.985 In substitute_simple_macros_impl() data:EMPTY
       20107:20210517:141049.985 In get_value() key:'net.tcp.service[http]'
       20107:20210517:141049.985 In get_value_simple() key_orig:'net.tcp.service[http]' addr:'10.50.87.144'
       20107:20210517:141049.988 End of get_value_simple():SUCCEED
       20107:20210517:141049.988 End of get_value():SUCCEED
       20107:20210517:141049.988 In zbx_activate_item_host() hostid:14807 itemid:3945157 type:3
       20107:20210517:141049.988 End of zbx_activate_item_host()
       20107:20210517:141049.988 In zbx_preprocess_item_value()
       20107:20210517:141049.988 End of zbx_preprocess_item_value()
       20107:20210517:141049.989 In zbx_ipc_socket_open()
       20107:20210517:141150.047 End of zbx_ipc_socket_open():FAIL
       20107:20210517:141150.047 cannot connect to preprocessing service: Cannot connect to service "preprocessing": [2] No such file or directory.
      
      [email protected]:/tmp# egrep " 20033" zabbix-proxy-8.log
       20033:20210517:141037.692 proxy #148 started [poller #131]
       20033:20210517:141049.288 zbx_setproctitle() title:'poller #131 [connecting to the database]'
       20033:20210517:141049.305 In DBconnect() flag:0
       20033:20210517:141049.318 End of DBconnect():0
       20033:20210517:141049.321 zbx_setproctitle() title:'poller #131 [got 0 values in 0.000000 sec, getting values]'
       20033:20210517:141049.326 In get_values()
       20033:20210517:141049.326 In DCconfig_get_poller_items() poller_type:0
       20033:20210517:141049.327 End of DCconfig_get_poller_items():1
       20033:20210517:141049.328 In substitute_key_macros_impl() data:'net.if.out[ens3]'
       20033:20210517:141049.329 End of substitute_key_macros_impl():SUCCEED data:'net.if.out[ens3]'
       20033:20210517:141049.329 In substitute_simple_macros_impl() data:'10050'
       20033:20210517:141049.331 In get_value() key:'net.if.out[ens3]'
       20033:20210517:141049.331 In get_value_agent() host:'zabbix-proxy-8' addr:'192.168.101.27' key:'net.if.out[ens3]' conn:'unencrypted'
       20033:20210517:141049.335 Sending [net.if.out[ens3]]
       20033:20210517:141049.336 get value from agent result: '10335816499'
       20033:20210517:141049.337 End of get_value_agent():SUCCEED
       20033:20210517:141049.337 End of get_value():SUCCEED
       20033:20210517:141049.337 In zbx_activate_item_host() hostid:13851 itemid:2577877 type:0
       20033:20210517:141049.338 End of zbx_activate_item_host()
       20033:20210517:141049.338 In zbx_preprocess_item_value()
       20033:20210517:141049.338 End of zbx_preprocess_item_value()
       20033:20210517:141049.338 In zbx_ipc_socket_open()
       20033:20210517:141150.041 End of zbx_ipc_socket_open():FAIL
       20033:20210517:141150.041 cannot connect to preprocessing service: Cannot connect to service "preprocessing": [2] No such file or directory.
      

      child processes still were starting (1240 already started ! ) and preprocessing manager did not start yet.
      1000 pollers started and 221 unreachable pollers:

      # egrep " started" zabbix-proxy-8.log | tail -n3
       22029:20210517:141149.919 proxy #1236 started [unreachable poller #219]
       22031:20210517:141149.944 proxy #1237 started [unreachable poller #220]
       22034:20210517:141150.180 proxy #1238 started [unreachable poller #221]
      
      # egrep " started" zabbix-proxy-8.log     
       19877:20210517:141035.430 proxy #0 started [main process]
       19884:20210517:141035.431 proxy #1 started [configuration syncer #1]
       19887:20210517:141037.034 proxy #2 started [trapper #1]
       19888:20210517:141037.034 proxy #3 started [heartbeat sender #1]
       19889:20210517:141037.035 proxy #4 started [data sender #1]
       19890:20210517:141037.036 proxy #5 started [housekeeper #1]
       19891:20210517:141037.038 proxy #6 started [discoverer #1]
       19892:20210517:141037.039 proxy #7 started [discoverer #2]
       19893:20210517:141037.039 proxy #8 started [discoverer #3]
       19894:20210517:141037.040 proxy #9 started [discoverer #4]
       19895:20210517:141037.041 proxy #10 started [discoverer #5]
       19896:20210517:141037.042 proxy #11 started [history syncer #1]
       19897:20210517:141037.042 proxy #12 started [history syncer #2]
       19898:20210517:141037.045 proxy #13 started [history syncer #3]
       19899:20210517:141037.046 proxy #14 started [history syncer #4]
       19900:20210517:141037.047 proxy #15 started [snmp trapper #1]
       19901:20210517:141037.048 proxy #16 started [self-monitoring #1]
       19902:20210517:141037.049 proxy #17 started [task manager #1]
       19903:20210517:141037.050 proxy #18 started [poller #1]
      ...
        21519:20210517:141130.529 proxy #1014 started [poller #997]
       21523:20210517:141130.732 proxy #1017 started [poller #1000]
       21529:20210517:141130.744 proxy #1018 started [unreachable poller #1]
       21531:20210517:141130.864 proxy #1019 started [unreachable poller #2]
      ...
      ...  1+ minute passed.
       22029:20210517:141149.919 proxy #1236 started [unreachable poller #219]
       22031:20210517:141149.944 proxy #1237 started [unreachable poller #220]
       22034:20210517:141150.180 proxy #1238 started [unreachable poller #221]
       

      Later number of pollers was decreased and the proxy was able to operate successfully without exiting.

      I think that preprocessing processes should start before pollers, to avid such issue.

      Attachments

        Activity

          People

            vso Vladislavs Sokurenko
            zalex_ua Oleksii Zagorskyi
            Votes:
            2 Vote for this issue
            Watchers:
            7 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: