[SNMP4J] Possible concurrency bug in snmp4j ?
Maayan, Elhanan
Elhanan.Maayan at sbdinc.com
Mon Feb 12 19:53:02 CET 2018
Thanks, I'll try that , I'm trying to access the bug system, but I can't find it....
The real issue I'm encountering which I don't know the cause is that the snmp4j tries to send messages, trying to connect , but simply doesn't, I did a thread dump and it seems to be stuck on the select method no matter what
"DefaultTCPTransportMapping_192.168.60.80/0" #75906 daemon prio=5 os_prio=0 tid=0x00007f4748e75000 nid=0x79e5 runnable [0x00007f4733768000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked <0x00000007042019f8> (a sun.nio.ch.Util$3)
- locked <0x00000007042019e8> (a java.util.Collections$UnmodifiableSet)
- locked <0x0000000704201a08> (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
at org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread.run(DefaultTcpTransportMapping.java:786)
at java.lang.Thread.run(Thread.java:745)
there's nothing on tcpdump, using a separate snmp4j on shell on the same machine is able to connect to the same remote machine,
but still:
2018-02-12 20:46:48,982 DEBUG DefaultTcpTransportMapping - Looking up connection for destination '192.168.56.1/162' returned: SocketEntry[peerAddress=192.168.56.1/162,socket=Socket[unconnected],lastUse=Mon Mar 09 07:06:25 IST 1970,readBufferPosition=-1]
2018-02-12 20:46:48,982 DEBUG DefaultTcpTransportMapping - {192.168.56.1/162=SocketEntry[peerAddress=192.168.56.1/162,socket=Socket[unconnected],lastUse=Mon Mar 09 07:06:25 IST 1970,readBufferPosition=-1]}
2018-02-12 20:46:48,982 DEBUG DefaultTcpTransportMapping - Socket for address '192.168.56.1/162' is closed, opening it...
2018-02-12 20:46:48,982 DEBUG DefaultTcpTransportMapping - Trying to connect to 192.168.56.1/162
I see that "trying to connect to" is invoked the wakeup, so that must means the .select is released, but returns no keys, can there be any reason for that?
-----Original Message-----
From: Frank Fock [mailto:fock at agentpp.com]
Sent: Monday, February 12, 2018 8:45 PM
To: Maayan, Elhanan <Elhanan.Maayan at sbdinc.com>
Cc: snmp4j at agentpp.org
Subject: Re: [SNMP4J] Possible concurrency bug in snmp4j ?
*External Message, please be cautious.*
Hi Elhanan,
Please upgrade to SNMP4J 2.5.11 to fix this issue.
Best regards
Frank
> Am 12.02.2018 um 18:05 schrieb Maayan, Elhanan <Elhanan.Maayan at sbdinc.com>:
>
> Hi..i'm using snm4j 2.4.3.
>
> Is it possible that just when snmp4j closes a connection (due to timeout, or remote closing) and it's trying to addRegistration causing to throw an exception, is it possible that snmp4j can no longer establish connection?
>
>
>
> Below is a small log of a sample client I'm doing , which does interval every 5 seconds, furthermore it's target.setTimeout is also set to 5 seconds, to emulate the bug (which actually happens upon remote close)
>
> You can see that subsequent attempts simply try to connect but don't' send anything..
>
>
>
> Mon Feb 12 18:10:37 IST 2018 Sending message
>
> Looking up connection for destination '192.168.97.21/162' returned: SocketEntry[peerAddress=192.168.97.21/162,socket=Socket[addr=qa-mv-0640.corp.aeroscout.com/192.168.97.21,port=162,localport=51072],lastUse=Mon Mar 09 04:30:03 IST 1970,readBufferPosition=-1]
>
> {192.168.97.21/162=SocketEntry[peerAddress=192.168.97.21/162,socket=Socket[addr=qa-mv-0640.corp.aeroscout.com/192.168.97.21,port=162,localport=51072],lastUse=Mon Mar 09 04:30:03 IST 1970,readBufferPosition=-1]}
>
> Waking up selector for new message
>
> Socket has not been used for 10002 milliseconds, closing it
>
> Socket to 192.168.97.21/162 closed due to timeout
>
> Adding operation 8 for: SocketEntry[peerAddress=192.168.97.21/162,socket=Socket[unconnected],lastUse=Mon Mar 09 04:30:13 IST 1970,readBufferPosition=-1]
>
> java.nio.channels.ClosedChannelException
>
> Firing transport state event: org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 1d6c6de8,peerAddress=192.168.97.21/162,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]
>
> State changed to Closed Peer address 192.168.97.21/162
>
> Exception in thread "DefaultTCPTransportMapping_192.168.60.80/0" java.lang.RuntimeException: java.nio.channels.ClosedChannelException
>
> at org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread.processPending(DefaultTcpTransportMapping.java:697)
>
> at org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread.run(DefaultTcpTransportMapping.java:893)
>
> at java.lang.Thread.run(Thread.java:745)
>
> Caused by: java.nio.channels.ClosedChannelException
>
> at java.nio.channels.spi.AbstractSelectableChannel.register(AbstractSelectableChannel.java:197)
>
> at org.snmp4j.transport.DefaultTcpTransportMapping$SocketEntry.addRegistration(DefaultTcpTransportMapping.java:433)
>
> at org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread.processPending(DefaultTcpTransportMapping.java:658)
>
> ... 2 more
>
> Mon Feb 12 18:10:47 IST 2018 Sending message
>
> Looking up connection for destination '192.168.97.21/162' returned: null
>
> {}
>
> Socket for address '192.168.97.21/162' is closed, opening it...
>
> Trying to connect to 192.168.97.21/162
>
> Mon Feb 12 18:10:57 IST 2018 Sending message
>
> Looking up connection for destination '192.168.97.21/162' returned: SocketEntry[peerAddress=192.168.97.21/162,socket=Socket[unconnected],lastUse=Mon Mar 09 04:30:23 IST 1970,readBufferPosition=-1]
>
> {192.168.97.21/162=SocketEntry[peerAddress=192.168.97.21/162,socket=Socket[unconnected],lastUse=Mon Mar 09 04:30:23 IST 1970,readBufferPosition=-1]}
>
> Socket for address '192.168.97.21/162' is closed, opening it...
>
> Trying to connect to 192.168.97.21/162
>
> Mon Feb 12 18:11:07 IST 2018 Sending message
>
> Looking up connection for destination '192.168.97.21/162' returned: SocketEntry[peerAddress=192.168.97.21/162,socket=Socket[unconnected],lastUse=Mon Mar 09 04:30:33 IST 1970,readBufferPosition=-1]
>
> {192.168.97.21/162=SocketEntry[peerAddress=192.168.97.21/162,socket=Socket[unconnected],lastUse=Mon Mar 09 04:30:33 IST 1970,readBufferPosition=-1]}
>
> Socket for address '192.168.97.21/162' is closed, opening it...
> _______________________________________________
> SNMP4J mailing list
> SNMP4J at agentpp.org
> https://oosnmp.net/mailman/listinfo/snmp4j
More information about the SNMP4J
mailing list