[asterisk-bugs] [JIRA] (ASTERISK-16115) [patch] problem with ringinuse=no, queue members receive sometimes two calls

Tue Dec 4 05:23:45 CST 2012

    [ https://issues.asterisk.org/jira/browse/ASTERISK-16115?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=200371#comment-200371 ] 

Mikhail Lundberg edited comment on ASTERISK-16115 at 12/4/12 5:21 AM:
----------------------------------------------------------------------

Tested with clean rebuild and seen no creshes, so i'm sorry for the last comment, information about crash it not true.

Today I made some tests with latest 11.1.0_rc1 from SVN patched with app_queue.c-svn-r375015 using method with many .call files and still having multiply calls from queue.

{code}
>cat debug |grep -v pbx.c |grep 33099
[2012-12-04 12:49:20] DEBUG[32420][C-0000012c] app_queue.c: Trying 'SIP/33099' with metric 1000
[2012-12-04 12:49:20] DEBUG[32420][C-0000012c] app_queue.c: Locked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32420][C-0000012c] chan_sip.c: Outgoing Call for 33099
[2012-12-04 12:49:20] DEBUG[31211] chan_sip.c: Checking device state for peer 33099
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: Changing state for SIP/33099 - state 6 (Ringing)
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: device 'SIP/33099' state '6'
[2012-12-04 12:49:20] DEBUG[32420][C-0000012c] app_queue.c: Unlocked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32421][C-0000012d] app_queue.c: Trying 'SIP/33099' with metric 1000
[2012-12-04 12:49:20] DEBUG[32421][C-0000012d] app_queue.c: Locked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32421][C-0000012d] chan_sip.c: Outgoing Call for 33099
[2012-12-04 12:49:20] DEBUG[31211] chan_sip.c: Checking device state for peer 33099
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: Changing state for SIP/33099 - state 6 (Ringing)
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: device 'SIP/33099' state '6'
[2012-12-04 12:49:20] DEBUG[32421][C-0000012d] app_queue.c: Unlocked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32422][C-0000012e] app_queue.c: Trying 'SIP/33099' with metric 1000
[2012-12-04 12:49:20] DEBUG[32422][C-0000012e] app_queue.c: Locked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32422][C-0000012e] chan_sip.c: Outgoing Call for 33099
[2012-12-04 12:49:20] DEBUG[31211] chan_sip.c: Checking device state for peer 33099
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: Changing state for SIP/33099 - state 6 (Ringing)
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: device 'SIP/33099' state '6'
{code}

I see Locks and then Unlocks here in seprate threads?

In sip.conf for 33099:
{code}
callconter=yes
busylevel=1
call-limit=3
{code}

In queue.conf:
{code}
autofill=yes
[3333](StandardQueue)
weight=90
strategy = rrmemory
servicelevel = 60
timeout = 15
retry = 3
wrapuptime=30
autopause=no
ringinuse=no
{code}

      was (Author: mvlbrn):
    Tested with clean rebuild and seen no creshes, so i'm sorry for the last comment, information about crach it not true.

Today I made some tests with latest 11.1.0_rc1 from SVN patched with app_queue.c-svn-r375015 using method with many .call files and still having multiply calls from queue.

{code}
>cat debug |grep -v pbx.c |grep 33099
[2012-12-04 12:49:20] DEBUG[32420][C-0000012c] app_queue.c: Trying 'SIP/33099' with metric 1000
[2012-12-04 12:49:20] DEBUG[32420][C-0000012c] app_queue.c: Locked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32420][C-0000012c] chan_sip.c: Outgoing Call for 33099
[2012-12-04 12:49:20] DEBUG[31211] chan_sip.c: Checking device state for peer 33099
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: Changing state for SIP/33099 - state 6 (Ringing)
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: device 'SIP/33099' state '6'
[2012-12-04 12:49:20] DEBUG[32420][C-0000012c] app_queue.c: Unlocked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32421][C-0000012d] app_queue.c: Trying 'SIP/33099' with metric 1000
[2012-12-04 12:49:20] DEBUG[32421][C-0000012d] app_queue.c: Locked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32421][C-0000012d] chan_sip.c: Outgoing Call for 33099
[2012-12-04 12:49:20] DEBUG[31211] chan_sip.c: Checking device state for peer 33099
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: Changing state for SIP/33099 - state 6 (Ringing)
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: device 'SIP/33099' state '6'
[2012-12-04 12:49:20] DEBUG[32421][C-0000012d] app_queue.c: Unlocked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32422][C-0000012e] app_queue.c: Trying 'SIP/33099' with metric 1000
[2012-12-04 12:49:20] DEBUG[32422][C-0000012e] app_queue.c: Locked SIP/33099 in queue 3333
[2012-12-04 12:49:20] DEBUG[32422][C-0000012e] chan_sip.c: Outgoing Call for 33099
[2012-12-04 12:49:20] DEBUG[31211] chan_sip.c: Checking device state for peer 33099
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: Changing state for SIP/33099 - state 6 (Ringing)
[2012-12-04 12:49:20] DEBUG[31211] devicestate.c: device 'SIP/33099' state '6'
{code}

I see Locks and then Unlocks here in seprate threads?

In sip.conf for 33099:
{code}
callconter=yes
busylevel=1
call-limit=3
{code}

In queue.conf:
{code}
autofill=yes
[3333](StandardQueue)
weight=90
strategy = rrmemory
servicelevel = 60
timeout = 15
retry = 3
wrapuptime=30
autopause=no
ringinuse=no
{code}

