[SNMP4J] Possible concurrency bug in snmp4j ?

Wed Feb 14 10:08:37 CET 2018

2.6.0 will be released next week. 

> Am 13.02.2018 um 18:15 schrieb Maayan, Elhanan <Elhanan.Maayan at sbdinc.com>:
> 
> Thanks, do you have any timeline regarding 2.6?
>  
> From: Frank Fock [mailto:fock at agentpp.com] 
> Sent: Tuesday, February 13, 2018 7:15 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.*
> 2.5.11 might already solve the problem, that depends on your usage profile.
> The work around would be to apply the 2.6.0 DefaultTcpMapping sources to your version, if you do not like to use/wait for that version.
>  
> 
> 
> On 13. Feb 2018, at 10:53, Maayan, Elhanan <Elhanan.Maayan at sbdinc.com> wrote:
>  
> so 2.5.11 won't help? Any workaround?
> 
> Get Outlook for Android
>  
> From: Frank Fock <fock at agentpp.com>
> Sent: Tuesday, February 13, 2018 11:51:23 AM
> To: Maayan, Elhanan
> Cc: snmp4j at agentpp.org
> Subject: Re: [SNMP4J] Possible concurrency bug in snmp4j ?
>  
> *External Message, please be cautious.*
> 
> The immediate reconnection issue (TCP) to the same address and port (SFJ-164) has been fixed in SNMP4J 2.6.0 which is available as SNAPSHOT. 
> 
> See also the mailing list archive around January 27th. 
> 
> The ticket system is available for users with support contract.
> 
> Best regards,
> Frank 
> 
> > On 12. Feb 2018, at 19:53, Maayan, Elhanan <Elhanan.Maayan at sbdinc.com> wrote:
> > 
> > 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
> > 
>  