[ZBX-25108] Floating bug in async snmp pollers. Random items errors Created: 2024 Aug 23  Updated: 2025 Feb 03  Resolved: 2025 Jan 16

Status: Closed
Project: ZABBIX BUGS AND ISSUES
Component/s: Proxy (P), Server (S)
Affects Version/s: 7.0.3
Fix Version/s: 7.0.9rc1, 7.2.3rc1, 7.4.0alpha1

Type: Problem report Priority: Trivial
Reporter: Nick Assignee: Dmitrijs Goloscapovs
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: 8h
Original Estimate: Not Specified

Attachments: PNG File image-2024-08-24-00-40-19-687.png     PNG File image-2024-08-24-00-42-28-679.png     PNG File image-2024-08-24-00-44-21-728.png     PNG File image-2024-08-26-21-24-43-662.png     PNG File image-2024-08-26-21-26-05-299.png     PNG File image-2024-09-25-09-32-48-738.png     PNG File image-2024-09-25-09-33-40-065.png     PNG File image-2024-10-15-16-11-37-728.png     PNG File image-2024-10-15-16-11-55-642.png     PNG File image-2024-10-17-13-07-21-350.png     PNG File image-2024-10-17-14-10-06-532.png     PNG File image.png    
Issue Links:
Duplicate
Team: Team A
Sprint: S24-W46/47, S24-W48/49, S24-W50/51/52/1, S25-W2/3
Story Points: 0.5

 Description   

After move to async snmp poller i started getting random errors in items in hosts unavailable via icmp and snmp
for expamle:

SNMP OID: get[sysObjectID.0]

 

after several days or weeks i got

cannot read from session: Bad version specified (Sub-id not found: (top) -> ifLastChange)

 

But this host does not use oid "ifLastChange" anywhere

 

In another host (also not available via icmp and snmp) i got another error with same OID:

SNMP OID: get[sysObjectID.0]:
cannot read from session: Bad version specified (Sub-id not found: (top) -> ifHCInUcastPkts)


and also this host does not use oid "ifHCInUcastPkts" anywhere

ifLastChange and ifHCInUcastPkts exists in other hosts that have also been converted to asynс pollers.
There is probably a bug in async pollers and/or buffer with incorrect indexes between items differents hosts.
This happens when polling through via server and proxy.

 Comments   
Comment by Oleksii Zagorskyi [ 2024 Aug 26 ]

When you say "After move to async snmp poller" - do you mean here a major upgrade to 7.0 from older releases?
Or what exact change you performed ?

Comment by Oleksii Zagorskyi [ 2024 Aug 26 ]

And clarify please as for "icmp" because the new async polling is not used for ICMP checks. They are working as before - using fping tool, which does its job in an own way (also async, though).

Comment by Nick [ 2024 Aug 26 ]

zalex_ua, Upgraded from 6.4 to 7. No problem with it. Then i edit all OID settings in my templates to "get[...]"

"not available via icmp" means that host is shutdown and not response to ping

currently 30k hosts are polled via async snmp pollers
this errors appear only in those hosts that are unavailable

Comment by Nick [ 2024 Aug 26 ]

Another host with this problem:

SNMP OID: get[sysObjectID.0]
cannot read from session: Bad version specified (Sub-id not found: (top) -> ifHighSpeed)

not use "ifHighSpeed" in this host anywhere

 

server log:

grep -r host123 /var/log/zabbix
/var/log/zabbix/zabbix_server.log.1:523862:20240824:022116.773 enabling SNMP agent checks on host "host123": interface became available
/var/log/zabbix/zabbix_server.log.1:523777:20240824:022116.779 item "host123:device.object.id" became not supported: cannot read from session: Bad version specified (Sub-id not found: (top) -> ifHighSpeed)
/var/log/zabbix/zabbix_server.log.1:523862:20240824:022123.558 SNMP agent item "device.uptime" on host "host123" failed: first network error, wait for 15 seconds
/var/log/zabbix/zabbix_server.log.1:523862:20240824:022141.159 SNMP agent item "device.uptime" on host "host123" failed: another network error, wait for 15 seconds
/var/log/zabbix/zabbix_server.log.1:523862:20240824:022159.444 SNMP agent item "device.uptime" on host "host123" failed: another network error, wait for 15 seconds
/var/log/zabbix/zabbix_server.log.1:523862:20240824:022217.349 temporarily disabling SNMP agent checks on host "host123": interface unavailable

log says that interface became available, but is not true

zabbix[host,snmp,available]:

icmpping:

Comment by Vladislavs Sokurenko [ 2024 Sep 17 ]

Network errors should be improved by ZBX-25176, does this issue occur often ? Is it possible to test patch ? Could we introduce retry on this error instead of failing or does it continue failing for long time afterwards ?

Comment by Nick [ 2024 Sep 25 ]

After upgrading to 7.0.4 i detached and cleared template from all hosts with errors to clear error (about 100 hosts)
7.0.4 didn't fix it. Errors still keep popping up. How can i help further?

Comment by Nick [ 2024 Oct 15 ]

So I found a host where I can reproduce the problem.

 

snmpbulkwalk -v2c -c public 10.245.143.8 .1.3.6.1.2.1.1.2.0
Timeout: No Response from 10.245.143.8

