Snmp timeout exceptions appear in provisiond log

Description

When you run a provisioning you can find a lot messages like these in the provisiond log files. I assume it happens, if a node does not respond via SNMP and provisiond or the detectors try to find the SNMP service. This can be a normal state if a node does not support SNMP.
Having a log entry, that the SNMP service was not detected is valid, but the complete exception message is too much. It is really hard to find other log entries because of this.
My suggestion here is to catch this exception and print just a one-liner with INFO level.

2023-04-26 08:11:32,078 WARN  [Timer-32361241] o.o.n.s.s.Snmp4JStrategy: processResponse: Timeout.  Agent: SnmpAgentConfig[Address: 10.10.9.230, ProxyForAddress: null, Port: 161, Timeout: 3000, Retries: 3, MaxVarsPerPdu: 10, MaxRepetitions: 2, MaxRequestSize: 65535, Version: v2c, TTL: null, ReadCommunity: XXXXXXXX, WriteCommunity: XXXXXXXX], requestID=2071026112
2023-04-26 08:11:32,078 ERROR [scanExecutor-36] o.o.n.s.s.Snmp4JStrategy: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.230.
java.util.concurrent.ExecutionException: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.230.
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999) ~[?:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.send(Snmp4JStrategy.java:320) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.buildAndSendPdu(Snmp4JStrategy.java:309) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.get(Snmp4JStrategy.java:255) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.get(Snmp4JStrategy.java:236) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.SnmpUtils.get(SnmpUtils.java:88) ~[org.opennms.core.snmp.api-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.getValue(SnmpDetector.java:387) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.isServiceDetected(SnmpDetector.java:246) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.isServiceDetected(SnmpDetector.java:67) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.support.AgentBasedSyncAbstractDetector.detect(AgentBasedSyncAbstractDetector.java:59) ~[opennms-provision-api-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.client.rpc.DetectorClientRpcModule$1.get(DetectorClientRpcModule.java:90) ~[opennms-detectorclient-rpc-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.client.rpc.DetectorClientRpcModule$1.get(DetectorClientRpcModule.java:85) ~[opennms-detectorclient-rpc-31.0.5.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.230.
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy$2.onResponse(Snmp4JStrategy.java:357) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.snmp4j.Snmp$PendingRequest.run(Snmp.java:1878) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at java.util.TimerThread.mainLoop(Timer.java:556) ~[?:?]
	at java.util.TimerThread.run(Timer.java:506) ~[?:?]
Caused by: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.230.
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.processResponse(Snmp4JStrategy.java:430) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy$2.onResponse(Snmp4JStrategy.java:355) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.snmp4j.Snmp$PendingRequest.run(Snmp.java:1878) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at java.util.TimerThread.mainLoop(Timer.java:556) ~[?:?]
	at java.util.TimerThread.run(Timer.java:506) ~[?:?]
2023-04-26 08:11:37,703 WARN  [Timer-32361562] o.o.n.s.s.Snmp4JStrategy: processResponse: Timeout.  Agent: SnmpAgentConfig[Address: 10.10.9.152, ProxyForAddress: null, Port: 161, Timeout: 3000, Retries: 3, MaxVarsPerPdu: 10, MaxRepetitions: 2, MaxRequestSize: 65535, Version: v2c, TTL: null, ReadCommunity: XXXXXXXX, WriteCommunity: XXXXXXXX], requestID=1174619077
2023-04-26 08:11:37,703 WARN  [Timer-32361563] o.o.n.s.s.Snmp4JStrategy: processResponse: Timeout.  Agent: SnmpAgentConfig[Address: 10.10.9.152, ProxyForAddress: null, Port: 161, Timeout: 3000, Retries: 3, MaxVarsPerPdu: 10, MaxRepetitions: 2, MaxRequestSize: 65535, Version: v2c, TTL: null, ReadCommunity: XXXXXXXX, WriteCommunity: XXXXXXXX], requestID=54639890
2023-04-26 08:11:37,703 ERROR [scanExecutor-27] o.o.n.s.s.Snmp4JStrategy: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.152.
java.util.concurrent.ExecutionException: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.152.
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999) ~[?:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.send(Snmp4JStrategy.java:320) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.buildAndSendPdu(Snmp4JStrategy.java:309) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.get(Snmp4JStrategy.java:255) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.get(Snmp4JStrategy.java:236) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.SnmpUtils.get(SnmpUtils.java:88) ~[org.opennms.core.snmp.api-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.getValue(SnmpDetector.java:387) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.isServiceDetected(SnmpDetector.java:246) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.isServiceDetected(SnmpDetector.java:67) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.support.AgentBasedSyncAbstractDetector.detect(AgentBasedSyncAbstractDetector.java:59) ~[opennms-provision-api-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.client.rpc.DetectorClientRpcModule$1.get(DetectorClientRpcModule.java:90) ~[opennms-detectorclient-rpc-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.client.rpc.DetectorClientRpcModule$1.get(DetectorClientRpcModule.java:85) ~[opennms-detectorclient-rpc-31.0.5.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.152.
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy$2.onResponse(Snmp4JStrategy.java:357) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.snmp4j.Snmp$PendingRequest.run(Snmp.java:1878) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at java.util.TimerThread.mainLoop(Timer.java:556) ~[?:?]
	at java.util.TimerThread.run(Timer.java:506) ~[?:?]
Caused by: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.152.
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.processResponse(Snmp4JStrategy.java:430) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy$2.onResponse(Snmp4JStrategy.java:355) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.snmp4j.Snmp$PendingRequest.run(Snmp.java:1878) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at java.util.TimerThread.mainLoop(Timer.java:556) ~[?:?]
	at java.util.TimerThread.run(Timer.java:506) ~[?:?]
2023-04-26 08:11:37,704 ERROR [scanExecutor-7] o.o.n.s.s.Snmp4JStrategy: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.152.
java.util.concurrent.ExecutionException: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.152.
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395) ~[?:?]
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999) ~[?:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.send(Snmp4JStrategy.java:320) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.buildAndSendPdu(Snmp4JStrategy.java:309) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.get(Snmp4JStrategy.java:255) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.get(Snmp4JStrategy.java:236) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.SnmpUtils.get(SnmpUtils.java:88) ~[org.opennms.core.snmp.api-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.getValue(SnmpDetector.java:387) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.isServiceDetected(SnmpDetector.java:246) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.snmp.SnmpDetector.isServiceDetected(SnmpDetector.java:67) ~[opennms-detector-simple-31.0.5.jar:?]
	at org.opennms.netmgt.provision.support.AgentBasedSyncAbstractDetector.detect(AgentBasedSyncAbstractDetector.java:59) ~[opennms-provision-api-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.client.rpc.DetectorClientRpcModule$1.get(DetectorClientRpcModule.java:90) ~[opennms-detectorclient-rpc-31.0.5.jar:?]
	at org.opennms.netmgt.provision.detector.client.rpc.DetectorClientRpcModule$1.get(DetectorClientRpcModule.java:85) ~[opennms-detectorclient-rpc-31.0.5.jar:?]
	at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) ~[?:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: org.opennms.netmgt.snmp.SnmpException: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.152.
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy$2.onResponse(Snmp4JStrategy.java:357) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.snmp4j.Snmp$PendingRequest.run(Snmp.java:1878) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at java.util.TimerThread.mainLoop(Timer.java:556) ~[?:?]
	at java.util.TimerThread.run(Timer.java:506) ~[?:?]
Caused by: org.opennms.netmgt.snmp.SnmpAgentTimeoutException: Timeout retrieving response for 10.10.9.152.
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy.processResponse(Snmp4JStrategy.java:430) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.opennms.netmgt.snmp.snmp4j.Snmp4JStrategy$2.onResponse(Snmp4JStrategy.java:355) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at org.snmp4j.Snmp$PendingRequest.run(Snmp.java:1878) ~[org.opennms.core.snmp.implementations.snmp4j-31.0.5.jar:?]
	at java.util.TimerThread.mainLoop(Timer.java:556) ~[?:?]
	at java.util.TimerThread.run(Timer.java:506) ~[?:?]

Acceptance / Success Criteria

None

Activity

Show:

Details

Assignee

Unassigned

Reporter

Marcel Fuhrmann

Labels

Provisioningdetectorlogging

HB Backlog Status

Backlog

Components

Affects versions

31.0.6

Priority

Trivial

PagerDuty

Created April 26, 2023 at 9:54 AM

Updated May 24, 2023 at 1:30 PM

Configure