[SNMP4J] random problem sending command over TCP

Wed Nov 4 11:14:48 CET 2009

Hi Frank,

I have a random problem using SNMP4J version 1.10 SNAPSHOT 12/10/2009.
I know that SNMP4J 1.10.2 was released since then, but I cannot try it in 
this environment right now. I hope to try it soon, to check if it solves 
this problem.

My application hangs forever while sending a command by TCP (the client is 
not listening to commands in that case). 
My feeling is that problem occurs when the application has been idle (i.e. 
receiving TRAP but not sending commands) during a long time (e.g. 8 
hours). The first try to send a command hangs. The next ones to the same 
client work ok (i.e. the client does not answer, but the send command 
finishes gracefully).

Please find enclosed the logs
I am not sure it is a SNMP4J problem, it could be another IBM problem like 
when we manually tried to close the TCP connection.

I will let you know if I can reproduce it with 1.10.2 final.

Thanks
Regards

************ Start Display Current Environment ************
WebSphere Platform 6.1 [ND 6.1.0.17 cf170821.07] [EJB3 6.1.0.17 
cf170821.02]  running with process name 
mmmaix11aCell\mmmaix11a\xxxxx_cluster_srv1 and process id 274738
Host Operating System is AIX, version 5.3
Java version = J2RE 1.5.0 IBM J9 2.3 AIX ppc-32 j9vmap3223-20080315 (JIT 
enabled)
J9VM - 20080314_17962_bHdSMr
JIT  - 20080130_0718ifx2_r8
GC   - 200802_08, Java Compiler = j9jit23, Java VM name = IBM J9 VM
was.install.root = /usr/WebSphere61/AppServer
user.install.root = /usr/WebSphere61/AppServer/profiles/AppSrv
Java Home = /usr/WebSphere61/AppServer/java/jre
ws.ext.dirs = 
/usr/WebSphere61/AppServer/java/lib:/usr/WebSphere61/AppServer/profiles/AppSrv/classes:/usr/WebSphere61/AppServer/classes:/usr/WebSphere61/AppServer/lib:/usr/WebSphere61/AppServer/installedChannels:/usr/WebSphere61/AppServer/lib/ext:/usr/WebSphere61/AppServer/web/help:/usr/WebSphere61/AppServer/deploytool/itp/plugins/com.ibm.etools.ejbdeploy/runtime
Classpath = 
/usr/WebSphere61/AppServer/profiles/AppSrv/properties:/usr/WebSphere61/AppServer/properties:/usr/WebSphere61/AppServer/lib/startup.jar:/usr/WebSphere61/AppServer/lib/bootstrap.jar:/usr/WebSphere61/AppServer/lib/j2ee.jar:/usr/WebSphere61/AppServer/lib/lmproxy.jar:/usr/WebSphere61/AppServer/lib/urlprotocols.jar:/usr/WebSphere61/AppServer/deploytool/itp/batchboot.jar:/usr/WebSphere61/AppServer/deploytool/itp/batch2.jar:/usr/WebSphere61/AppServer/java/lib/tools.jar:/expl/xxxxx/configuracion
Java Library path = 
/usr/WebSphere61/AppServer/java/jre/bin:/usr/WebSphere61/AppServer/java/jre/bin:/usr/WebSphere61/AppServer/java/jre/bin/classic:/usr/WebSphere61/AppServer/java/jre/bin:/usr/WebSphere61/AppServer/bin:/expl/HSM/libPlaca/libCCA4758:/usr/mqm/java/lib:/usr/WebSphere61/AppServer/java/jre/bin/j9vm:/usr/WebSphere61/AppServer/java/jre/bin/j9vm:/usr/mqm/java/lib:/usr/lib:/usr/WebSphere61/AppServer/lib/WMQ/java/lib
************* End Display Current Environment *************
[11/4/09 9:25:23:788 CET] 00000067 ServletWrappe I   SRVE0242I: [xxxxx] 
[/xxxxx] [/index.jsp]: Initialization successful.
[11/4/09 9:25:23:912 CET] 00000067 LoggerListene W 
org.springframework.security.event.authentication.LoggerListener 
onApplicationEvent Authentication event AuthenticationSuccessEvent: 
xxxxxxx; details: 
org.springframework.security.ui.WebAuthenticationDetails at fffde5d4: 
RemoteIpAddress: 10.2.2.144; SessionId: He_iDPJLjiyYBb5LT4garTt
[11/4/09 9:25:25:941 CET] 00000071 ServletWrappe I   SRVE0242I: [xxxxx] 
[/xxxxx] [/WEB-INF/tiles/body/commandCenter.jsp]: Initialization 
successful.
[11/4/09 9:25:34:423 CET] 00000070 SystemOut     O org.snmp4j.security.USM 
<generateResponseMessage> RFC3414 §3.1.4.b Outgoing message is not 
encrypted
[11/4/09 9:25:34:426 CET] 00000070 SystemOut     O 
org.snmp4j.mp.MPv3$Cache <addEntry> Adding cache entry: 
StateReference[msgID=722819076,pduHandle=PduHandle[1975023096],securityEngineID=,securityModel=org.snmp4j.security.USM at 76fc76fc,securityName=urwxxxxxxx,securityLevel=1,contextEngineID=,contextName=]
[11/4/09 9:25:34:429 CET] 00000070 SystemOut     O 
org.snmp4j.Snmp$PendingRequest <pduHandleAssigned> Running pending sync 
request with handle PduHandle[1975023096] and retry count left 0
[11/4/09 9:25:34:440 CET] 00000070 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <sendMessage> 
Looking up connection for destination '222.21.122.222/161' returned: null
[11/4/09 9:25:34:442 CET] 00000070 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <sendMessage> 
{}
[11/4/09 9:25:34:444 CET] 00000070 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <sendMessage> 
Socket for address '222.21.122.222/161' is closed, opening it...
[11/4/09 9:25:34:452 CET] 00000070 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <sendMessage> 
Trying to connect to 222.21.122.222/161
[11/4/09 9:25:34:481 CET] 00000072 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread 
<processPending> Registering for connect: 
SocketEntry[peerAddress=222.21.122.222/161,socket=Socket[unconnected],lastUse=Wed 
Nov 04 09:25:34 CET 2009]
[11/4/09 9:25:39:449 CET] 00000074 SystemOut     O 
org.snmp4j.Snmp$PendingRequest <run> Request timed out: 1975023096
[11/4/09 9:26:49:535 CET] 00000072 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <run> Key is 
connectable
[11/4/09 9:26:49:537 CET] 00000072 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread 
<connectChannel> java.net.ConnectException: A remote host did not respond 
within the timeout period.
[11/4/09 9:26:49:539 CET] 00000072 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread 
<processPending> Registering for connect: 
SocketEntry[peerAddress=222.21.122.222/161,socket=Socket[unconnected],lastUse=Wed 
Nov 04 09:25:34 CET 2009]
[11/4/09 9:26:49:540 CET] 00000072 SystemOut     O 
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread 
<processPending> java.nio.channels.ClosedChannelException
[11/4/09 9:26:49:542 CET] 00000072 SystemOut     O 
org.snmp4j.transport.TcpTransportMapping <fireConnectionStateChanged> 
Firing transport state event: 
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 4c564c56,peerAddress=222.21.122.222/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]
[11/4/09 9:37:12:886 CET] 0000000c ThreadMonitor W   WSVR0605W: Thread 
"WebContainer : 4" (00000070) has been active for 698780 milliseconds and 
may be hung.  There is/are 1 thread(s) in total in the server that may be 
hung.
[11/4/09 9:58:32:760 CET] 00000067 LoggerListene W 
org.springframework.security.event.authentication.LoggerListener 
onApplicationEvent Authentication event AuthenticationSuccessEvent: 
xxxxxxx; details: 
org.springframework.security.ui.WebAuthenticationDetails at fffc7f0c: 
RemoteIpAddress: 10.2.2.144; SessionId: 2xXUg3GXjUY1BkZHYdd17KN