snmpwalk -v2c -c public 10.245.143.8 .1.3.6.1.2.1.1.2.0
Timeout: No Response from 10.245.143.8

snmpget -v2c -c public 10.245.143.8 .1.3.6.1.2.1.1.2.0
Timeout: No Response from 10.245.143.8

Host is not responding - timeout

 

But async pollers report errors. Sync poller does not report errors:

tracelog:

 

  4142:20241015:160344.334 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160344.334 queue processing_num:0 pending:0
  4142:20241015:160345.334 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160345.334 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160345.335 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160345.335 End of zbx_dc_config_get_poller_items():1
  4142:20241015:160345.335 In zbx_prepare_items() num:1
  4142:20241015:160345.335 In substitute_key_macros_impl() data:'device.object.id2'
  4142:20241015:160345.335 End of substitute_key_macros_impl():SUCCEED data:'device.object.id2'
  4142:20241015:160345.335 In substitute_simple_macros_impl() data:'161'
  4142:20241015:160345.335 End substitute_simple_macros_impl() data:'161'
  4142:20241015:160345.335 In substitute_simple_macros_impl() data:'{$SNMP_COMMUNITY}'
  4142:20241015:160345.335 In um_cache_resolve() macro:'{$SNMP_COMMUNITY}'
  4142:20241015:160345.335 End of um_cache_resolve(): public
  4142:20241015:160345.335 End substitute_simple_macros_impl() data:'public'
  4142:20241015:160345.335 In substitute_key_macros_impl() data:'get[SNMPv2-MIB::sysObjectID.0]'
  4142:20241015:160345.335 End of substitute_key_macros_impl():SUCCEED data:'get[SNMPv2-MIB::sysObjectID.0]'
  4142:20241015:160345.335 In substitute_simple_macros_impl() data:'3s'
  4142:20241015:160345.335 End substitute_simple_macros_impl() data:'3s'
  4142:20241015:160345.335 End of zbx_prepare_items()
  4142:20241015:160345.335 queue processing_num:0 pending:0
  4142:20241015:160345.335 In async_initiate_queued_checks()
  4142:20241015:160345.335 In zbx_async_check_snmp() key:'device.object.id2' host:'test' addr:'10.245.143.8'
  4142:20241015:160345.335 In zbx_snmp_translate() OID:'SNMPv2-MIB::sysObjectID.0'
  4142:20241015:160345.335 End of zbx_snmp_translate() oid_translated:'SNMPv2-MIB::sysObjectID.0'
  4142:20241015:160345.336 snmp_bulkwalk_parse_param() oids_num:1
  4142:20241015:160345.336 snmp_bulkwalk_parse_params() oids_num:1
  4142:20241015:160345.336 In zbx_is_ip4() ip:'10.245.143.8'
  4142:20241015:160345.336 End of zbx_is_ip4():SUCCEED
  4142:20241015:160345.336 In async_dns_event() result:0
  4142:20241015:160345.336 In async_event()
  4142:20241015:160345.336 In snmp_task_process() init event:0 fd:-1 itemid:63054
  4142:20241015:160345.336 In zbx_snmp_open_session()
  4142:20241015:160345.336 In zbx_is_ip4() ip:'10.245.143.8'
  4142:20241015:160345.336 End of zbx_is_ip4():SUCCEED
  4142:20241015:160345.336 SNMP [public@10.245.143.8:161]
  4142:20241015:160345.336 End of zbx_snmp_open_session()
  4142:20241015:160345.336 In snmp_bulkwalk_add() OID: '.1.3.6.1.2.1.1.2.0'
  4142:20241015:160345.336 In snmp_bulkwalk_add() sending
  4142:20241015:160345.336 In snmp_bulkwalk_add() send completed reqid:1389801725
  4142:20241015:160345.336 End of snmp_bulkwalk_add():SUCCEED fd:28
  4142:20241015:160345.336 End of snmp_task_process() init event:0 fd:28 itemid:63054 state:read
  4142:20241015:160345.336 End of async_event():read
  4142:20241015:160345.336 End of async_dns_event()
  4142:20241015:160345.336 End of zbx_async_check_snmp():SUCCEED
  4142:20241015:160345.336 End of async_initiate_queued_checks(): num:1
  4142:20241015:160345.336 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160345.336 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160345.337 In async_event()
  4142:20241015:160345.337 In snmp_task_process() read event:2 fd:28 itemid:63054
  4142:20241015:160345.337 End of snmp_task_process() read event:2 fd:28 itemid:63054 error:cannot read from session: Bad version specified
  4142:20241015:160345.337 In process_async_result() key:'device.object.id2' host:'test' addr:'10.245.143.8'
  4142:20241015:160345.337 In zbx_preprocess_item_value()
  4142:20241015:160345.337 End of zbx_preprocess_item_value()
  4142:20241015:160345.337 finished processing itemid:63054 processing:0
  4142:20241015:160345.337 End of process_async_result():NOTSUPPORTED
  4142:20241015:160345.337 In zbx_snmp_close_session()
  4142:20241015:160345.337 In asynch_response()
  4142:20241015:160345.338 operation:2 response id:1389801725 command:160 probe:0
  4142:20241015:160345.338 In snmp_bulkwalk_handle_response()
  4142:20241015:160345.338 End of snmp_bulkwalk_handle_response():NETWORK_ERROR running:0
  4142:20241015:160345.338 End of asynch_response():NETWORK_ERROR
  4142:20241015:160345.338 End of zbx_snmp_close_session()
  4142:20241015:160345.338 End of async_event():stop
  4142:20241015:160345.338 In zbx_ipc_socket_write()
  4142:20241015:160345.338 interfaces num:1
  4142:20241015:160345.338 requeue num:1
  4142:20241015:160345.338 In poller_update_interfaces() num:1
  4142:20241015:160345.338 In zbx_activate_item_interface() interfaceid:390 itemid:63054 type:20 version:70000
  4142:20241015:160345.338 End of zbx_ipc_socket_write():SUCCEED
  4142:20241015:160345.338 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160345.338 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160345.338 resuming SNMP agent checks on host "test": connection restored
  4142:20241015:160345.338 End of zbx_activate_item_interface()
  4142:20241015:160345.338 In zbx_ipc_socket_write()
  4142:20241015:160345.339 End of zbx_ipc_socket_write():SUCCEED
  4142:20241015:160345.339 End of poller_update_interfaces()
  4142:20241015:160345.339 requeue items nextcheck:1728983035
  4142:20241015:160346.334 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160346.334 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160346.334 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160346.334 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160346.334 queue processing_num:0 pending:0
  4142:20241015:160347.334 zbx_setproctitle() title:'snmp poller #1 [got 1 values, queued 1 in 5 sec]'
  4142:20241015:160347.334 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160347.334 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160347.334 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160347.334 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160347.334 queue processing_num:0 pending:0
  4142:20241015:160348.334 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160348.334 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160348.334 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160348.334 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160348.334 queue processing_num:0 pending:0
  4142:20241015:160349.334 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160349.334 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160349.335 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160349.335 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160349.335 queue processing_num:0 pending:0
  4142:20241015:160350.335 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160350.335 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160350.335 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160350.335 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160350.335 queue processing_num:0 pending:0
  4142:20241015:160351.335 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160351.335 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160351.335 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160351.335 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160351.335 queue processing_num:0 pending:0
  4142:20241015:160352.335 zbx_setproctitle() title:'snmp poller #1 [got 0 values, queued 0 in 5 sec]'
  4142:20241015:160352.336 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160352.336 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160352.336 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160352.336 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160352.337 queue processing_num:0 pending:0
  4142:20241015:160353.336 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160353.337 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160353.337 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160353.337 End of zbx_dc_config_get_poller_items():0
  4142:20241015:160353.337 queue processing_num:0 pending:0
  4142:20241015:160354.337 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241015:160354.337 End of zbx_ipc_async_socket_recv():0
  4142:20241015:160354.337 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241015:160354.337 End of zbx_dc_config_get_poller_items():0

 

 

please fix it

Comment by Vladislavs Sokurenko [ 2024 Oct 15 ]

Could you please also try with snmpget -v2c -d -c public 10.245.143.8 .1.3.6.1.2.1.1.2.0

Comment by Vladislavs Sokurenko [ 2024 Oct 15 ]

Could you please also provide log with ordinary check without get from poller, does it timeout ?

Comment by Nick [ 2024 Oct 17 ]

 

i made fresh install zabbix node with two hosts:

  • 'test' host with 2 items (sync SNMPv2-MIB::sysObjectID.0 and async get[SNMPv2-MIB::sysObjectID.0])
  • 'another' host (juniper mx960 with ~400 interfaces, interface discovery, discovered items are also asyncs)

'test' host supports snmp_v1, but if interface setting switched to snmp_v2 mode, then it is possible to reproduce errors

 

If 'another' host is enabled, items from 'another' host gets to 'test' host errors:

  4142:20241017:123230.646 enabling SNMP agent checks on host "test": interface became available
  4095:20241017:123230.663 item "test:object_id_async" became not supported: cannot read from session: Bad version specified (Sub-id not found: (top) -> ifHighSpeed)
  4106:20241017:123238.686 SNMP agent item "object_id_sync" on host "test" failed: first network error, wait for 15 seconds
  4142:20241017:123253.642 resuming SNMP agent checks on host "test": connection restored
  4095:20241017:123253.647 error reason for "test:object_id_async" changed: cannot read from session: Bad version specified (Sub-id not found: (top) -> ifHCOutBroadcastPkts)
  4111:20241017:123256.839 SNMP agent item "object_id_sync" on host "test" failed: first network error, wait for 15 seconds
  4111:20241017:123314.855 SNMP agent item "object_id_sync" on host "test" failed: another network error, wait for 15 seconds
  4111:20241017:123332.873 SNMP agent item "object_id_sync" on host "test" failed: another network error, wait for 15 seconds
  4111:20241017:123350.892 temporarily disabling SNMP agent checks on host "test": interface unavailable

 

snmpget for 'test' host:

snmpget -v2c -d -c public 10.245.143.8 .1.3.6.1.2.1.1.2.0

Sending 43 bytes to UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 29 02 01  01 04 06 70  75 62 6C 69  63 A0 1C 02    0).....public...
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  0E 30 0C 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 05 00                    .+.........
Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  00 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01                                    ......

