[SNMP4J] Problem with DefaultTCPTransportMapping
Brice Fines
bfines at sermepa.es
Wed Sep 30 16:49:51 CEST 2009
Hi,
I have a problem using DefaultTCPTransportMapping.
I am using SNMP4J.jar version 1.10.1 to send SNMP GET over TCP.
I am using a unique TcpTransportMapping instance to send the SNMP commands
to various clients.
It seems that everything is ok while I get a SNMP GET response from the
clients, but if try to connect to one that is not online, I get a connect
a java.net.ConnectException. It seems that DefaultTCPTransportMapping
cannot recover from this one, because all the follwing commands sent to
previous clients (i.e. the one that were working) result in
java.nio.ClosedChannelException in DefaultTCPTransportMapping.
For example, the sequence would be:
1) send GET command to client 1 that is listenning over TCP.
2) get GET response from client 1 over TCP.
3) send GET command to client 2 that is not listenning over TCP.
4) get java.net.ConnectExecption in DefaultTCPTransportMapping.
5) send GET command to client 1 again.
6) get java.nio.ClosedChannelExceptionin DefaultTCPTransportMapping.
Please find enclosed some SNMP4J matching that sequence at the end of the
document (hope it can help).
I tried to manually close every TcpTransportMapping connection (using
TcpTransportMapping.close(address)) after each send, but I still have the
same problem.
I tried to send GET commands to others clients and everything is Ok while
I got an answer from them, but it stops working if one of them fails to
connect.
Should I use a differend TcpTransportMapping for every command that I
send?
Am I forgetting to close something in TcpTransportMapping?
Is there a way for DefaultTcpTransportMapping to recover?
Thanks
Regards
//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
This log corresponds to the the first GET command to client 1, and the
result is a nice GET response
//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368371,pduHandle=PduHandle[1461997048],securityEngineID=,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=1,contextEngineID=,contextName=]>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368371,pduHandle=PduHandle[1461997048],securityEngineID=,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=1,contextEngineID=,contextName=]>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.Snmp] - <Running pending sync request with
handle PduHandle[1461997048] and retry count left 0>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.Snmp] - <Running pending sync request with
handle PduHandle[1461997048] and retry count left 0>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.127/161' returned: null>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.127/161' returned: null>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{}>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{}>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Socket for address '10.2.2.127/161' is closed, opening it...>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Socket for address '10.2.2.127/161' is closed, opening it...>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Trying to connect to 10.2.2.127/161>
[30/09/09 15:43:24:530 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Trying to connect to 10.2.2.127/161>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Connected to 10.2.2.127/161>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Connected to 10.2.2.127/161>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=null,newState=1,cancelled=false,causingException=null]>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=null,newState=1,cancelled=false,causingException=null]>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Send message with length 61 to 10.2.2.127/161:
30:3b:02:01:03:30:11:02:04:7e:90:07:b3:02:03:00:ff:ff:04:01:04:02:01:03:04:10:30:0e:04:00:02:01:00:02:01:00:04:00:04:00:04:00:30:11:04:00:04:00:a0:0b:02:01:00:02:01:00:02:01:00:30:00>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Send message with length 61 to 10.2.2.127/161:
30:3b:02:01:03:30:11:02:04:7e:90:07:b3:02:03:00:ff:ff:04:01:04:02:01:03:04:10:30:0e:04:00:02:01:00:02:01:00:04:00:04:00:04:00:30:11:04:00:04:00:a0:0b:02:01:00:02:01:00:02:01:00:30:00>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Reading header 6 bytes from 10.2.2.127/161>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Reading header 6 bytes from 10.2.2.127/161>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Message length is
org.snmp4j.transport.MessageLength[headerLength=2,payloadLength=105]>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Message length is
org.snmp4j.transport.MessageLength[headerLength=2,payloadLength=105]>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Received message from 10.2.2.127/161 with length 107:
30:69:02:01:03:30:12:02:04:7e:90:07:b3:02:04:7f:ff:ff:ff:04:01:00:02:01:03:04:1f:30:1d:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:3f:02:03:02:f3:ff:04:00:04:00:04:00:30:2f:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a8:1c:02:01:00:02:01:00:02:01:00:30:11:30:0f:06:0a:2b:06:01:06:03:0f:01:01:04:00:41:01:1b>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Received message from 10.2.2.127/161 with length 107:
30:69:02:01:03:30:12:02:04:7e:90:07:b3:02:04:7f:ff:ff:ff:04:01:00:02:01:03:04:1f:30:1d:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:3f:02:03:02:f3:ff:04:00:04:00:04:00:30:2f:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a8:1c:02:01:00:02:01:00:02:01:00:30:11:30:0f:06:0a:2b:06:01:06:03:0f:01:01:04:00:41:01:1b>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <SNMPv3 header decoded:
msgId=2123368371, msgMaxSize=2147483647, msgFlags=00, secModel=3>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <SNMPv3 header decoded:
msgId=2123368371, msgMaxSize=2147483647, msgFlags=00, secModel=3>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.security.USM] - <Accepting zero length
security name>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.security.USM] - <Accepting zero length
security name>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <Removed cache entry:
StateReference[msgID=2123368371,pduHandle=PduHandle[1461997048],securityEngineID=,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=1,contextEngineID=,contextName=]>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <Removed cache entry:
StateReference[msgID=2123368371,pduHandle=PduHandle[1461997048],securityEngineID=,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=1,contextEngineID=,contextName=]>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <RFC3412 §7.2.10 - Received PDU
(msgID=2123368371) is a response or an internal class message.
PduHandle.transactionID = 1461997048>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <RFC3412 §7.2.10 - Received PDU
(msgID=2123368371) is a response or an internal class message.
PduHandle.transactionID = 1461997048>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <MPv3 finished>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <MPv3 finished>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.Snmp] - <Searching pending request with
handlePduHandle[1461997048]>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.Snmp] - <Searching pending request with
handlePduHandle[1461997048]>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.Snmp] - <Send new request after report.>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.Snmp] - <Send new request after report.>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <Context engine ID of scoped PDU
is empty! Setting it to authoritative engine ID:
80:00:1f:88:80:7d:10:00:00:29:15:78:4a>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.mp.MPv3] - <Context engine ID of scoped PDU
is empty! Setting it to authoritative engine ID:
80:00:1f:88:80:7d:10:00:00:29:15:78:4a>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:24:530 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,530 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.AuthGeneric] - <MD5First digest:
b4:f1:54:db:6f:3f:08:b8:1a:93:2a:f0:a3:aa:ae:e4>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.AuthGeneric] - <MD5First digest:
b4:f1:54:db:6f:3f:08:b8:1a:93:2a:f0:a3:aa:ae:e4>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.AuthGeneric] - <MD5localized key:
17:42:83:41:47:2d:39:41:b0:82:58:90:1e:69:2e:fb>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.AuthGeneric] - <MD5localized key:
17:42:83:41:47:2d:39:41:b0:82:58:90:1e:69:2e:fb>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.UsmUserTable] - <Adding user
urwXxxxxxx =
UsmUser[secName=urwXxxxxxx,authProtocol=1.3.6.1.6.3.10.1.1.2,authPassphrase=17:42:83:41:47:2d:39:41:b0:82:58:90:1e:69:2e:fb,privProtocol=null,privPassphrase=null,localizationEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a]>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.UsmUserTable] - <Adding user
urwXxxxxxx =
UsmUser[secName=urwXxxxxxx,authProtocol=1.3.6.1.6.3.10.1.1.2,authPassphrase=17:42:83:41:47:2d:39:41:b0:82:58:90:1e:69:2e:fb,privProtocol=null,privPassphrase=null,localizationEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a]>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368372,pduHandle=PduHandle[1461997048],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368372,pduHandle=PduHandle[1461997048],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.127/161' returned:
SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.127/161' returned:
SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{10.2.2.127/161=SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]}>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{10.2.2.127/161=SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]}>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Send message with length 129 to 10.2.2.127/161:
30:7f:02:01:03:30:11:02:04:7e:90:07:b4:02:03:00:ff:ff:04:01:05:02:01:03:04:33:30:31:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:00:02:01:00:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:f3:36:a0:12:77:e1:a6:50:f1:3c:a2:9d:04:00:30:32:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a0:1f:02:04:57:24:4d:f8: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>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Send message with length 129 to 10.2.2.127/161:
30:7f:02:01:03:30:11:02:04:7e:90:07:b4:02:03:00:ff:ff:04:01:05:02:01:03:04:33:30:31:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:00:02:01:00:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:f3:36:a0:12:77:e1:a6:50:f1:3c:a2:9d:04:00:30:32:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a0:1f:02:04:57:24:4d:f8: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>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Reading header 6 bytes from 10.2.2.127/161>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Reading header 6 bytes from 10.2.2.127/161>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Message length is
org.snmp4j.transport.MessageLength[headerLength=3,payloadLength=130]>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Message length is
org.snmp4j.transport.MessageLength[headerLength=3,payloadLength=130]>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Received message from 10.2.2.127/161 with length 133:
30:81:82:02:01:03:30:12:02:04:7e:90:07:b4:02:04:7f:ff:ff:ff:04:01:01:02:01:03:04:35:30:33:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:3f:02:03:02:f3:ff:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:9f:a0:94:d2:37:e2:8b:75:59:ed:fb:8f:04:00:30:32:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a8:1f:02:04:57:24:4d:f8:02:01:00:02:01:00:30:11:30:0f:06:0a:2b:06:01:06:03:0f:01:01:02:00:41:01:1d>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Received message from 10.2.2.127/161 with length 133:
30:81:82:02:01:03:30:12:02:04:7e:90:07:b4:02:04:7f:ff:ff:ff:04:01:01:02:01:03:04:35:30:33:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:3f:02:03:02:f3:ff:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:9f:a0:94:d2:37:e2:8b:75:59:ed:fb:8f:04:00:30:32:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a8:1f:02:04:57:24:4d:f8:02:01:00:02:01:00:30:11:30:0f:06:0a:2b:06:01:06:03:0f:01:01:02:00:41:01:1d>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.mp.MPv3] - <SNMPv3 header decoded:
msgId=2123368372, msgMaxSize=2147483647, msgFlags=01, secModel=3>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.mp.MPv3] - <SNMPv3 header decoded:
msgId=2123368372, msgMaxSize=2147483647, msgFlags=01, secModel=3>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:24:655 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,655 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.UsmTimeTable] - <CheckTime: time
ok (non authorative)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.UsmTimeTable] - <CheckTime: time
ok (non authorative)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <Removed cache entry:
StateReference[msgID=2123368372,pduHandle=PduHandle[1461997048],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <Removed cache entry:
StateReference[msgID=2123368372,pduHandle=PduHandle[1461997048],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <RFC3412 §7.2.10 - Received PDU
(msgID=2123368372) is a response or an internal class message.
PduHandle.transactionID = 1461997048>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <RFC3412 §7.2.10 - Received PDU
(msgID=2123368372) is a response or an internal class message.
PduHandle.transactionID = 1461997048>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <MPv3 finished>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <MPv3 finished>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.Snmp] - <Searching pending request with
handlePduHandle[1461997048]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.Snmp] - <Searching pending request with
handlePduHandle[1461997048]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.Snmp] - <Send new request after report.>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.Snmp] - <Send new request after report.>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368373,pduHandle=PduHandle[1461997048],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368373,pduHandle=PduHandle[1461997048],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.127/161' returned:
SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.127/161' returned:
SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{10.2.2.127/161=SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]}>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{10.2.2.127/161=SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]}>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Send message with length 132 to 10.2.2.127/161:
30:81:81:02:01:03:30:11:02:04:7e:90:07:b5:02:03:00:ff:ff:04:01:05:02:01:03:04:35:30:33:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:3f:02:03:02:f3:ff:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:a2:86:70:c2:08:80:4f:bd:59:e9:a6:16:04:00:30:32:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a0:1f:02:04:57:24:4d:f8: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>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Send message with length 132 to 10.2.2.127/161:
30:81:81:02:01:03:30:11:02:04:7e:90:07:b5:02:03:00:ff:ff:04:01:05:02:01:03:04:35:30:33:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:3f:02:03:02:f3:ff:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:a2:86:70:c2:08:80:4f:bd:59:e9:a6:16:04:00:30:32:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a0:1f:02:04:57:24:4d:f8: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>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Reading header 6 bytes from 10.2.2.127/161>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Reading header 6 bytes from 10.2.2.127/161>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Message length is
org.snmp4j.transport.MessageLength[headerLength=3,payloadLength=147]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Message length is
org.snmp4j.transport.MessageLength[headerLength=3,payloadLength=147]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Received message from 10.2.2.127/161 with length 150:
30:81:93:02:01:03:30:12:02:04:7e:90:07:b5:02:04:7f:ff:ff:ff:04:01:01:02:01:03:04:35:30:33:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:3f:02:03:02:f3:ff:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:ed:5d:3c:82:0a:bd:48:3f:b8:16:c8:60:04:00:30:43:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a2:30:02:04:57:24:4d:f8: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:36:35:2d:38:38:38:38:2d:38:38:20:30:30:36:35>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Received message from 10.2.2.127/161 with length 150:
30:81:93:02:01:03:30:12:02:04:7e:90:07:b5:02:04:7f:ff:ff:ff:04:01:01:02:01:03:04:35:30:33:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:02:01:3f:02:03:02:f3:ff:04:0a:75:72:77:53:65:72:6d:65:70:61:04:0c:ed:5d:3c:82:0a:bd:48:3f:b8:16:c8:60:04:00:30:43:04:0d:80:00:1f:88:80:7d:10:00:00:29:15:78:4a:04:00:a2:30:02:04:57:24:4d:f8: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:36:35:2d:38:38:38:38:2d:38:38:20:30:30:36:35>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <SNMPv3 header decoded:
msgId=2123368373, msgMaxSize=2147483647, msgFlags=01, secModel=3>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <SNMPv3 header decoded:
msgId=2123368373, msgMaxSize=2147483647, msgFlags=01, secModel=3>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.UsmTimeTable] - <CheckTime: time
ok (non authorative)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.security.UsmTimeTable] - <CheckTime: time
ok (non authorative)>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <Removed cache entry:
StateReference[msgID=2123368373,pduHandle=PduHandle[1461997048],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <Removed cache entry:
StateReference[msgID=2123368373,pduHandle=PduHandle[1461997048],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <RFC3412 §7.2.10 - Received PDU
(msgID=2123368373) is a response or an internal class message.
PduHandle.transactionID = 1461997048>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <RFC3412 §7.2.10 - Received PDU
(msgID=2123368373) is a response or an internal class message.
PduHandle.transactionID = 1461997048>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <MPv3 finished>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.mp.MPv3] - <MPv3 finished>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.Snmp] - <Looking up pending request with
handle PduHandle[1461997048]>
[30/09/09 15:43:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.Snmp] - <Looking up pending request with
handle PduHandle[1461997048]>
[30/09/09 15:43:24:670 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.Snmp] - <Removed pending request with
handle: PduHandle[1461997048]>
[30/09/09 15:43:24:670 CEST] 00000030 SystemOut O 2009-09-30
15:43:24,670 DEBUG [org.snmp4j.Snmp] - <Removed pending request with
handle: PduHandle[1461997048]>
//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
This log corresponds to the the first GET command to client 2, but this
client is not listenning and I get a ConnectException
//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368374,pduHandle=PduHandle[1461997052],securityEngineID=,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=1,contextEngineID=,contextName=]>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368374,pduHandle=PduHandle[1461997052],securityEngineID=,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=1,contextEngineID=,contextName=]>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.Snmp] - <Running pending sync request with
handle PduHandle[1461997052] and retry count left 0>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.Snmp] - <Running pending sync request with
handle PduHandle[1461997052] and retry count left 0>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.66/161' returned: null>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.66/161' returned: null>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{10.2.2.127/161=SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]}>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{10.2.2.127/161=SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]}>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Socket for address '10.2.2.66/161' is closed, opening it...>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Socket for address '10.2.2.66/161' is closed, opening it...>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Trying to connect to 10.2.2.66/161>
[30/09/09 15:43:30:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:30,795 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Trying to connect to 10.2.2.66/161>
[30/09/09 15:43:31:905 CEST] 00000034 SystemOut O 2009-09-30
15:43:31,905 WARN [org.snmp4j.transport.DefaultTcpTransportMapping] - <
java.net.ConnectException: Connection refused: no further information>
[30/09/09 15:43:31:905 CEST] 00000034 SystemOut O 2009-09-30
15:43:31,905 WARN [org.snmp4j.transport.DefaultTcpTransportMapping] - <
java.net.ConnectException: Connection refused: no further information>
[30/09/09 15:43:31:905 CEST] 00000034 SystemOut O 2009-09-30
15:43:31,905 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:43:31:905 CEST] 00000034 SystemOut O 2009-09-30
15:43:31,905 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:43:31:905 CEST] 00000034 SystemOut O 2009-09-30
15:43:31,905 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:43:31:905 CEST] 00000034 SystemOut O 2009-09-30
15:43:31,905 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:43:31:905 CEST] 00000034 SystemErr R
java.net.ConnectException: Connection refused: no further information
[30/09/09 15:43:31:905 CEST] 00000034 SystemErr R at
sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[30/09/09 15:43:31:905 CEST] 00000034 SystemErr R at
sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:602)
[30/09/09 15:43:31:905 CEST] 00000034 SystemErr R at
org.snmp4j.transport.DefaultTcpTransportMapping$ServerThread.run(
DefaultTcpTransportMapping.java:722)
[30/09/09 15:43:31:905 CEST] 00000034 SystemErr R at
java.lang.Thread.run(Thread.java:810)
[30/09/09 15:43:31:905 CEST] 00000034 SystemErr R at
org.snmp4j.util.DefaultThreadFactory$WorkerThread.run(
DefaultThreadFactory.java:65)
[30/09/09 15:43:35:795 CEST] 00000036 SystemOut O 2009-09-30
15:43:35,795 DEBUG [org.snmp4j.Snmp] - <Request timed out: 1461997052>
[30/09/09 15:43:35:795 CEST] 00000036 SystemOut O 2009-09-30
15:43:35,795 DEBUG [org.snmp4j.Snmp] - <Request timed out: 1461997052>
[30/09/09 15:43:35:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:35,795 DEBUG [org.snmp4j.Snmp] - <Removed pending request with
handle: PduHandle[1461997052]>
[30/09/09 15:43:35:795 CEST] 00000030 SystemOut O 2009-09-30
15:43:35,795 DEBUG [org.snmp4j.Snmp] - <Removed pending request with
handle: PduHandle[1461997052]>
//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
This log corresponds to the the second GET command to client 1, but
DefaultTcpTransportMapping cannot manage to connect due to previous
ClosedChannelException
//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.mp.MPv3] - <Context engine ID of scoped PDU
is empty! Setting it to authoritative engine ID:
80:00:1f:88:80:7d:10:00:00:29:15:78:4a>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.mp.MPv3] - <Context engine ID of scoped PDU
is empty! Setting it to authoritative engine ID:
80:00:1f:88:80:7d:10:00:00:29:15:78:4a>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.security.USM] -
<getUser(engineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,
securityName=urwXxxxxxx)>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.security.USM] - <RFC3414 §3.1.4.b Outgoing
message is not encrypted>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368375,pduHandle=PduHandle[1461997053],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.mp.MPv3] - <Adding cache entry:
StateReference[msgID=2123368375,pduHandle=PduHandle[1461997053],securityEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,securityModel=org.snmp4j.security.USM at 17161716,securityName=urwXxxxxxx,securityLevel=2,contextEngineID=80:00:1f:88:80:7d:10:00:00:29:15:78:4a,contextName=]>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.Snmp] - <Running pending sync request with
handle PduHandle[1461997053] and retry count left 0>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.Snmp] - <Running pending sync request with
handle PduHandle[1461997053] and retry count left 0>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.127/161' returned:
SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Looking up connection for destination '10.2.2.127/161' returned:
SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009]>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{10.2.2.127/161=SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009],
10.2.2.66/161=SocketEntry[peerAddress=10.2.2.66/161,socket=Socket[unconnected],lastUse=Wed
Sep 30 15:43:30 CEST 2009]}>
[30/09/09 15:43:54:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<{10.2.2.127/161=SocketEntry[peerAddress=10.2.2.127/161,socket=Socket[addr=/10.2.2.127,port=161,localport=1358],lastUse=Wed
Sep 30 15:43:24 CEST 2009],
10.2.2.66/161=SocketEntry[peerAddress=10.2.2.66/161,socket=Socket[unconnected],lastUse=Wed
Sep 30 15:43:30 CEST 2009]}>
[30/09/09 15:43:54:983 CEST] 00000034 SystemOut O 2009-09-30
15:43:54,983 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:43:54:983 CEST] 00000034 SystemOut O 2009-09-30
15:43:54,983 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:43:54:983 CEST] 00000034 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:43:54:983 CEST] 00000034 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:43:54:983 CEST] 00000034 SystemOut O 2009-09-30
15:43:54,983 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:43:54:983 CEST] 00000034 SystemOut O 2009-09-30
15:43:54,983 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:43:54:983 CEST] 00000034 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:43:54:983 CEST] 00000034 SystemOut O 2009-09-30
15:43:54,983 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:43:59:983 CEST] 00000036 SystemOut O 2009-09-30
15:43:59,983 DEBUG [org.snmp4j.Snmp] - <Request timed out: 1461997053>
[30/09/09 15:43:59:983 CEST] 00000036 SystemOut O 2009-09-30
15:43:59,983 DEBUG [org.snmp4j.Snmp] - <Request timed out: 1461997053>
[30/09/09 15:43:59:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:59,983 DEBUG [org.snmp4j.Snmp] - <Removed pending request with
handle: PduHandle[1461997053]>
[30/09/09 15:43:59:983 CEST] 00000030 SystemOut O 2009-09-30
15:43:59,983 DEBUG [org.snmp4j.Snmp] - <Removed pending request with
handle: PduHandle[1461997053]>
[30/09/09 15:44:24:545 CEST] 00000038 SystemOut O 2009-09-30
15:44:24,545 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Scheduling 125>
[30/09/09 15:44:24:545 CEST] 00000038 SystemOut O 2009-09-30
15:44:24,545 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Scheduling 125>
[30/09/09 15:44:24:670 CEST] 00000038 SystemOut O 2009-09-30
15:44:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Socket has not been used for 60000 micro seconds, closing it>
[30/09/09 15:44:24:670 CEST] 00000038 SystemOut O 2009-09-30
15:44:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Socket has not been used for 60000 micro seconds, closing it>
[30/09/09 15:44:24:670 CEST] 00000038 SystemOut O 2009-09-30
15:44:24,670 INFO [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Socket to 10.2.2.127/161 closed due to timeout>
[30/09/09 15:44:24:670 CEST] 00000038 SystemOut O 2009-09-30
15:44:24,670 INFO [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Socket to 10.2.2.127/161 closed due to timeout>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Read channel not open, no bytes read from 10.2.2.127/161>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 DEBUG [org.snmp4j.transport.DefaultTcpTransportMapping] -
<Read channel not open, no bytes read from 10.2.2.127/161>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 ERROR [org.snmp4j.transport.DefaultTcpTransportMapping] -
<java.nio.channels.ClosedChannelException>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
[30/09/09 15:44:24:670 CEST] 00000034 SystemOut O 2009-09-30
15:44:24,670 DEBUG [org.snmp4j.transport.TcpTransportMapping] - <Firing
transport state event:
org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 6c446c44,peerAddress=10.2.2.66/161,newState=4,cancelled=false,causingException=java.nio.channels.ClosedChannelException]>
More information about the SNMP4J
mailing list