[Home]

Summary:ASTERISK-13474: The status of a local channel in state_interface of a queue is wrong the first time is added and lost after a reload
Reporter:Francesco Romano (francesco_r)Labels:
Date Opened:2009-01-29 04:20:53.000-0600Date Closed:2009-03-31 14:40:28
Priority:BlockerRegression?No
Status:Closed/CompleteComponents:Applications/app_queue
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 14359.patch
( 1) console_debug.log
( 2) console.txt
Description:I use the new feature of stateinterface parameter to monitor the status of a real device when used with local channel as member. So for example if i add to queues.conf a static member:
member=Local/2503@from-internal/n,0,,SIP/2503
whit queue show i have:
Local/2503@from-internal/n (Not in use) has taken no calls yet

But this is wrong because this member is not registered and unavailable. Infact if i convert the member to SIP/2503 the status become correctly:
SIP/2503 (Unavailable) has taken no calls yet

Other problem: if 2503 use the phone with queue show i have correctly:
Local/2503@from-internal/n (In use) has taken no calls yet
But if in this exact moment i do a reload the status become newly:
Local/2503@from-internal/n (Not in use) has taken no calls yet
Comments:By: Mark Michelson (mmichelson) 2009-01-30 10:29:05.000-0600

Hi, thanks for the report. It sounds like there are two separate issues. I haven't yet begun to investigate this or try to reproduce it locally, but I thought I'd at least make some comments about the issues.

The nice thing about this is that it should be relatively easy to reproduce the scenario, so I'll get to work and hopefully have a solution soon.
By: Mark Michelson (mmichelson) 2009-01-30 13:09:02.000-0600

Bad news. I could not reproduce either of these problems using 1.6.0.5 or the latest svn checkout of the 1.6.0 branch.

Regarding the first issue you reported, using a SIP channel directly or as the state interface for a local channel produced the same results for me. I looked in chan_sip.c and found that the condition under which it will report "unavailable" is if you have qualify set in sip.conf and the peer is determined to be unreachable through this means. In all my testing, it made no difference which method I used for specifying queue members. I'll describe the state changes I saw.

I set this test up by setting qualify=yes on one of my SIP peers and then unplugging the phone from the network and starting Asterisk. When Asterisk started up, I issued a queue show command and saw that my queue member was "not in use." Very soon after, I saw a notice that the SIP peer was unreachable. After that, issuing a queue show command showed the interface as "unavailable." Keep in mind what I said above. No matter whether I used a local channel with a SIP state interface or used a SIP channel directly, the results were the same.

Regarding the second issue you reported, I just plain could not reproduce it at all. All attempts at reloading while a queue member was "in use" did not change his status.

I'd like to fix these issues one-at-a-time, so let's concentrate first on the issue where the local channel with a state interface behaves differently than a SIP channel regarding the "not in use" and "unavailable" states. Since you listed the reproducibility as "always" I'm assuming that this occurs consistently. Does the problem "correct" itself after a period of time? I'm a bit at a loss here since I thought this would be easy to reproduce. Right now, I think it may help if you could upload the CLI output from when Asterisk starts up with debug and verbose levels set to at least 3. That way, I may be able to see where the device state errors are.
By: Francesco Romano (francesco_r) 2009-01-31 07:41:54.000-0600

I did other tests and if i start asterisk from zero the status is correct, you are right, BUT if you do a reload i lost the status of each member.
With SIP channel instead all status are correct. Also immediately after a reload.

In my test i did:
- defined in queues.conf three members
member=Local/101@from-internal/n,0,,SIP/101
member=Local/503@from-internal/n,0,,SIP/503
member=Local/509@from-internal/n,0,,SIP/509
(but only 509 is connected to the lan)
- started asterisk
- queue show (with correct states)
  Members:
     Local/503@from-internal/n (Invalid) has taken no calls yet
     Local/101@from-internal/n (Invalid) has taken no calls yet
     Local/509@from-internal/n (Not in use) has taken no calls yet
  No Callers
- 509 do echo test
- queue show (with correct states)
  Members:
     Local/503@from-internal/n (Invalid) has taken no calls yet
     Local/101@from-internal/n (Invalid) has taken no calls yet
     Local/509@from-internal/n (In use) has taken no calls yet
  No Callers
- reload
- queue show (with wrong states)
  Members:
     Local/503@from-internal/n (Not in use) has taken no calls yet
     Local/101@from-internal/n (Not in use) has taken no calls yet
     Local/509@from-internal/n (Not in use) has taken no calls yet
  No Callers

I waited 5 minutes but the states were never updated.
Attached a console output.
By: Mark Michelson (mmichelson) 2009-02-02 14:24:27.000-0600

In your setup, do the peer entries for SIP/101 and SIP/503 have qualify=yes set on them? That seems to be a key here. Everything else actually makes sense to me.

At startup, I can see that app_queue.so is loaded before chan_sip.so. When app_queue.so is loaded, it attempts to see what the device states of its members are, but it cannot since the channel driver is not loaded yet. As a result, all three queue members are in the "invalid" state.