Sending 43 bytes to UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 29 02 01  01 04 06 70  75 62 6C 69  63 A0 1C 02    0).....public...
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  0E 30 0C 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 05 00                    .+.........
Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  00 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01                                    ......

Sending 43 bytes to UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 29 02 01  01 04 06 70  75 62 6C 69  63 A0 1C 02    0).....public...
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  0E 30 0C 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 05 00                    .+.........
Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  00 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01                                    ......

Sending 43 bytes to UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 29 02 01  01 04 06 70  75 62 6C 69  63 A0 1C 02    0).....public...
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  0E 30 0C 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 05 00                    .+.........
Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  00 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01                                    ......

Sending 43 bytes to UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 29 02 01  01 04 06 70  75 62 6C 69  63 A0 1C 02    0).....public...
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  0E 30 0C 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 05 00                    .+.........
Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  00 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01                                    ......

Sending 43 bytes to UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 29 02 01  01 04 06 70  75 62 6C 69  63 A0 1C 02    0).....public...
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  0E 30 0C 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 05 00                    .+.........

Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  00 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01                                    ......

Timeout: No Response from 10.245.143.8.

 

trace log for async and sync checks for 'test' host (I had to disable 'another' host to avoid chaos in the logs):

  4142:20241017:123412.637 zbx_setproctitle() title:'snmp poller #1 [got 0 values, queued 0 in 5 sec]'
  4142:20241017:123412.637 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123412.637 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123412.637 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123412.637 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123412.638 queue processing_num:0 pending:0
  4142:20241017:123412.653 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123412.653 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123413.631 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123413.631 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123413.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123413.632 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123413.632 queue processing_num:0 pending:0
  4142:20241017:123413.652 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123413.652 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123414.631 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123414.631 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123414.631 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123414.632 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123414.632 queue processing_num:0 pending:0
  4142:20241017:123414.652 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123414.652 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123415.631 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123415.631 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123415.631 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123415.632 End of zbx_dc_config_get_poller_items():1
  4142:20241017:123415.632 In zbx_prepare_items() num:1
  4142:20241017:123415.632 In substitute_key_macros_impl() data:'object_id_async'
  4142:20241017:123415.632 End of substitute_key_macros_impl():SUCCEED data:'object_id_async'
  4142:20241017:123415.632 In substitute_simple_macros_impl() data:'161'
  4142:20241017:123415.632 End substitute_simple_macros_impl() data:'161'
  4142:20241017:123415.632 In substitute_simple_macros_impl() data:'{$SNMP_COMMUNITY}'
  4142:20241017:123415.632 In um_cache_resolve() macro:'{$SNMP_COMMUNITY}'
  4142:20241017:123415.632 End of um_cache_resolve(): public
  4142:20241017:123415.632 End substitute_simple_macros_impl() data:'public'
  4142:20241017:123415.632 In substitute_key_macros_impl() data:'get[SNMPv2-MIB::sysObjectID.0]'
  4142:20241017:123415.632 End of substitute_key_macros_impl():SUCCEED data:'get[SNMPv2-MIB::sysObjectID.0]'
  4142:20241017:123415.632 In substitute_simple_macros_impl() data:'3s'
  4142:20241017:123415.632 End substitute_simple_macros_impl() data:'3s'
  4142:20241017:123415.632 End of zbx_prepare_items()
  4142:20241017:123415.632 queue processing_num:0 pending:0
  4142:20241017:123415.632 In async_initiate_queued_checks()
  4142:20241017:123415.633 In zbx_async_check_snmp() key:'object_id_async' host:'test' addr:'10.245.143.8'
  4142:20241017:123415.633 In zbx_snmp_translate() OID:'SNMPv2-MIB::sysObjectID.0'
  4142:20241017:123415.633 End of zbx_snmp_translate() oid_translated:'SNMPv2-MIB::sysObjectID.0'
  4142:20241017:123415.633 snmp_bulkwalk_parse_param() oids_num:1
  4142:20241017:123415.633 snmp_bulkwalk_parse_params() oids_num:1
  4142:20241017:123415.633 In zbx_is_ip4() ip:'10.245.143.8'
  4142:20241017:123415.633 End of zbx_is_ip4():SUCCEED
  4142:20241017:123415.633 In async_dns_event() result:0
  4142:20241017:123415.633 In async_event()
  4142:20241017:123415.633 In snmp_task_process() init event:0 fd:-1 itemid:63169
  4142:20241017:123415.633 In zbx_snmp_open_session()
  4142:20241017:123415.633 In zbx_is_ip4() ip:'10.245.143.8'
  4142:20241017:123415.633 End of zbx_is_ip4():SUCCEED
  4142:20241017:123415.633 SNMP [public@10.245.143.8:161]
  4142:20241017:123415.633 End of zbx_snmp_open_session()
  4142:20241017:123415.633 In snmp_bulkwalk_add() OID: '.1.3.6.1.2.1.1.2.0'
  4142:20241017:123415.633 In snmp_bulkwalk_add() sending
  4142:20241017:123415.634 In snmp_bulkwalk_add() send completed reqid:1400134746
  4142:20241017:123415.634 End of snmp_bulkwalk_add():SUCCEED fd:28
  4142:20241017:123415.634 End of snmp_task_process() init event:0 fd:28 itemid:63169 state:read
  4142:20241017:123415.634 End of async_event():read
  4142:20241017:123415.634 End of async_dns_event()
  4142:20241017:123415.634 End of zbx_async_check_snmp():SUCCEED
  4142:20241017:123415.634 End of async_initiate_queued_checks(): num:1
  4142:20241017:123415.634 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123415.634 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123415.634 In async_event()
  4142:20241017:123415.634 In snmp_task_process() read event:2 fd:28 itemid:63169
  4142:20241017:123415.635 End of snmp_task_process() read event:2 fd:28 itemid:63169 error:cannot read from session: Bad version specified (Sub-id not found: (top) -> enterprises)
  4142:20241017:123415.635 In process_async_result() key:'object_id_async' host:'test' addr:'10.245.143.8'
  4142:20241017:123415.635 In zbx_preprocess_item_value()
  4142:20241017:123415.635 End of zbx_preprocess_item_value()
  4142:20241017:123415.635 finished processing itemid:63169 processing:0
  4142:20241017:123415.635 End of process_async_result():NOTSUPPORTED
  4142:20241017:123415.635 In zbx_snmp_close_session()
  4142:20241017:123415.635 In asynch_response()
  4142:20241017:123415.635 operation:2 response id:1400134746 command:160 probe:0
  4142:20241017:123415.635 In snmp_bulkwalk_handle_response()
  4142:20241017:123415.635 End of snmp_bulkwalk_handle_response():NETWORK_ERROR running:0
  4142:20241017:123415.635 End of asynch_response():NETWORK_ERROR
  4142:20241017:123415.635 End of zbx_snmp_close_session()
  4142:20241017:123415.635 End of async_event():stop
  4142:20241017:123415.635 In zbx_ipc_socket_write()
  4142:20241017:123415.635 End of zbx_ipc_socket_write():SUCCEED
  4142:20241017:123415.636 interfaces num:1
  4142:20241017:123415.636 requeue num:1
  4142:20241017:123415.636 In poller_update_interfaces() num:1
  4142:20241017:123415.636 In zbx_activate_item_interface() interfaceid:392 itemid:63169 type:20 version:0
  4142:20241017:123415.636 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123415.636 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123415.636 enabling SNMP agent checks on host "test": interface became available
  4095:20241017:123415.636 error reason for "test:object_id_async" changed: cannot read from session: Bad version specified (Sub-id not found: (top) -> enterprises)
  4142:20241017:123415.636 End of zbx_activate_item_interface()
  4142:20241017:123415.636 In zbx_ipc_socket_write()
  4142:20241017:123415.636 End of zbx_ipc_socket_write():SUCCEED
  4142:20241017:123415.636 End of poller_update_interfaces()
  4142:20241017:123415.636 requeue items nextcheck:1729143256
  4142:20241017:123416.635 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123416.635 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123416.635 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123416.636 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123416.636 queue processing_num:0 pending:0
  4142:20241017:123417.633 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123417.634 zbx_setproctitle() title:'snmp poller #1 [got 1 values, queued 1 in 5 sec]'
  4142:20241017:123417.634 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123417.634 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123417.634 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123417.634 queue processing_num:0 pending:0
  4142:20241017:123418.632 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123418.632 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123418.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123418.633 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123418.633 queue processing_num:0 pending:0
  4142:20241017:123419.632 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123419.632 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123419.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123419.632 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123419.632 queue processing_num:0 pending:0
  4142:20241017:123420.631 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123420.631 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123420.631 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123420.632 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123420.632 queue processing_num:0 pending:0
  4142:20241017:123421.635 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123421.635 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123421.635 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123421.636 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123421.636 queue processing_num:0 pending:0
  4142:20241017:123422.634 zbx_setproctitle() title:'snmp poller #1 [got 0 values, queued 0 in 5 sec]'
  4142:20241017:123422.634 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123422.634 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123422.634 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123422.634 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123422.634 queue processing_num:0 pending:0
  4142:20241017:123423.635 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123423.636 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123423.636 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123423.636 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123423.636 queue processing_num:0 pending:0
  4142:20241017:123424.635 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123424.635 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123424.635 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123424.636 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123424.636 queue processing_num:0 pending:0
  4103:20241017:123424.749 SNMP agent item "object_id_sync" on host "test" failed: first network error, wait for 15 seconds
  4142:20241017:123425.635 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123425.636 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123425.636 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123425.636 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123425.636 queue processing_num:0 pending:0
  4142:20241017:123426.634 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123426.634 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123426.634 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123426.635 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123426.635 queue processing_num:0 pending:0
  4142:20241017:123427.632 zbx_setproctitle() title:'snmp poller #1 [got 0 values, queued 0 in 5 sec]'
  4142:20241017:123427.632 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123427.632 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123427.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123427.633 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123427.633 queue processing_num:0 pending:0
  4142:20241017:123428.632 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123428.632 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123428.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123428.633 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123428.633 queue processing_num:0 pending:0
  4142:20241017:123429.631 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123429.632 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123429.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123429.632 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123429.632 queue processing_num:0 pending:0
  4142:20241017:123430.636 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123430.636 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123430.636 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123430.636 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123430.636 queue processing_num:0 pending:0
  4142:20241017:123431.636 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123431.636 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123431.636 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123431.636 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123431.636 queue processing_num:0 pending:0
  4142:20241017:123432.631 zbx_setproctitle() title:'snmp poller #1 [got 0 values, queued 0 in 5 sec]'
  4142:20241017:123432.631 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123432.631 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123432.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123432.632 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123432.632 queue processing_num:0 pending:0
  4142:20241017:123433.635 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123433.635 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123433.635 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123433.636 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123433.636 queue processing_num:0 pending:0
  4142:20241017:123434.633 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123434.634 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123434.634 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123434.634 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123434.634 queue processing_num:0 pending:0
  4142:20241017:123435.632 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123435.632 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123435.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123435.632 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123435.633 queue processing_num:0 pending:0
  4142:20241017:123436.631 In zbx_ipc_async_socket_recv() timeout:0
  4142:20241017:123436.632 End of zbx_ipc_async_socket_recv():0
  4142:20241017:123436.632 In zbx_dc_config_get_poller_items() poller_type:9
  4142:20241017:123436.632 End of zbx_dc_config_get_poller_items():0
  4142:20241017:123436.632 queue processing_num:0 pending:0
  4142:20241017:123437.633 log level has been decreased to 3 (warning)
  4111:20241017:123442.944 SNMP agent item "object_id_sync" on host "test" failed: another network error, wait for 15 seconds
  4111:20241017:123500.963 SNMP agent item "object_id_sync" on host "test" failed: another network error, wait for 15 seconds
  4111:20241017:123518.983 temporarily disabling SNMP agent checks on host "test": interface unavailable

 

