Issues with Queue Member Status in Asterisk

Hello,

I am encountering issues with the status of queue members in Asterisk. I’ve noticed that queue members start to show as Not in use after a while, even when they are on an active call at that moment, and this call is being received from the same queue that is showing them as Not in use. I have not yet been able to identify the exact moment when this happens.

For instance, in the contingencia queue, the extension 8032 is showing a status of Not in use:

contingencia has 5 calls (max unlimited) in 'rrmemory' strategy (500s holdtime, 411s talktime), W:0, C:483, A:102, SL:1.4%, SL2:1.2% within 0s
   Members:
      SIP/9361 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9385 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8034 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 15 calls (last was 53103 secs ago)
      SIP/8024 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9365 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9389 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8038 (ringinuse disabled) (realtime) (Unavailable) has taken 35 calls (last was 54455 secs ago)
      SIP/8028 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 26 calls (last was 63493 secs ago)
      SIP/9369 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 7 calls (last was 51395 secs ago)
      SIP/9392 (ringinuse disabled) (dynamic) (paused:undefined was 84592 secs ago) (Unavailable) has taken no calls yet
      SIP/8041 (ringinuse disabled) (realtime) (Unavailable) has taken 17 calls (last was 51635 secs ago)
      SIP/8031 (ringinuse disabled) (realtime) (Unavailable) has taken 18 calls (last was 56101 secs ago)
      SIP/9362 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9386 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8035 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 20 calls (last was 55986 secs ago)
      SIP/8025 (ringinuse disabled) (realtime) (Not in use) has taken 31 calls (last was 501 secs ago)
      SIP/9366 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8015 (ringinuse disabled) (realtime) (Unavailable) has taken 21 calls (last was 49782 secs ago)
      SIP/8039 (ringinuse disabled) (realtime) (Unavailable) has taken 13 calls (last was 42221 secs ago)
      SIP/8029 (ringinuse disabled) (realtime) (Unavailable) has taken 29 calls (last was 56897 secs ago)
      SIP/8042 (ringinuse disabled) (realtime) (Unavailable) has taken 20 calls (last was 38240 secs ago)
      SIP/8032 (ringinuse disabled) (realtime) (Not in use) has taken 19 calls (last was 596 secs ago)
      SIP/9363 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Not in use) has taken 22 calls (last was 41 secs ago)
      SIP/9387 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 16 calls (last was 49997 secs ago)
      SIP/8036 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 15 calls (last was 52654 secs ago)
      SIP/8026 (ringinuse disabled) (realtime) (Unavailable) has taken 14 calls (last was 45065 secs ago)
      SIP/9367 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9390 (ringinuse disabled) (realtime) (Unavailable) has taken 20 calls (last was 50352 secs ago)
      SIP/9360 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9384 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8033 (ringinuse disabled) (realtime) (in call) (In use) has taken 11 calls (last was 342 secs ago)
      SIP/8023 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 18 calls (last was 45077 secs ago)
      SIP/9364 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Not in use) has taken no calls yet
      SIP/8013 (ringinuse disabled) (realtime) (in call) (In use) has taken 13 calls (last was 482 secs ago)
      SIP/9388 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8027 (ringinuse disabled) (realtime) (Unavailable) has taken 19 calls (last was 53537 secs ago)
      SIP/9368 (ringinuse disabled) (realtime) (Unavailable) has taken 23 calls (last was 57346 secs ago)
      SIP/9391 (ringinuse disabled) (realtime) (in call) (In use) has taken 14 calls (last was 336 secs ago)
      SIP/9449 (ringinuse disabled) (dynamic) (in call) (In use) has taken 27 calls (last was 1178 secs ago)
      SIP/8040 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
   Callers:
      1. SIP/webex-sede-00004f56 (wait: 5:33, prio: 0)
      2. SIP/webex-sede-00004f79 (wait: 4:56, prio: 0)
      3. SIP/webex-sede-00004fb0 (wait: 3:50, prio: 0)
      4. SIP/webex-sede-00004ffd (wait: 1:24, prio: 0)
      5. SIP/webex-sede-0000501c (wait: 0:21, prio: 0)

However, extension 8032 is on a call at this moment, and even stranger, it’s on a call that it received from the contingency queue. If I call the extension, it signals busy, and if I check the hints, it shows that the extension is Idle.

# asterisk -rx "core show channels verbose" | grep d167ef58-7085-42e9-b
SIP/webex-sede-00004 queues               8817                5 Up      Queue        contingencia,t,,          051999113113    00:25:52                         d167ef58-7085-42e9-b
SIP/8032-00004e4b    ddd                  8817                1 Up      AppQueue     (Outgoing Line)           8032            00:15:34                         d167ef58-7085-42e9-b
#asterisk -rx "core show hints" | grep 8032
8032@default        : SIP/8032              State:Idle            Presence:not_set         Watchers  2

Everything was fine at the beggining of the day, but as time passes and the number of calls increases, this starts to happen more frequently with different extensions in the queue.

To make things even stranger, the status was correct for the next call that came in:

