[SNMP4J] TcpTransportMapping.close(address) hanging in AIX
Brice Fines
bfines at sermepa.es
Wed Oct 21 19:03:58 CEST 2009
Hi,
(sorry I had no time to try it yesterday).
I downloaded snapshot of 21 October 2009.
Here are the logs.
Regards.
[10/21/09 19:00:33:097 CEST] 00000034 SystemOut O org.snmp4j.mp.MPv3
<prepareOutgoingMessage> Context engine ID of scoped PDU is empty! Setting
it to authoritative engine ID: 80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a
[10/21/09 19:00:33:104 CEST] 00000034 SystemOut O
org.snmp4j.security.USM <getUser>
getUser(engineID=80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a,
securityName=urwxxxxxxx)
[10/21/09 19:00:33:109 CEST] 00000034 SystemOut O
org.snmp4j.security.USM <generateResponseMessage> RFC3414 §3.1.4.b
Outgoing message is not encrypted
[10/21/09 19:00:33:117 CEST] 00000034 SystemOut O
org.snmp4j.mp.MPv3$Cache <addEntry> Adding cache entry:
StateReference[msgID=807915147,pduHandle=PduHandle[614437318],securityEngineID=80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a,securityModel=org.snmp4j.security.USM at 79d279d2,securityName=urwxxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a,contextName=]
[10/21/09 19:00:33:128 CEST] 00000034 SystemOut O
org.snmp4j.Snmp$PendingRequest <pduHandleAssigned> Running pending sync
request with handle PduHandle[614437318] and retry count left 0
[10/21/09 19:00:33:133 CEST] 00000034 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <sendMessage>
Looking up connection for destination '10.2.2.91/161' returned: null
[10/21/09 19:00:33:138 CEST] 00000034 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <sendMessage>
{}
[10/21/09 19:00:33:142 CEST] 00000034 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <sendMessage>
Socket for address '10.2.2.91/161' is closed, opening it...
[10/21/09 19:00:33:149 CEST] 00000034 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <sendMessage>
Trying to connect to 10.2.2.91/161
[10/21/09 19:00:33:150 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread
<processPending> Registering for connect:
SocketEntry[peerAddress=10.2.2.91/161,socket=Socket[unconnected],lastUse=Wed
Oct 21 19:00:33 CEST 2009]
[10/21/09 19:00:33:152 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <run> Key is
connectable
[10/21/09 19:00:33:153 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread
<connectChannel> Connected to 10.2.2.91/161
[10/21/09 19:00:33:158 CEST] 0000003a SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping <close> Socket to
10.2.2.66/161 closed
[10/21/09 19:00:33:162 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread
<connectChannel> Fire connected event for null
[10/21/09 19:00:33:164 CEST] 00000038 SystemOut O
org.snmp4j.transport.TcpTransportMapping <fireConnectionStateChanged>
Firing transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 56225622,peerAddress=10.2.2.91/161,newState=1,cancelled=false,causingException=null]
[10/21/09 19:00:33:165 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread
<processPending> Registering for write:
SocketEntry[peerAddress=10.2.2.91/161,socket=Socket[addr=/10.2.2.91,port=161,localport=39578],lastUse=Wed
Oct 21 19:00:33 CEST 2009]
[10/21/09 19:00:33:167 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <run> Key is
writable
[10/21/09 19:00:33:169 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread
<writeMessage> Send message with length 133 to 10.2.2.91/161:
30:81:82:02:01:03:30:11:02:04:30:27:ce:8b:02:03:00:ff:ff:04:01:05:02:01:03:04:36:30:34:04:0d:80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a:02:02:02:01:02:03:06:d5:b5:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:f6:69:16:33:e5:03:08:a7:12:e6:2b:a6:04:00:30:32:04:0d:80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a:04:00:a0:1f:02:04:24:9f:91:c6:02:01:00:02:01:00:30:11:30:0f:06:0b:2b:06:01:04:01:b6:20:01:01:01:01:05:00
[10/21/09 19:00:33:182 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <run> Key is
readable
[10/21/09 19:00:33:183 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <run> Key is
reading
[10/21/09 19:00:33:185 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <readMessage>
Reading header 6 bytes from 10.2.2.91/161
[10/21/09 19:00:33:186 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread <readMessage>
Message length is
org.snmp4j.transport.MessageLength[headerLength=3,payloadLength=148]
[10/21/09 19:00:33:188 CEST] 00000038 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread
<dispatchMessage> Received message from 10.2.2.91/161 with length 151:
30:81:94:02:01:03:30:12:02:04:30:27:ce:8b:02:04:7f:ff:ff:ff:04:01:01:02:01:03:04:36:30:34:04:0d:80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a:02:02:02:01:02:03:06:d5:b5:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:52:e9:5c:ef:e5:af:a8:73:e0:a0:e7:41:04:00:30:43:04:0d:80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a:04:00:a2:30:02:04:24:9f:91:c6:02:01:00:02:01:00:30:22:30:20:06:0b:2b:06:01:04:01:b6:20:01:01:01:01:04:11:30:30:38:31:2d:38:38:38:38:2d:38:38:20:30:30:38:31
[10/21/09 19:00:33:190 CEST] 00000038 SystemOut O
org.snmp4j.mp.MPv3$HeaderData <decodeBER> SNMPv3 header decoded:
msgId=807915147, msgMaxSize=2147483647, msgFlags=01, secModel=3
[10/21/09 19:00:33:195 CEST] 00000038 SystemOut O
org.snmp4j.security.USM <getUser>
getUser(engineID=80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a,
securityName=urwxxxxxxx)
[10/21/09 19:00:33:201 CEST] 00000038 SystemOut O
org.snmp4j.security.UsmTimeTable <checkTime> CheckTime: time ok (non
authorative)
[10/21/09 19:00:33:213 CEST] 00000038 SystemOut O
org.snmp4j.mp.MPv3$Cache <popEntry> Removed cache entry:
StateReference[msgID=807915147,pduHandle=PduHandle[614437318],securityEngineID=80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a,securityModel=org.snmp4j.security.USM at 79d279d2,securityName=urwxxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:e7:25:00:00:e1:03:4a:4a,contextName=]
[10/21/09 19:00:33:214 CEST] 00000038 SystemOut O org.snmp4j.mp.MPv3
<prepareDataElements> RFC3412 §7.2.10 - Received PDU (msgID=807915147) is
a response or an internal class message. PduHandle.transactionID =
614437318
[10/21/09 19:00:33:224 CEST] 00000038 SystemOut O org.snmp4j.mp.MPv3
<prepareDataElements> MPv3 finished
[10/21/09 19:00:33:225 CEST] 00000038 SystemOut O org.snmp4j.Snmp
<processPdu> Looking up pending request with handle PduHandle[614437318]
[10/21/09 19:00:33:243 CEST] 00000034 SystemOut O org.snmp4j.Snmp
<send> Removed pending request with handle: PduHandle[614437318]
[10/21/09 19:00:33:272 CEST] 00000034 SystemOut O
org.snmp4j.transport.DefaultTcpTransportMapping <close> Closing socket for
peer address 10.2.2.91/161
More information about the SNMP4J
mailing list