test sync item:

 

in async poller similar behavior is expected, without errors

Comment by Vladislavs Sokurenko [ 2024 Oct 17 ]

I am sorry but to get logs for sync checks need to increase log level for poller process:
./sbin/zabbix_server -R log_level_increase="poller"

It looks like eventually there was some kind of response, could it be that it is malformed ?

Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  00 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01                                    ......

But is mentioned as timeout:
Timeout: No Response from 10.245.143.8.

Comment by Nick [ 2024 Oct 17 ]

with zabbix_server -R log_level_increase="poller"

  4104:20241017:132649.745 In get_values()
  4104:20241017:132649.745 In zbx_dc_config_get_poller_items() poller_type:0
  4104:20241017:132649.745 End of zbx_dc_config_get_poller_items():0
  4104:20241017:132649.745 In zbx_dc_config_get_poller_nextcheck() poller_type:0
  4104:20241017:132649.745 End of zbx_dc_config_get_poller_nextcheck():1729146538
  4104:20241017:132649.746 End of get_values():0
  4104:20241017:132649.746 zbx_setproctitle() title:'poller #2 [got 0 values in 0.000217 sec, idle 5 sec]'
  4104:20241017:132649.746 In zbx_ipc_async_socket_recv() timeout:5
  4111:20241017:132649.872 temporarily disabling SNMP agent checks on host "test": interface unavailable
  4107:20241017:132649.929 End of zbx_ipc_async_socket_recv():0
  4107:20241017:132649.929 zbx_setproctitle() title:'poller #5 [got 0 values in 0.000268 sec, getting values]'
  4107:20241017:132649.929 In get_values()
  4107:20241017:132649.929 In zbx_dc_config_get_poller_items() poller_type:0
  4107:20241017:132649.929 End of zbx_dc_config_get_poller_items():0
  4107:20241017:132649.929 In zbx_dc_config_get_poller_nextcheck() poller_type:0
  4107:20241017:132649.929 End of zbx_dc_config_get_poller_nextcheck():1729146538
  4107:20241017:132649.929 End of get_values():0
  4107:20241017:132649.929 zbx_setproctitle() title:'poller #5 [got 0 values in 0.000229 sec, idle 5 sec]'
  4107:20241017:132649.929 In zbx_ipc_async_socket_recv() timeout:5
  4106:20241017:132650.742 End of zbx_ipc_async_socket_recv():0
  4106:20241017:132650.743 zbx_setproctitle() title:'poller #4 [got 0 values in 0.000244 sec, getting values]'
  4106:20241017:132650.743 In get_values()
  4106:20241017:132650.743 In zbx_dc_config_get_poller_items() poller_type:0
  4106:20241017:132650.743 End of zbx_dc_config_get_poller_items():1
  4106:20241017:132650.743 In zbx_prepare_items() num:1
  4106:20241017:132650.743 In substitute_key_macros_impl() data:'object_id_sync'
  4106:20241017:132650.743 End of substitute_key_macros_impl():SUCCEED data:'object_id_sync'
  4106:20241017:132650.743 In substitute_simple_macros_impl() data:'161'
  4106:20241017:132650.743 End substitute_simple_macros_impl() data:'161'
  4106:20241017:132650.743 In substitute_simple_macros_impl() data:'{$SNMP_COMMUNITY}'
  4106:20241017:132650.743 In um_cache_resolve() macro:'{$SNMP_COMMUNITY}'
  4106:20241017:132650.743 End of um_cache_resolve(): public
  4106:20241017:132650.743 End substitute_simple_macros_impl() data:'public'
  4106:20241017:132650.743 In substitute_key_macros_impl() data:'SNMPv2-MIB::sysObjectID.0'
  4106:20241017:132650.743 End of substitute_key_macros_impl():SUCCEED data:'SNMPv2-MIB::sysObjectID.0'
  4106:20241017:132650.743 In substitute_simple_macros_impl() data:'3s'
  4106:20241017:132650.743 End substitute_simple_macros_impl() data:'3s'
  4106:20241017:132650.743 End of zbx_prepare_items()
  4106:20241017:132650.743 In get_values_snmp() host:'test' addr:'10.245.143.8' num:1
  4106:20241017:132650.743 In zbx_snmp_open_session()
  4106:20241017:132650.743 In zbx_is_ip4() ip:'10.245.143.8'
  4106:20241017:132650.743 End of zbx_is_ip4():SUCCEED
  4106:20241017:132650.743 SNMP [public@10.245.143.8:161]
  4106:20241017:132650.744 End of zbx_snmp_open_session()
  4106:20241017:132650.744 In zbx_snmp_process_standard()
  4106:20241017:132650.744 In zbx_snmp_translate() OID:'SNMPv2-MIB::sysObjectID.0'
  4106:20241017:132650.744 End of zbx_snmp_translate() oid_translated:'SNMPv2-MIB::sysObjectID.0'
  4106:20241017:132650.744 In zbx_snmp_get_values() num:1 level:0
  4103:20241017:132654.739 End of zbx_ipc_async_socket_recv():0
  4103:20241017:132654.739 zbx_setproctitle() title:'poller #1 [got 0 values in 0.000480 sec, getting values]'
  4103:20241017:132654.739 In get_values()
  4103:20241017:132654.739 In zbx_dc_config_get_poller_items() poller_type:0
  4103:20241017:132654.739 End of zbx_dc_config_get_poller_items():0
  4103:20241017:132654.739 In zbx_dc_config_get_poller_nextcheck() poller_type:0
  4103:20241017:132654.739 End of zbx_dc_config_get_poller_nextcheck():1729146538
  4103:20241017:132654.739 End of get_values():0
  4103:20241017:132654.739 zbx_setproctitle() title:'poller #1 [got 0 values in 0.000224 sec, idle 5 sec]'
  4103:20241017:132654.739 In zbx_ipc_async_socket_recv() timeout:5
  4105:20241017:132654.742 End of zbx_ipc_async_socket_recv():0
  4105:20241017:132654.742 zbx_setproctitle() title:'poller #3 [got 0 values in 0.000262 sec, getting values]'
  4105:20241017:132654.742 In get_values()
  4105:20241017:132654.742 In zbx_dc_config_get_poller_items() poller_type:0
  4105:20241017:132654.742 End of zbx_dc_config_get_poller_items():0
  4105:20241017:132654.742 In zbx_dc_config_get_poller_nextcheck() poller_type:0
  4105:20241017:132654.742 End of zbx_dc_config_get_poller_nextcheck():1729146538
  4105:20241017:132654.742 End of get_values():0
  4105:20241017:132654.742 zbx_setproctitle() title:'poller #3 [got 0 values in 0.000275 sec, idle 5 sec]'
  4105:20241017:132654.742 In zbx_ipc_async_socket_recv() timeout:5
  4104:20241017:132654.751 End of zbx_ipc_async_socket_recv():0
  4104:20241017:132654.751 zbx_setproctitle() title:'poller #2 [got 0 values in 0.000217 sec, getting values]'
  4104:20241017:132654.751 In get_values()
  4104:20241017:132654.751 In zbx_dc_config_get_poller_items() poller_type:0
  4104:20241017:132654.751 End of zbx_dc_config_get_poller_items():0
  4104:20241017:132654.751 In zbx_dc_config_get_poller_nextcheck() poller_type:0
  4104:20241017:132654.751 End of zbx_dc_config_get_poller_nextcheck():1729146538
  4104:20241017:132654.751 End of get_values():0
  4104:20241017:132654.751 zbx_setproctitle() title:'poller #2 [got 0 values in 0.000201 sec, idle 5 sec]'
  4104:20241017:132654.751 In zbx_ipc_async_socket_recv() timeout:5
  4107:20241017:132654.935 End of zbx_ipc_async_socket_recv():0
  4107:20241017:132654.935 zbx_setproctitle() title:'poller #5 [got 0 values in 0.000229 sec, getting values]'
  4107:20241017:132654.935 In get_values()
  4107:20241017:132654.935 In zbx_dc_config_get_poller_items() poller_type:0
  4107:20241017:132654.935 End of zbx_dc_config_get_poller_items():0
  4107:20241017:132654.935 In zbx_dc_config_get_poller_nextcheck() poller_type:0
  4107:20241017:132654.935 End of zbx_dc_config_get_poller_nextcheck():1729146538
  4107:20241017:132654.935 End of get_values():0
  4107:20241017:132654.935 zbx_setproctitle() title:'poller #5 [got 0 values in 0.000196 sec, idle 5 sec]'
  4107:20241017:132654.935 In zbx_ipc_async_socket_recv() timeout:5
  4106:20241017:132656.751 zbx_snmp_get_values() snmp_sess_synch_response() status:2 s_snmp_errno:-24 errstat:-1 mapping_num:1
  4106:20241017:132656.751 End of zbx_snmp_get_values():NETWORK_ERROR
  4106:20241017:132656.751 End of zbx_snmp_process_standard():NETWORK_ERROR
  4106:20241017:132656.751 In zbx_snmp_close_session()
  4106:20241017:132656.751 End of zbx_snmp_close_session()
  4106:20241017:132656.751 getting SNMP values failed: Timeout while connecting to "10.245.143.8:161".
  4106:20241017:132656.751 End of get_values_snmp()
  4106:20241017:132656.751 In zbx_deactivate_item_interface() interfaceid:392 itemid:63170 type:20
  4106:20241017:132656.751 zbx_deactivate_item_interface() errors_from:1729146355 available:2
  4106:20241017:132656.751 End of zbx_deactivate_item_interface()
  4106:20241017:132656.751 In zbx_ipc_socket_write()
  4106:20241017:132656.751 End of zbx_ipc_socket_write():SUCCEED
  4106:20241017:132656.751 End of get_values():1
  4106:20241017:132656.751 zbx_setproctitle() title:'poller #4 [got 1 values in 6.008723 sec, idle 5 sec]'
  4106:20241017:132656.751 In zbx_ipc_async_socket_recv() timeout:5
  4103:20241017:132659.745 End of zbx_ipc_async_socket_recv():0
  4103:20241017:132659.745 zbx_setproctitle() title:'poller #1 [got 0 values in 0.000224 sec, getting values]'
  4103:20241017:132659.745 In get_values()
  4103:20241017:132659.745 In zbx_dc_config_get_poller_items() poller_type:0
  4103:20241017:132659.745 End of zbx_dc_config_get_poller_items():0
  4103:20241017:132659.745 In zbx_dc_config_get_poller_nextcheck() poller_type:0
  4103:20241017:132659.745 End of zbx_dc_config_get_poller_nextcheck():1729146538
  4103:20241017:132659.745 End of get_values():0