contingencia has 3 calls (max unlimited) in 'rrmemory' strategy (231s holdtime, 715s talktime), W:0, C:493, A:114, SL:1.4%, SL2:1.2% within 0s
   Members:
      SIP/9361 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9385 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8034 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 15 calls (last was 54670 secs ago)
      SIP/8024 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9365 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9389 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8038 (ringinuse disabled) (realtime) (in call) (In use) has taken 35 calls (last was 56022 secs ago)
      SIP/8028 (ringinuse disabled) (realtime) (Unavailable) has taken 27 calls (last was 270 secs ago)
      SIP/9369 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 7 calls (last was 52962 secs ago)
      SIP/9392 (ringinuse disabled) (dynamic) (paused:undefined was 86159 secs ago) (Unavailable) has taken no calls yet
      SIP/8041 (ringinuse disabled) (realtime) (Unavailable) has taken 17 calls (last was 53202 secs ago)
      SIP/8031 (ringinuse disabled) (realtime) (in call) (In use) has taken 19 calls (last was 248 secs ago)
      SIP/9362 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9386 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8035 (ringinuse disabled) (realtime) (in call) (In use) has taken 20 calls (last was 57553 secs ago)
      SIP/8025 (ringinuse disabled) (realtime) (in call) (In use) has taken 31 calls (last was 2068 secs ago)
      SIP/9366 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8015 (ringinuse disabled) (realtime) (Unavailable) has taken 21 calls (last was 51349 secs ago)
      SIP/8039 (ringinuse disabled) (realtime) (Unavailable) has taken 13 calls (last was 43788 secs ago)
      SIP/8029 (ringinuse disabled) (realtime) (in call) (In use) has taken 29 calls (last was 58464 secs ago)
      SIP/8042 (ringinuse disabled) (realtime) (in call) (In use) has taken 21 calls (last was 166 secs ago)
      SIP/8032 (ringinuse disabled) (realtime) (in call) (In use) has taken 19 calls (last was 2163 secs ago)
      SIP/9363 (ringinuse disabled) (realtime) (in call) (In use) has taken 22 calls (last was 1608 secs ago)
      SIP/9387 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 16 calls (last was 51564 secs ago)
      SIP/8036 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 15 calls (last was 54221 secs ago)
      SIP/8026 (ringinuse disabled) (realtime) (Unavailable) has taken 14 calls (last was 46632 secs ago)
      SIP/9367 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9390 (ringinuse disabled) (realtime) (Unavailable) has taken 20 calls (last was 51919 secs ago)
      SIP/9360 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/9384 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8033 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Not in use) has taken 12 calls (last was 120 secs ago)
      SIP/8023 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Unavailable) has taken 18 calls (last was 46644 secs ago)
      SIP/9364 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Not in use) has taken no calls yet
      SIP/8013 (ringinuse disabled) (realtime) (in call) (In use) has taken 14 calls (last was 1275 secs ago)
      SIP/9388 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
      SIP/8027 (ringinuse disabled) (realtime) (Unavailable) has taken 19 calls (last was 55104 secs ago)
      SIP/9368 (ringinuse disabled) (realtime) (in call) (In use) has taken 23 calls (last was 58913 secs ago)
      SIP/9391 (ringinuse disabled) (realtime) (paused was 0 secs ago) (Not in use) has taken 18 calls (last was 292 secs ago)
      SIP/9449 (ringinuse disabled) (dynamic) (in call) (In use) has taken 28 calls (last was 930 secs ago)
      SIP/8040 (ringinuse disabled) (realtime) (paused:undefined was 0 secs ago) (Unavailable) has taken no calls yet
   Callers:
      1. SIP/webex-sede-00005277 (wait: 0:57, prio: 0)
      2. SIP/webex-sede-00005280 (wait: 0:24, prio: 0)
      3. SIP/webex-sede-00005282 (wait: 0:20, prio: 0)
# asterisk -rx "core show channels verbose" | grep 2c0da44d-7b16-4e31-8
SIP/8032-00005213    ddd                  8817                1 Up      AppQueue     (Outgoing Line)           8032            00:09:49                         2c0da44d-7b16-4e31-8
SIP/webex-sede-00005 queues               8817                5 Up      Queue        contingencia,t,,          08532467575     00:15:24                         2c0da44d-7b16-4e31-8
# asterisk -rx "core show hints" | grep 8032
8032@default        : SIP/8032              State:InUse           Presence:not_set         Watchers  2

Has anyone else experienced this?
Do you know how to resolve it or can you provide any guidance on what I should look into?

Thanks.

The chan_sip module is what calculates/determines/provides that information, if it’s not correct then it’s likely something in there.

These extensions are connected remotely through VPN.
Could this be happening due to some kind of packet blocking on the network? Any packet being blocked, lost, or discarded?

How could I monitor this?

Is this calculation you’re referring to constantly done during the call? In this case, can this status change during the call, what I mean is, at times it will show Not in use and at others InUse within the same call? Or is this calculation only done at the moment a call is sent to the extension?

I do not remember any details of how chan_sip determines such things or the specifics.

I don’t believe the problem is in the sip settings, I use realtime with a postgres database, and the extension in the example is configured as follows:

# SELECT name, defaultuser, host, type, context, secret, nat, callgroup, pickupgroup, language, disallow, allow, callerid, description FROM public.sippeers WHERE name = '8032';
 name |       defaultuser        |  host   |  type  | context |    secret    |         nat         | callgroup | pickupgroup | language | disallow | allow |             callerid              | description
------+--------------------------+---------+--------+---------+--------------+---------------------+-----------+-------------+----------+----------+-------+-----------------------------------+-------------
 8032 | TESTE TESTE TESTE TESTE1 | dynamic | friend | ddd     | 2ysOIsWBhFI0 | force_rport,comedia | 23        | 23          | pt_BR    | all      | ulaw  | "TESTE TESTE TESTE TESTE1" <8032> | Atento
(1 row)

I have these same settings working on other clients and I’ve never had this problem, what’s different in this one is that their network is very closed and segmented and with many members and many calls happening.

I still need help with this case, it is still happening that an extension that is on a call appears as Idle both in the queue and in the hints, I have already confirmed and in the sip.conf there is the line callcounter=yes within [general].

The problem is still happening very frequently, is there anything I can do to identify where the problem is, does anyone have any idea?