Asterisk 18 -- Agent ring time out works incorrectly intermitently

Asterisk Asterisk Support
1

Hi All,

We set “Agent Ring Time Out” = 30 seconds in table queue
But it is expired after 2 seconds, this issue happend only one time at Customer site
We could not reproduce the issue on the same lab, more detail is as below

05:07:10: our Customer updated table queue with Strategy to “rrmemory” and timeout(Agent Ring Timeout) to “30 seconds”
*Notes: We are supporting asterisk load balancing (Multiple asterisks)

05:08:52: Look at first block of log below for First call, we can see, Agent Ring Timeout works well, it is “Nobody picked up in 30000 ms”

05:10:27: Look at the second block of log below for Second call, we can, Agent Ring Timeout is is 2 seconds, not 30 seconds anymore see the log “app_queue.c: Nobody picked up in 2000 ms”

Now we could not reproduce the issue, obviously everything is done by app_queue.c, so I can’t think about any trigger from asterisk (AMI/AGI) or any trigger from outsides (Caller) which is able to change the Agent Ring Timeout in asterisk

If you have any idea how can I dig deeper on this issue to figure out the root cause, or you can give me some assumption any trigger which can lead to this behavior (Agent Ring Timeout is changed)

First call – Agent Ring Timeout worked well
ip-10-5-0-209CLI> agi://127.0.0.1:4573/strategy,370: Skill Strategy: rrmemory
ip-10-5-0-209CLI> – <PJSIP/provider_brastel_t-40ecaed9-0000001f>AGI Script agi://127.0.0.1:4573/strategy completed, returning 0
ip-10-5-0-209CLI> – Executing [0368688305@queues:7] Set(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “PJSIP_DTMF_MODE()=info”) in new stack
ip-10-5-0-209CLI> – Executing [0368688305@queues:8] Queue(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “370,tT,60”) in new stack
ip-10-5-0-209CLI> – Started music on hold, class ‘147’, on channel ‘PJSIP/provider_brastel_t-40ecaed9-0000001f’
ip-10-5-0-209CLI> – Called PJSIP/64005@147.collabos.com
ip-10-5-0-209CLI> [2023-05-11 05:08:22.940] WARNING[10021]: res_pjsip_sdp_rtp.c:1909 create_outgoing_sdp_stream: Format ‘testlaw’ can not be added to SDP, consider disallowing it on endpoint ‘64005@147.collabos.com’
ip-10-5-0-209CLI> – PJSIP/64005@147.collabos.com-00000020 is ringing
ip-10-5-0-209CLI> > 0x7f459c0aba60 – Strict RTP learning complete - Locking on source address 202.173.5.145:16440
ip-10-5-0-209CLI> [2023-05-11 05:08:52.820] NOTICE[15225]: res_pjsip_outbound_publish.c:1340 sip_outbound_publish_callback: No response received for outbound publish ‘asterisk9-c’
ip-10-5-0-209*CLI> – Nobody picked up in 30000 ms
ip-10-5-0-209*CLI> – Called PJSIP/64006@147.collabos.com