Soon after chan_sip.so loads, I can see that Asterisk sends an OPTIONS packet to SIP/509, which SIP/509 responds to. Thus, there is a NOTICE message in the log showing that SIP/509 is reachable, followed shortly after by its change to "not in use" instead of "invalid."

When you reload, chan_sip.so is already loaded when app_queue attempts to re-check device state of its members. This time, chan_sip tells app_queue that SIP/101 and SIP/503 are both "not in use" because they're not being used and they have not failed a qualify check. If you turn on qualify for SIP/101 and SIP/503, I suspect that both would become "unavailable" after the next qualify attempt.
By: Francesco Romano (francesco_r) 2009-02-02 15:29:16.000-0600

Invalid is ok. The queue do not try to dial a member that have invalid state.
And all sip friends have already qualify=yes:
[101]
type=friend
secret=101
qualify=yes
port=5060
pickupgroup=
nat=no
mailbox=101@device
host=dynamic
dtmfmode=rfc2833
dial=SIP/101
context=from-internal
canreinvite=no
callgroup=
callerid=Int <101>
accountcode=

I repeat, when i put members as sip device (eg. member=SIP/101) all works well. Also immediately after a reload, i don't need to wait the qualify. Seems that the reload reset the state_interface.
By: Francesco Romano (francesco_r) 2009-02-02 16:26:32.000-0600

If you want i can give you access to this test machine and see yourself the problem. Another member of Digium (mattf) has already logged in to resolve other bugs related to libpri, so for me it's not a problem.
By: Mark Michelson (mmichelson) 2009-02-03 11:12:00.000-0600

Thanks I may require access to your machine, just so I can see all the configuration parameters. I have a feeling that there is some busted logic in app_queue somewhere, but it's not easy to find that incorrect logic when everything is working on my end. I'm going to take a few hours to look at this from my end some more, and if I don't find anything that seems incorrect, I'll get login information for your machine.
By: Mark Michelson (mmichelson) 2009-02-03 11:19:22.000-0600

I think I may have found the problem and it was a really silly mistake on my part. I'll upload a patch for you to test.
By: Mark Michelson (mmichelson) 2009-02-03 11:20:17.000-0600

I have uploaded 14359.patch for testing. Please let me know if this fixes the problem for you.
By: Francesco Romano (francesco_r) 2009-02-03 11:41:50.000-0600

Yes, problem fixed. The bug is also present in this backport http://reviewboard.digium.com/r/116/
Any chance it will be merged to 1.4?

Thank you
By: Mark Michelson (mmichelson) 2009-02-04 16:04:04.000-0600

I'll update the reviewboard request to have this fix, too. I would like to get it backported to 1.4 since it fixes problems that many were having. The problem is that I haven't received nearly as much constructive feedback as I would have liked. I have waited a while, so I don't think anyone would fault me if I merged that change in at this point though. I'll wait until just after the next stable 1.4 version is released before attempting that merge.
By: Mark Michelson (mmichelson) 2009-02-04 16:17:36.000-0600

btw, what I'm committing to close this issue fixes that one line but I also found a couple of other spots that had similar problems (although they are much less likely to come up in normal situations). I just thought I'd make sure you understood what was going on here.
By: Digium Subversion (svnbot) 2009-02-04 16:17:59.000-0600

Repository: asterisk
Revision: 173507

U   trunk/apps/app_queue.c

------------------------------------------------------------------------
r173507 | mmichelson | 2009-02-04 16:16:19 -0600 (Wed, 04 Feb 2009) | 7 lines

Fix some areas where the incorrect interface was passed to ast_device_state

I swear it feels like I already did this once...

(closes issue ASTERISK-13474)
Reported by: francesco_r

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=173507
By: Digium Subversion (svnbot) 2009-02-04 16:24:00.000-0600

Repository: asterisk
Revision: 173534

_U  branches/1.6.0/
U   branches/1.6.0/apps/app_queue.c

------------------------------------------------------------------------
r173534 | mmichelson | 2009-02-04 16:23:59 -0600 (Wed, 04 Feb 2009) | 15 lines

Merged revisions 173507 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
r173507 | mmichelson | 2009-02-04 16:16:19 -0600 (Wed, 04 Feb 2009) | 7 lines

Fix some areas where the incorrect interface was passed to ast_device_state

I swear it feels like I already did this once...

(closes issue ASTERISK-13474)
Reported by: francesco_r

........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=173534
By: Digium Subversion (svnbot) 2009-02-04 16:25:16.000-0600

Repository: asterisk
Revision: 173541

_U  branches/1.6.1/
U   branches/1.6.1/apps/app_queue.c

------------------------------------------------------------------------
r173541 | mmichelson | 2009-02-04 16:25:16 -0600 (Wed, 04 Feb 2009) | 15 lines

Merged revisions 173507 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
r173507 | mmichelson | 2009-02-04 16:16:19 -0600 (Wed, 04 Feb 2009) | 7 lines

Fix some areas where the incorrect interface was passed to ast_device_state

I swear it feels like I already did this once...

(closes issue ASTERISK-13474)
Reported by: francesco_r