Comment by Vladislavs Sokurenko [ 2024 Oct 17 ]

I am sorry but it seems that the error is correct and there is something wrong with the device, it's possible to fix something on our side and continue requesting until timeout but it still will not work because device responds with invalid version:

Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  00 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01

Should be:

Received 54 byte packet from UDP: [10.245.143.8]:161->[0.0.0.0]:38638
0000: 30 34 02 01  01 04 06 70  75 62 6C 69  63 A2 27 02    04.....public.'.
0016: 04 53 92 C3  DD 02 01 00  02 01 00 30  19 30 17 06    .S.........0.0..
0032: 08 2B 06 01  02 01 01 02  00 06 0B 2B  06 01 04 01    .+.........+....
0048: 9D 03 0E 02  01 01

Also can check with the following request to see that it will also log that there was incorrect response:

snmpget -v2c -DALL -c public 127.0.0.1:1234 .1.3.6.1.2.1.1.2.0
Comment by Nick [ 2024 Oct 17 ]

Device is fine (it is snpm_v1). I wrote that the errors can be reproduced by enabling snmp_v2 in zabbix for thist host only.

Read above:
"If 'another' host is enabled, items from 'another' host gets to 'test' host errors:"
How do you explain this?

Items from other hosts get into errors to another hosts that are unavailable (the very first description of the problem)