Second call – Agent ring time did not work correctly
[2023-05-11 05:10:25.268] VERBOSE[17432][C-00000010] pbx.c: Executing [0368688305@queues:1] Set(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “CHANNEL(musicclass)=147”) in new stack
[2023-05-11 05:10:25.268] VERBOSE[17432][C-00000010] pbx.c: Executing [0368688305@queues:2] Set(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “queue_tenant_id=370_147”) in new stack
[2023-05-11 05:10:25.275] VERBOSE[17432][C-00000010] pbx.c: Executing [0368688305@queues:3] Set(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “queue_timeout=60”) in new stack
[2023-05-11 05:10:25.275] VERBOSE[17432][C-00000010] pbx.c: Executing [0368688305@queues:4] Set(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “CALLERID(name)=447-370”) in new stack
[2023-05-11 05:10:25.275] VERBOSE[17432][C-00000010] pbx.c: Executing [0368688305@queues:5] Answer(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “nocdr”) in new stack
[2023-05-11 05:10:25.275] VERBOSE[14665] res_rtp_asterisk.c: 0x7fd3b00e9240 – Strict RTP learning after remote address set to: 202.173.5.145:17930
[2023-05-11 05:10:25.437] VERBOSE[17432][C-00000010] res_rtp_asterisk.c: 0x7fd3b00e9240 – Strict RTP switching to RTP target address 202.173.5.145:17930 as source
[2023-05-11 05:10:25.437] VERBOSE[17432][C-00000010] pbx.c: Executing [0368688305@queues:6] AGI(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “agi://127.0.0.1:4573/strategy,370”) in new stack
[2023-05-11 05:10:25.487] VERBOSE[17432][C-00000010] res_agi.c: agi://127.0.0.1:4573/strategy,370: Skill Strategy: rrmemory
[2023-05-11 05:10:25.492] VERBOSE[17432][C-00000010] res_agi.c: <PJSIP/provider_brastel_t-40ecaed9-0000001f>AGI Script agi://127.0.0.1:4573/strategy completed, returning 0
[2023-05-11 05:10:25.493] VERBOSE[17432][C-00000010] pbx.c: Executing [0368688305@queues:7] Set(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “PJSIP_DTMF_MODE()=info”) in new stack
[2023-05-11 05:10:25.499] VERBOSE[17432][C-00000010] pbx.c: Executing [0368688305@queues:8] Queue(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “370,tT,60”) in new stack
[2023-05-11 05:10:25.523] VERBOSE[17432][C-00000010] res_musiconhold.c: Started music on hold, class ‘147’, on channel ‘PJSIP/provider_brastel_t-40ecaed9-0000001f’
[2023-05-11 05:10:25.542] VERBOSE[17432][C-00000010] app_queue.c: Called PJSIP/64004@147.collabos.com
[2023-05-11 05:10:25.546] WARNING[16313] res_pjsip_sdp_rtp.c: Format ‘testlaw’ can not be added to SDP, consider disallowing it on endpoint ‘64004@147.collabos.com’
[2023-05-11 05:10:25.546] WARNING[16313] res_pjsip_sdp_rtp.c: Format ‘silk8’ can not be added to SDP, consider disallowing it on endpoint ‘64004@147.collabos.com’
[2023-05-11 05:10:25.546] WARNING[16313] res_pjsip_sdp_rtp.c: Format ‘silk12’ can not be added to SDP, consider disallowing it on endpoint ‘64004@147.collabos.com’
[2023-05-11 05:10:25.546] WARNING[16313] res_pjsip_sdp_rtp.c: Format ‘silk16’ can not be added to SDP, consider disallowing it on endpoint ‘64004@147.collabos.com’
[2023-05-11 05:10:25.546] WARNING[16313] res_pjsip_sdp_rtp.c: Format ‘silk24’ can not be added to SDP, consider disallowing it on endpoint ‘64004@147.collabos.com’
[2023-05-11 05:10:26.653] NOTICE[5147] res_pjsip_outbound_publish.c: No response received for outbound publish ‘asterisk9-c’
[2023-05-11 05:10:27.507] VERBOSE[17432][C-00000010] app_queue.c: Nobody picked up in 2000 ms
[2023-05-11 05:10:27.547] VERBOSE[17432][C-00000010] app_queue.c: Called PJSIP/64005@147.collabos.com

2

i would suspect Periodic Announce or Timeout restart: set to no
or Queue timeout: is set to 60 ?

3

Hi @benphone ,

You’re right, periodic_announce is set to “no” and periodic_announce_frequency is “empty”
And also Queue timeout is set to 60 – Queue(“PJSIP/provider_brastel_t-40ecaed9-0000001f”, “370,tT,60”).

How does these settings impact to Agent Ring Time Out ?
Do you have any idea about this issue ? And Now I can’t reproduce the issue anymore

4

Humn, I compared the two logs above again and see that
The second log doesn’t have a line “PJSIP/64005@147.collabos.com-00000020 is ringing”

it seems that When Queue calls Agent but Agent did not ring
this may be a network issue at Customer site, Agent did not respond

Currenlty the issue can’t be reproduced and we also don’t have browserphone console and pcap to confirm this.

Besides that I don’t know where the 2000 ms is set for Asterisk when Agent did not respond the ringing.

Any idea would be appreciated

5

By the way, if my analysis above is correct, then this log " Nobody picked up in 2000 ms" would be confused.

If Agent doesn’t respond to INVITE or The response (180 Ringing) is dropped somewhere but not arrive at asterisk in time, Then Asterisk would report a message more clearly “Not receive response from Agent …”