........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=173541
By: Francesco Romano (francesco_r) 2009-03-30 12:15:44

I see that state_interface for app_queue was backported to 1.4 (ASTERISK-12295) but without the patch present in this report. So this bug is now present in 1.4SVN.

P.S.: is already some days that i can't go to http://svn.digium.com/view/ (404 not found), is the server moved to another url?
By: Mark Michelson (mmichelson) 2009-03-31 10:32:38

ViewVC has been disabled because of some severe performance issues beyond our control.

Thanks for pointing this out. I am just about to get this merged into 1.4.
By: Digium Subversion (svnbot) 2009-03-31 10:34:06

Repository: asterisk
Revision: 185298

U   branches/1.4/apps/app_queue.c

------------------------------------------------------------------------
r185298 | mmichelson | 2009-03-31 10:34:05 -0500 (Tue, 31 Mar 2009) | 10 lines

Fix some state_interface stuff that was in trunk but not in the backport to 1.4.

Issue ASTERISK-13474 was fixed between the time that I posted the review of the backport
of the state interface change for 1.4. This merges the changes from that issue
back into 1.4.

(closes issue ASTERISK-13474)
Reported by: francesco_r


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=185298
By: Digium Subversion (svnbot) 2009-03-31 10:34:29

Repository: asterisk
Revision: 185299

_U  trunk/

------------------------------------------------------------------------
r185299 | mmichelson | 2009-03-31 10:34:29 -0500 (Tue, 31 Mar 2009) | 15 lines

Blocked revisions 185298 via svnmerge

........
 r185298 | mmichelson | 2009-03-31 10:34:05 -0500 (Tue, 31 Mar 2009) | 10 lines
 
 Fix some state_interface stuff that was in trunk but not in the backport to 1.4.
 
 Issue ASTERISK-13474 was fixed between the time that I posted the review of the backport
 of the state interface change for 1.4. This merges the changes from that issue
 back into 1.4.
 
 (closes issue ASTERISK-13474)
 Reported by: francesco_r
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=185299
By: Digium Subversion (svnbot) 2009-03-31 10:35:35

Repository: asterisk
Revision: 185300

_U  branches/1.6.1/

------------------------------------------------------------------------
r185300 | mmichelson | 2009-03-31 10:35:35 -0500 (Tue, 31 Mar 2009) | 21 lines

Blocked revisions 185299 via svnmerge

................
 r185299 | mmichelson | 2009-03-31 10:34:29 -0500 (Tue, 31 Mar 2009) | 15 lines
 
 Blocked revisions 185298 via svnmerge
 
 ........
   r185298 | mmichelson | 2009-03-31 10:34:05 -0500 (Tue, 31 Mar 2009) | 10 lines
   
   Fix some state_interface stuff that was in trunk but not in the backport to 1.4.
   
   Issue ASTERISK-13474 was fixed between the time that I posted the review of the backport
   of the state interface change for 1.4. This merges the changes from that issue
   back into 1.4.
   
   (closes issue ASTERISK-13474)
   Reported by: francesco_r
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=185300
By: Digium Subversion (svnbot) 2009-03-31 14:39:52

Repository: asterisk
Revision: 185466

_U  branches/1.6.0/

------------------------------------------------------------------------
r185466 | mmichelson | 2009-03-31 14:39:52 -0500 (Tue, 31 Mar 2009) | 21 lines

Blocked revisions 185299 via svnmerge

................
 r185299 | mmichelson | 2009-03-31 10:34:29 -0500 (Tue, 31 Mar 2009) | 15 lines
 
 Blocked revisions 185298 via svnmerge
 
 ........
   r185298 | mmichelson | 2009-03-31 10:34:05 -0500 (Tue, 31 Mar 2009) | 10 lines
   
   Fix some state_interface stuff that was in trunk but not in the backport to 1.4.
   
   Issue ASTERISK-13474 was fixed between the time that I posted the review of the backport
   of the state interface change for 1.4. This merges the changes from that issue
   back into 1.4.
   
   (closes issue ASTERISK-13474)
   Reported by: francesco_r
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=185466
By: Digium Subversion (svnbot) 2009-03-31 14:40:27

Repository: asterisk
Revision: 185467

_U  branches/1.6.2/

------------------------------------------------------------------------
r185467 | mmichelson | 2009-03-31 14:40:27 -0500 (Tue, 31 Mar 2009) | 21 lines

Blocked revisions 185299 via svnmerge

................
 r185299 | mmichelson | 2009-03-31 10:34:29 -0500 (Tue, 31 Mar 2009) | 15 lines
 
 Blocked revisions 185298 via svnmerge
 
 ........
   r185298 | mmichelson | 2009-03-31 10:34:05 -0500 (Tue, 31 Mar 2009) | 10 lines
   
   Fix some state_interface stuff that was in trunk but not in the backport to 1.4.
   
   Issue ASTERISK-13474 was fixed between the time that I posted the review of the backport
   of the state interface change for 1.4. This merges the changes from that issue
   back into 1.4.
   
   (closes issue ASTERISK-13474)
   Reported by: francesco_r
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=185467