[SNMP4J] IllegalStateException in Snmp.send()

[Frank Fock]

Hello Alberto,

Thanks for trying it out! There is another synchronization
needed to ensure the correct order of timer task states.

Please replace also the cancel method in the Snmp class
by the following code:

   public void cancel(PDU request, ResponseListener listener) {
     AsyncRequestKey key = new AsyncRequestKey(request, listener);
     PduHandle pending = (PduHandle) asyncRequests.remove(key);
     logger.debug("Canceling pending request with handle " + pending);
     if (pending != null) {
       PendingRequest pendingRequest =
           (PendingRequest) pendingRequests.remove(pending);
       if (pendingRequest != null) {
         pendingRequest.setFinished();
         synchronized (sync) {
           pendingRequest.cancel();
         }
       }
     }
   }

Best regards,
Frank

Alberto wrote:
> Hello Frank,
> 
> after running your snmp4j patched lib for the whole weekend, this morning we 
> got again the "Task already scheduled or canceled" problem.
> This time it seems related to an asynchronous request.
> Below some log4j traces:
> 
> 18/12/2006 08:32:58:829 DEBUG [Timer-6] [Log4jLogAdapter.debug] New pending 
> async request with handle PduHandle[1136328694]
> ...
> 18/12/2006 08:33:00:845 DEBUG [Timer-7] [Log4jLogAdapter.debug] Running 
> pending request (3 left) with handle: PduHandle[1136328694]
> ...
> 18/12/2006 08:33:00:945 DEBUG [SNMPDriverDispatchPool.1] [Log4jLogAdapter.
> debug] Looking up pending request with handle PduHandle[1136328694]
> ...
> 18/12/2006 08:33:00:946 DEBUG [SNMPDriverDispatchPool.1] [Log4jLogAdapter.
> debug] Canceling pending request with handle PduHandle[1136328694]
> ...
> 18/12/2006 08:33:00:948 ERROR [Timer-7] [Log4jLogAdapter.error] Failed to 
> process pending request PduHandle[1136328694] because Task already scheduled or 
> cancelled
> java.lang.IllegalStateException: Task already scheduled or cancelled
>         at java.util.Timer.sched(Timer.java:358)
>         at java.util.Timer.schedule(Timer.java:170)
>         at org.snmp4j.Snmp$PendingRequest.run(Snmp.java:1434)
>         at java.util.TimerThread.mainLoop(Timer.java:512)
>         at java.util.TimerThread.run(Timer.java:462)
> ...
> 
> From that moment on, thread Timer-7 is gone.
> Moreover, the number of running threads in my server application has increased 
> a lot and many threads are somehow blocked on snmp send request.
> Example:
> 
> Thread t at 1194749: (state = BLOCKED)
>  - java.lang.Object.wait(long) @bci=0 (Compiled frame; information may be 
> imprecise)
>  - java.lang.Object.wait() @bci=2, line=474 (Compiled frame)
>  - org.snmp4j.Snmp.send(org.snmp4j.PDU, org.snmp4j.Target) @bci=4, line=758 
> (Interpreted frame)
>  - com.tilab.common.device.snmp.SNMPV2Driver.executeRequest(org.snmp4j.PDU) 
> @bci=15, line=670 (Interpreted frame)
>  - com.tilab.common.device.snmp.SNMPV2Driver.read(org.snmp4j.PDU) @bci=2, 
> line=614 (Compiled frame)
>  - com.tilab.common.device.snmp.SNMPV2Driver.executeGetRequest(java.lang.
> String) @bci=26, line=231 (Compiled frame)
>  - com.tilab.common.device.snmp.SNMPV2Adapter.readOidValues(java.lang.String
> [], com.tilab.emmas.device.Device, java.lang.Stri
> ng) @bci=4, line=512 (Compiled frame)
>  - com.tilab.common.device.snmp.SNMPV2Adapter.loadObjectValues(com.tilab.emmas.
> mibmodel.MibObject, java.lang.String[]) @bci=2
> 3, line=366 (Compiled frame)
>  - com.tilab.common.device.snmp.SNMPV2Adapter.loadObject(java.lang.Class, com.
> tilab.emmas.device.Device, java.lang.String, ja
> va.lang.String[]) @bci=35, line=289 (Compiled frame)
>  - com.tilab.emmas.device.Device.load(java.lang.Class, com.tilab.common.device.
> IMibAdapter, java.lang.String, java.lang.Strin
> g[]) @bci=6, line=327 (Compiled frame)
>  - com.tilab.emmas.scheduler.performance.PmCollectionTask.call() @bci=26, 
> line=47 (Compiled frame)
>  - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=28, line=675 
> (Compiled frame)
>  - java.lang.Thread.run() @bci=11, line=595 (Compiled frame)
> 
> If you need additional traces or tests, feel free to ask.
> 
> Waiting for your help,
> Alberto
> 
> 
>> ----Messaggio originale----
>> Dal: fock at agentpp.com
>> Data: 15/12/2006 1.56
>> A: "Alberto"<alberto_mascheroni at fastwebnet.it>
>> Cc: <snmp4j at agentpp.org>
>> Ogg: Re: R: Re: [SNMP4J] IllegalStateException in Snmp.send()
>>
>> Hi Alberto,
>>
>> According to your and the others' information I have
>> revisited the current synchronous Snmp.send(..) code
>> and found a possible cause of the exception.
>>
>> Please try out the following modification of the
>> synchronous send method. The difference is the
>> additional "synchronized" block with the comment:
>>
>>   public ResponseEvent send(PDU pdu, Target target,
>>                             TransportMapping transport) throws 
>> IOException {
>>
>> ...
>>
>>         if (retryRequest != null) {
>>           retryRequest.setFinished();
>>           // We need to synchronize here to make sure that the retryRequest
>>           // is already scheduled when we cancel it. Otherwise it might be
>>           // canceled before being scheduled which results in an
>>           // IllegalStateException being thrown in the retry handler.
>>           synchronized (sync) {
>>             retryRequest.cancel();
>>           }
>>         }
>> ...
>>   }
>>
>> Is my assumption correct that you are using synchronous
>> requests?
>>
>> Best regards,
>> Frank
> 
> 
> --------------------
> Alberto Mascheroni
> Mob. +39-333-6314222

-- 
AGENT++
http://www.agentpp.com
http://www.mibexplorer.com
http://www.mibdesigner.com