[SNMP4J] Problem with DefaultTCPTransportMapping
Frank Fock
fock at agentpp.com
Wed Sep 30 23:39:51 CEST 2009
Hi Brice,
I will try to reproduce and fix the problem.
Best regards,
Frank
Brice Fines wrote:
> 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]>
> _______________________________________________
> SNMP4J mailing list
> SNMP4J at agentpp.org
> http://lists.agentpp.org/mailman/listinfo/snmp4j
--
AGENT++
http://www.agentpp.com
http://www.snmp4j.com
http://www.mibexplorer.com
http://www.mibdesigner.com
More information about the SNMP4J
mailing list