> [patch] problem with ringinuse=no, queue members receive sometimes two calls
> ----------------------------------------------------------------------------
>
>                 Key: ASTERISK-16115
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-16115
>             Project: Asterisk
>          Issue Type: Bug
>          Components: Applications/app_queue
>            Reporter: nik600
>            Assignee: Bradley Watkins
>         Attachments: app_queue.c-1.6.2.10.patch, app_queue.c-svn-r368404.patch, app_queue.c-svn-r370418.patch, app_queue.c-svn-r375015.patch, debug_.txt
>
>
> Dear all
> on a debian amd64 i've installed (from source) asterisk 1.4.31
> On the system we have in average 50 concurrent calls in queue and 40
> sip members.
> I'm experiencing an apparently random problem:
> sometimes some users receive 2 calls from asterisk, apparently
> ignoring the ringinuse=no settings.
> It appears on users that are members of many queues
> As you can see from the log, the user goes in a status Ring+Inuse.
> Any idea?
> Why the call is still dispatched to the user if it is not in the "Not
> in use" status?
> i've added some customized log in the ring_entry function and this is the result:
> {noformat}
> [May 18 14:13:04] DEBUG[24945] app_queue.c: KUMBELOG: queue=queue_1        count=1,membercount=13,ringinuse=0,device=SIP/PL1009,status=1
> [May 18 14:13:04] DEBUG[24945] app_queue.c: Found matching member SIP/PL1009 in queue 'queue_2'
> [May 18 14:13:04] VERBOSE[24945] logger.c:     -- Called SIP/PL1009
> [May 18 14:13:05] VERBOSE[24945] logger.c:     -- SIP/PL1009-00001807 is ringing
> [May 18 14:13:06] DEBUG[25098] app_queue.c: KUMBELOG: queue=queue_2        count=2,membercount=15,ringinuse=0,device=SIP/PL1009,status=1
> [May 18 14:13:06] DEBUG[25098] app_queue.c: Found matching member SIP/PL1009 in queue 'queue_1'
> [May 18 14:13:06] DEBUG[25098] app_queue.c: Found matching member SIP/PL1009 in queue 'queue_3'
> [May 18 14:13:06] VERBOSE[25098] logger.c:     -- Called SIP/PL1009
> [May 18 14:13:07] VERBOSE[25098] logger.c:     -- SIP/PL1009-00001808 is ringing
> [May 18 14:13:07] DEBUG[25312] app_queue.c: KUMBELOG: queue=queue_3        count=1,membercount=18,ringinuse=0,device=SIP/PL1009,status=6
> [May 18 14:13:08] DEBUG[25382] app_queue.c: KUMBELOG: queue=queue_4        count=1,membercount=18,ringinuse=0,device=SIP/PL1009,status=6
> [May 18 14:13:08] DEBUG[25224] app_queue.c: KUMBELOG: queue=queue_2        count=2,membercount=15,ringinuse=0,device=SIP/PL1009,status=6
> [May 18 14:13:12] VERBOSE[25098] logger.c:     -- SIP/PL1009-00001808 answered SIP/192.168.55.32-000017e6
> [May 18 14:13:13] VERBOSE[25098] logger.c:     -- Native bridging SIP/192.168.55.32-000017e6 and SIP/PL1009-00001808
> [May 18 14:13:14] DEBUG[25224] app_queue.c: KUMBELOG: queue=queue_2        count=1,membercount=15,ringinuse=0,device=SIP/PL1009,status=7
> {noformat}
> It seems that the system does not change the status of the user after calling it, and then re-schedule a new call.
> After that the status is updated and goes in a ring+inuse status (7)
> Do you have any idea about what can cause that?
> This is an example of my config
> {noformat}
> [PL1009]
> context=mycontext
> callerid=PhoneLine1009 <1009>
> secret=pwd1009
> type=peer
> host=dynamic
> call-limit=3
> disallow=all
> allow=ulaw
> queues:
> [queue_1]
> weight=10
> wrapuptime=0
> strategy=leastrecent
> joinempty=no
> retry=0
> autopause=yes
> setinterfacevar=yes
> eventwhencalled=yes
> eventmemberstatus=yes
> ringinuse=no
> member => SIP/PL1009
> [queue_2]
> weight=10
> wrapuptime=0
> strategy=leastrecent
> joinempty=no
> retry=0
> autopause=yes
> setinterfacevar=yes
> eventwhencalled=yes
> eventmemberstatus=yes
> ringinuse=no
> member => SIP/PL1009
> [queue_3]
> weight=10
> wrapuptime=0
> strategy=leastrecent
> joinempty=no
> retry=0
> autopause=yes
> setinterfacevar=yes
> eventwhencalled=yes
> eventmemberstatus=yes
> ringinuse=no
> member => SIP/PL1009
> {noformat}
> ****** ADDITIONAL INFORMATION ******
> I've tried:
> 1.4.31
> 1.4.30
> run the system using ESXi on DL380
> run the system using ESXi on HP Blade
> run the system directly on hardware without virtualization
> used slackware 13.0 instead of debian AMD 64
> changed the kernel hertz to 1000 instead of 250
> added dahdi to optimize timing
> On client-side, i've tested
> Sjphone on windows
> CISCO 7940 phone
> in all these test-case i had the problem, and it occurs with a frequency of 100 times each 4000 calls.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira