Summary:ASTERISK-15546: Setvar DEVICE_STATE manager action occasionally ignored.
Reporter:Matt King, M.A. Oxon. (kebl0155)Labels:
Date Opened:2010-01-29 11:07:02.000-0600Date Closed:2010-02-22 15:04:13.000-0600
Versions:Frequency of
Description:We use Manager to control DEVICE_STATE information to support ringinuse=no for local channels.

Though acknowledged by asterisk, commands to set to NOT_INUSE are sometimes ignored, which then stops further calls being routed to the agent.

This is an intermittent fault, affecting perhaps one in

We have seen this in Asterisk and


First we log in an agent using QueueAdd:

INFO 29/01/10 11:51:20 ManagerClient.send:
Action: QueueAdd
Queue: CustServ
Interface: Local/0015@agentdial
MemberName: Local/0015@agentdial
StateInterface: Custom:Local/0015@agentdial

Response: Success
Message: Added interface to queue

Then, when an agent answers the call, we use Manager to set the DEVICE_STATE as in use:

INFO 29/01/10 13:43:38 ManagerClient.send:
Action: Setvar
Variable: DEVICE_STATE(Custom:Local/0015@agentdial)
Value: INUSE

Response: Success
Message: Variable Set

The queue system then stops sending calls to the agent, and the agent is shown as In Use in 'queue show' (hooray!).

At the end of the call we send a complementary event to indicate the agent is free:

Action: Setvar
Variable: DEVICE_STATE(Custom:Local/0015@agentdial)

Response: Success
Message: Variable Set

This seems to work because the Queue system places one more call to the agent:

INFO 29/01/10 13:53:01
Event: AgentCalled
Privilege: agent,all
Queue: CustServ
AgentCalled: Local/0015@agentdial
AgentName: Local/0015@agentdial
ChannelCalling: Local/6276@incoming-8960;2
DestinationChannel: Local/0015@agentdial-6be7;1
CallerIDNum: unknown
CallerIDName: null
Context: custserv
Extension: dial
Priority: 2
Uniqueid: 1264773182.11921

In this case the agent does not answer the call.  The queue system should then place further calls to the agent, but no further calls are placed.  Running the 'queue show' command indicates that Asterisk still thinks the agent is in use:

CustServ has 1 calls (max unlimited) in 'ringall' strategy (109s holdtime, 0s talktime), W:0, C:12, A:2, SL:0.0% within 0s
     Local/0015@agentdial (dynamic) (In use) has taken no calls yet

The DEVICE_STATE for this member can only be set through Manager, and no further actions have been sent since the NOT_INUSE action, so this action must have been ignored.
Comments:By: David Vossel (dvossel) 2010-01-29 11:38:06.000-0600

This looks similar to this issue  (issue ASTERISK-15337)

Can you provide any steps to reproduce this?

By: David Vossel (dvossel) 2010-01-29 11:42:33.000-0600

Would you be able to update to the latests 1.6.2 svn code, or apply the patch in this issue (issue ASTERISK-15431).  That fix may be related to this and it is not yet in a release.

By: Matt King, M.A. Oxon. (kebl0155) 2010-01-29 11:56:10.000-0600

Hi Dvossel,

I'm sorry, this is an intermittent fault.  I haven't been able to spot any pattern as to when this happens.

We can't run the latest or 1.6.2 svn due to https://issues.asterisk.org/view.php?id=16729 - in fact I will have to downgrade this customer to this evening.

I will try the patch on Tuesday though.

Thanks for the swift response!

By: Matt King, M.A. Oxon. (kebl0155) 2010-01-29 11:56:46.000-0600

Oh and we've never seen the status as UNAVAILABLE (which seems to be symptomatic of 0016468) so I'm not sure if this is the same or not.

By: Leif Madsen (lmadsen) 2010-02-01 10:23:10.000-0600

OK, we'll need to leave this issue at a feedback status until additional information can be applied by the reporter, or that they can apply a patch per dvossel to determine if that will resolve the issue.

Without an ability to reproduce the issue, or additional information, there is likely little a developer will be able to do to move this forward.

By: Matt King, M.A. Oxon. (kebl0155) 2010-02-05 06:06:46.000-0600

OK the patch from 0016607 does seem to have fixed it in  I am trying today, which is the most recent version we can run.

I have noticed that it is sometimes sending two dial attempts at once though:

<previous dial times out>
   -- Nobody picked up in 10000 ms
   -- Hungup 'DAHDI/11-1'
 == Spawn extension (agentdial, 0007, 2) exited non-zero on 'Local/0007@agentdial-3870;2'

<new dial launched>
   -- Called Local/0007@agentdial
   -- Executing [0007@agentdial:1] Set("Local/0007@agentdial-e3a2;2", "__TRANSFER_CONTEXT=transfer") in new stack
   -- Executing [0007@agentdial:2] Dial("Local/0007@agentdial-e3a2;2", "DAHDI/r2/0007,,tTro") in new stack
   -- Requested transfer capability: 0x00 - SPEECH
   -- Called r2/0007
   -- Local/0007@agentdial-e3a2;1 is ringing

<then this happens straight away - it doesn't actually time out>
   -- Nobody picked up in 10000 ms
   -- Hungup 'DAHDI/12-1'
 == Spawn extension (agentdial, 0007, 2) exited non-zero on 'Local/0007@agentdial-7f1d;2'

<again this is happening straight away - it doesn't actually time out>
   -- Nobody picked up in 10000 ms
   -- Hungup 'DAHDI/13-1'
 == Spawn extension (agentdial, 0007, 2) exited non-zero on 'Local/0007@agentdial-5412;2'
   -- DAHDI/14-1 is proceeding passing it to Local/0007@agentdial-e3a2;2
   -- DAHDI/14-1 is ringing
   -- Local/0007@agentdial-e3a2;1 is ringing
   -- Executing [0007@agentdial:1] Set("Local/0007@agentdial-181a;2", "__TRANSFER_CONTEXT=transfer") in new stack
   -- Executing [0007@agentdial:2] Dial("Local/0007@agentdial-181a;2", "DAHDI/r2/0007,,tTro") in new stack
   -- Requested transfer capability: 0x00 - SPEECH
   -- Called Local/0007@agentdial
   -- Called r2/0007
   -- Local/0007@agentdial-181a;1 is ringing
   -- Executing [0007@agentdial:1] Set("Local/0007@agentdial-bf0a;2", "__TRANSFER_CONTEXT=transfer") in new stack
   -- Called Local/0007@agentdial
   -- Executing [0007@agentdial:2] Dial("Local/0007@agentdial-bf0a;2", "DAHDI/r2/0007,,tTro") in new stack

It looks like there's something broken with the timeout parameter.

By: Matt King, M.A. Oxon. (kebl0155) 2010-02-16 05:31:00.000-0600

...it looks like the problem with timeout was actually due to bug number 16834.

By: Leif Madsen (lmadsen) 2010-02-22 15:04:12.000-0600

OK, based on the feedback here, this looks to be resolved by 16607. You'll need to follow issue 16834 for the other issue you're experiencing which has been assigned to a developer.