Comment by Vladislavs Sokurenko [ 2024 Oct 17 ]

Understood, so the problem is that "Bad version specified" sometimes has also appended (Sub-id not found: (top) -> ifLastChange) or something else.

Comment by Nick [ 2024 Oct 17 ]

Yes, this happens even on inaccessible devices (no ping) (my first messages in this issue)

Comment by Vladislavs Sokurenko [ 2024 Oct 17 ]

What was snmp version ?
snmpget -V

Unfortunately I could not reproduce this floating error, might need to investigate more deeply as this error comes from NetSNMP library, maybe it remembered some last error somewhere in cache and appends it, probably will need to reproduce (sub id not found) first.

Comment by Nick [ 2024 Oct 17 ]

when using synchronous pollers everything is fine. no fake errors long time

snmpget -V
NET-SNMP version: 5.9.3

 uname -a
Linux zabbix-server-01 6.10.11+bpo-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.10.11-1~bpo12+1 (2024-10-03) x86_64 GNU/Linux

Debian GNU/Linux 12 (bookworm)
Comment by Vladislavs Sokurenko [ 2024 Oct 17 ]

There are no fake errors because errors are not reported and it try again until timeout, this might not be the best approach.

Comment by Vladislavs Sokurenko [ 2024 Oct 17 ]

It's possible that ifLastChange error is generated when using walk item ? We can clear last error before executing new items, this should solve the issue.

Comment by Vladislavs Sokurenko [ 2024 Oct 17 ]

Confirmed, error can be cleared with snmp_api_errstring(SNMPERR_SUCCESS) and can be set with snmp_set_detail(), it sets global variable in netsnmp variable.

Global variables:

static char     snmp_detail[192];
static int      snmp_detail_f = 0;
Comment by Dmitrijs Goloscapovs [ 2025 Jan 14 ]

Available in versions:

Generated at Sat Mar 29 16:14:30 EET 2025 using Jira 9.12.4#9120004-sha1:625303b708afdb767e17cb2838290c41888e9ff0.