[SNMP4J] SNMP over TCP socket timeout

Fri Jul 10 06:57:39 CEST 2009

Thanks Frank for your reply.

But socket timeout causes connection to close which trigger SNMP request
time out. I have already tried setConnectionTimeout method to increase
timeout period but it did not work. For your information I want to tell you
that I am querying an agent lying behind NAT at a remote site. For small
number of variable bindings (about 70) it works fine but over that it just
shows socket time out in log and at manager side SNMP request timeout occur.

what could be the possible reasons ??

thanks

with kind regards

lalit

On Fri, Jul 10, 2009 at 3:21 AM, Frank Fock <fock at agentpp.com> wrote:

> Hi,
>
> The timeout does not cause any problem other
> than a log output, right?
>
> If you want to change it, use:
>
> http://www.snmp4j.org/doc/org/snmp4j/transport/DefaultTcpTransportMapping.html#setConnectionTimeout(long)<http://www.snmp4j.org/doc/org/snmp4j/transport/DefaultTcpTransportMapping.html#setConnectionTimeout%28long%29>
>
> Best regards,
> Frank
>
>
> lalit patel wrote:
>
>> Hi all
>>
>> I am facing socket timout problem in SNMP over TCP. Log shows the
>> following
>> messages.....................
>>
>> 667672 [RequestPool.0] DEBUG
>> org.snmp4j.transport.DefaultTcpTransportMapping  - Looking up connection
>> for
>> destination '172.16.21.201/52303' returned: SocketEntry[peerAddress=
>>
>> 172.16.21.201/52303,socket=Socket[addr=/172.16.21.201,port=52303,localport=3333],lastUse=MonJul<http://172.16.21.201/52303,socket=Socket%5Baddr=/172.16.21.201,port=52303,localport=3333%5D,lastUse=MonJul>
>> 06 16:47:58 IST 2009]
>> 667672 [RequestPool.0] DEBUG
>> org.snmp4j.transport.DefaultTcpTransportMapping  - {
>>
>> 172.16.21.201/52302=SocketEntry[peerAddress=172.16.21.201/52302,socket=Socket[unconnected],lastUse=MonJul<http://172.16.21.201/52302=SocketEntry%5BpeerAddress=172.16.21.201/52302,socket=Socket%5Bunconnected%5D,lastUse=MonJul>
>> 06 16:47:39 IST 2009],
>>
>> 172.16.21.201/52303=SocketEntry[peerAddress=172.16.21.201/52303,socket=Socket[addr=/172.16.21.201,port=52303,localport=3333],lastUse=MonJul<http://172.16.21.201/52303=SocketEntry%5BpeerAddress=172.16.21.201/52303,socket=Socket%5Baddr=/172.16.21.201,port=52303,localport=3333%5D,lastUse=MonJul>
>> 06 16:47:58 IST 2009]}
>> 667672 [DefaultTCPTransportMapping_172.16.5.35/3333] DEBUG
>> org.snmp4j.transport.DefaultTcpTransportMapping  - Send message with
>> length
>> 1662 to 172.16.21.201/52303:
>>
>> 30:82:06:7a:02:01:03:30:11:02:04:06:32:7e:fa:02:03:00:ff:ff:04:01:03:02:01:03:04:36:30:34:04:0a:80:00:13:70:04:4c:41:4c:49:54:02:02:01:24:02:02:02:9b:04:06:4d:44:35:44:45:53:04:0c:ad:37:1a:62:0a:5a:80:8c:24:ed:43:cd:04:08:00:00:01:24:ff:b4:c8:75:04:82:06:28:7f:85:3a:1f:7d:9c:fb:6c:12:b6:8b:ea:7c:c3:41:0c:57:ef:46:ed:48:1f:8d:c5:eb:9b:8c:79:e9:d1:b4:a2:b5:3d:36:60:41:c4:57:02:da:58:3c:c7:00:c2:52:5a:64:62:64:07:70:40:67:c8:62:f5:90:cb:a8:f8:7a:db:d6:cc:6e:53:30:5a:78:7d:ad:61:04:ff:cd:3d:5b:e1:16:b5:65:b7:f6:8e:33:16:ea:80:f0:ef:f1:72:45:3e:89:f5:32:9b:42:98:72:64:be:95:6c:85:d1:13:f5:7d:11:fd:8a:2d:9b:49:ea:0f:bd:ad:45:03:a7:0a:1e:87:0f:53:e3:b0:16:d9:1f:fc:36:7b:de:be:c1:a2:f6:be:77:27:4c:9b:3a:a5:54:7c:a3:55:41:93:fb:58:47:0c:05:68:88:b2:8b:50:91:c4:0c:72:6b:df:f7:71:b3:34:21:d2:a0:60:d4:07:1e:d1:95:d9:28:da:19:cf:7c:73:70:11:83:13:69:91:f9:4e:41:ec:94:2b:6e:2b:dd:79:78:76:91:49:cf:e5:c3:fb:3d:1c:26:48:0c:22:2a:6d:90:8d:88:61:ba:a6:2a:d3:af:30:6f:94:a7:c2:0a:8a:12:0e:40:
>>
>
> d5:d3:d0:0f:7f:22:c9:2f:c1:a6:2d:fe:53:6b:3a:ae:be:ca:52:aa:d3:3d:7f:68:f4:35:36:cb:72:ea:7a:c6:96:8a:4b:cd:c2:ee:d5:97:d5:b5:ec:75:62:10:58:4d:39:88:e9:86:02:22:c7:b1:69:4a:ab:1c:50:53:6b:06:a1:b7:5d:69:b3:00:5a:7d:6a:5e:9b:0b:87:5e:44:e3:fb:7d:18:d0:7b:1e:f5:52:76:43:36:8a:b7:6a:e1:33:4c:fb:a4:65:4c:86:ce:34:a8:d6:70:f2:c1:30:78:fc:55:32:7c:6a:18:4d:62:95:49:ed:a0:d3:1e:ec:2f:fb:c0:3a:9d:c4:fe:a7:8a:a6:d7:35:df:52:76:30:02:9f:d9:f6:a5:45:74:15:34:8b:e1:c4:0a:d4:e1:cb:31:25:8c:e8:73:9e:48:77:d1:18:2e:3f:ac:23:ed:63:42:fc:0b:ff:6d:4a:c0:a3:04:86:67:61:6b:07:d8:19:f4:69:55:29:aa:fb:52:6e:f2:b5:7e:85:cd:8e:f2:85:4a:78:9b:f3:49:b9:6f:6a:be:36:bb:6f:63:c6:60:b4:48:f4:c3:e0:40:97:10:1b:f9:5a:73:15:07:75:55:8c:b7:5b:e7:4e:78:5d:9d:54:de:a6:92:1f:f5:88:6e:c1:ed:43:48:f1:a6:c6:8f:a1:c1:16:13:46:0c:15:25:61:9f:63:72:2e:39:92:34:f0:d3:e5:59:2a:b3:9b:4a:5e:61:2d:05:3c:b4:4c:74:2e:49:87:1b:42:e7:be:a4:f2:f9:b9:f3:80:28:75:01:61:e9:d6:c1:e7:84:c1:cf:79:c0:e4:2a:65:a1:25:40:06:cc:a8:9f:56:
>
> 77:76:51:79:07:ea:f5:69:fa:33:d3:a1:1d:45:66:13:03:80:32:3e:e4:22:0f:34:54:78:a6:ab:6c:5d:99:a0:d4:66:28:85:76:39:a0:4e:d7:ff:84:39:09:a3:23:f5:24:2f:ac:b1:ee:3d:37:af:85:4b:62:91:f3:2d:64:ee:05:aa:61:2a:53:a7:95:f4:0b:a6:00:84:b9:72:22:01:8c:d7:b5:36:46:c9:3f:2d:15:cf:eb:03:52:66:a9:41:5b:7f:39:b9:60:7b:be:b5:b5:bc:1d:3a:c3:70:67:cc:4a:86:7c:36:26:5e:0d:3a:4d:1d:5c:33:fd:77:e6:ec:81:95:41:d9:b7:b7:8e:b4:ed:25:f4:18:61:33:79:43:88:43:68:42:72:9f:f6:21:fa:35:2e:da:de:18:06:ce:b8:72:fe:55:c6:71:18:e8:8b:c3:5c:aa:a0:13:c1:cf:ee:67:c3:4d:68:a3:04:bd:af:4f:75:c4:20:b7:5f:79:73:bd:33:1d:d0:2f:bc:d2:90:a5:3c:28:0c:00:68:7a:b3:d6:b2:c6:66:89:1d:14:ed:f4:1d:7a:9a:51:47:04:7c:5b:af:85:c2:ef:08:19:a7:0e:5e:3c:34:03:10:6f:f1:0f:89:d8:a2:d3:71:08:c7:4c:ed:b2:64:eb:9a:e6:1d:56:1a:0c:68:3d:ac:52:45:5d:c2:fd:31:58:1e:09:54:bb:ed:52:50:2e:6c:50:8c:e9:f0:3d:e7:26:25:ff:ef:5b:8c:0a:ae:65:e5:62:f3:f6:a9:db:0b:1e:bf:df:1d:d1:d0:20:1f:ec:20:80:f1:59:1b:37:c6:4f:46:d9:e2:f5:21:c8:d9:0f:4c:6a:8b:a0:
>
> bd:69:81:c0:bd:ff:e9:af:1d:ef:5a:12:41:d4:b5:e9:c8:d1:9d:3c:8f:60:39:34:23:f1:de:fe:de:b3:e0:9a:6e:19:77:cb:95:ad:e7:eb:ce:2e:16:d1:17:49:71:76:e7:16:84:00:a3:7a:99:ed:36:a8:34:c4:b3:2c:e9:39:7f:8c:1a:31:4f:93:9b:2e:88:94:ca:d6:46:33:f3:35:2c:cc:ac:b8:32:2f:95:ea:1d:27:76:d4:86:78:0d:b2:85:ed:77:47:e0:59:c9:49:d2:a3:f8:5f:b5:86:2a:e9:5d:ac:fb:9f:3d:43:04:36:70:f4:96:d1:a7:c1:c9:55:7a:f6:76:96:92:0a:98:28:04:23:3b:6a:60:b6:80:5f:65:fe:91:62:ba:c7:c3:36:38:3b:45:9d:0a:d8:40:27:b1:a8:c1:6d:f3:4b:a0:e5:bf:ce:14:b7:3c:6b:15:9f:bc:5c:6e:2a:16:60:25:e1:2c:b5:6e:8f:17:f9:32:ff:6e:b3:38:81:d2:eb:1d:aa:26:cd:c3:15:16:32:84:22:f8:7a:c7:8c:10:b4:f3:95:87:ca:ae:a9:d3:30:2d:92:2d:c0:ad:40:f0:2e:a7:e2:3a:00:f9:b5:48:88:cc:02:9d:89:95:85:a2:2f:2e:f9:9b:4a:49:7f:97:ce:f3:d7:08:82:79:5b:cf:ac:68:53:8f:b1:5a:c9:d0:2e:21:95:93:85:71:af:df:f9:73:28:f0:39:2a:9f:2a:b2:b2:fa:29:40:cd:0a:8f:9f:19:19:4f:85:c6:21:c2:df:a5:99:f8:d5:d2:f7:9c:80:c4:37:e3:78:56:02:6d:66:d3:ea:38:6b:8f:0b:80:17:26:8d:18:14:
>
> 41:fa:de:48:3c:31:77:5d:d5:8b:49:3d:c5:2d:5b:e9:b8:38:e9:df:1a:b8:f2:fd:e4:86:2b:cf:5f:13:30:bc:8a:d4:9e:98:b0:e5:27:fc:79:65:19:75:5e:26:2a:68:ff:04:9c:cf:ce:ef:56:e2:63:69:89:87:36:fb:a2:83:2a:2f:55:2c:71:2e:23:70:51:05:f3:14:04:cd:30:15:7c:c1:18:e7:62:ac:40:c3:98:85:9f:1f:4d:71:1d:14:57:31:63:57:91:7e:62:1c:d8:aa:e4:ea:ad:47:7c:3c:02:24:b4:4f:97:e5:b9:4f:9e:04:a8:2d:8e:c9:5d:3f:7e:e8:98:c7:df:20:61:ea:8f:90:7c:74:b1:39:75:19:cc:70:94:af:bd:57:f8:65:e9:a0:89:a8:68:df:95:33:75:7a:e9:ec:0a:55:7f:b5:28:fc:80:b2:d9:bb:e3:3f:27:97:8a:93:6f:c8:09:2c:ae:f3:af:22:2d:f8:90:f2:a1:48:52:a1:6f:a3:bf:45:a4:3d:07:db:3f:7f:ea:97:f3:62:19:87:d5:2a:a8:ad:38:42:86:12:92:b1:68:20:b6:8d:30:03:dc:01:77:41:49:6c:2a:72:82:6e:0c:3c:28:1d:40:2f:c2:99:24:70:8e:a9:ca:00:d7:bf:05:5d:d7:66:fe:77:5b:90:57:e1:df:66:3e:dd:6f:80:a8:e6:79:7d:9d:ff:28:8a:29:87:21:2c:5b:8d:43:8b:63:12:81:73:d5:be:27:66:3b:d2:fa:f1:b8:51:e7:4e:47:ca:b0:b0:6f:5d:8c:5d:98:97:04:55:ce:61:b5:d3:03:01:45:5c:2a:16:85:58:ba:18:15:ec:
> 18:60:d7:00:f0:8d:e7:64:8b:b3:25:9f:8d
>
>> 707109 [Timer-1] DEBUG org.snmp4j.transport.DefaultTcpTransportMapping  -
>> Scheduling 813
>> 707937 [Timer-1] DEBUG org.snmp4j.transport.DefaultTcpTransportMapping  -
>> Socket has not been used for 60015 micro seconds, closing it
>> 707937 [Timer-1] INFO org.snmp4j.transport.DefaultTcpTransportMapping  -
>> Socket to 172.16.21.201/52302 closed due to timeout
>> 717094 [DefaultTCPTransportMapping_172.16.5.35/3333] DEBUG
>> org.snmp4j.transport.DefaultTcpTransportMapping  - Reading header -1 bytes
>> from 172.16.21.201/52303
>> 717094 [DefaultTCPTransportMapping_172.16.5.35/3333] DEBUG
>> org.snmp4j.transport.DefaultTcpTransportMapping  - Socket closed remotely
>> 717094 [DefaultTCPTransportMapping_172.16.5.35/3333] DEBUG
>> org.snmp4j.transport.TcpTransportMapping  - Firing transport state event:
>>
>> org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 16b13c7
>> ,peerAddress=
>> 172.16.21.201/52303,newState=2,cancelled=false,causingException=null]
>> 727109 [Timer-1] DEBUG org.snmp4j.transport.DefaultTcpTransportMapping  -
>> Scheduling 49985
>> 717094 [DefaultTCPTransportMapping_172.16.5.35/3333] DEBUG
>> org.snmp4j.transport.TcpTransportMapping  - Firing transport state event:
>>
>> org.snmp4j.transport.TransportStateEvent[source=org.snmp4j.transport.DefaultTcpTransportMapping at 16b13c7
>> ,peerAddress=
>> 172.16.21.201/52303,newState=2,cancelled=false,causingException=null]
>> 727109 [Timer-1] DEBUG org.snmp4j.transport.DefaultTcpTransportMapping  -
>> Scheduling 49985 777094 [Timer-1] DEBUG
>> org.snmp4j.transport.DefaultTcpTransportMapping  - Socket has not been
>> used
>> for 60000 micro seconds, closing it
>> 777094 [Timer-1] INFO org.snmp4j.transport.DefaultTcpTransportMapping  -
>> Socket to 172.16.21.201/52303 closed due to timeout
>>
>>
>>
>>
>> Is my guess that small socket timeout period is the cause of problem is
>> right ?
>> I think 60000 microsecond socket idle timeout is very small. How can I
>> increase this value ?
>>
>> any suggestion ??
>>
>>
>> thanks in advance
>>
>> Lalit Patel
>> _______________________________________________
>> 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
>
>