Problem with outbound call

AndySilvestre · May 22, 2024, 7:55pm

Hi Guys. I’m having a problem with some outbound calls. When I make the call I get the message ‘All the circuits are busy now’.
This error occurs only with some phone numbers. I don’t know what is wrong.
I don’t what log I have to update here. Sorry, but here are one of the asterisk log that goes wrong:

  == Spawn extension (from-pstn, 12345678, 1) exited non-zero on 'PJSIP/MyCompany-0000001b'
    -- PJSIP/MyCompany-0000001b Internal Gosub(func-apply-sipheaders,s,1(1)) complete GOSUB_RETVAL=
    -- Called PJSIP/01112345678@MyCompany
  == Everyone is busy/congested at this time (1:0/1/0)
    -- Executing [s@macro-dialout-trunk:29] NoOp("PJSIP/223-0000001a", "Dial failed for some reason with DIALSTATUS = CONGESTION and HANGUPCAUSE = 34") in new stack
    -- Executing [s@macro-dialout-trunk:30] GotoIf("PJSIP/223-0000001a", "0?continue,1:s-CONGESTION,1") in new stack
    -- Goto (macro-dialout-trunk,s-CONGESTION,1)
    -- Executing [s-CONGESTION@macro-dialout-trunk:1] Set("PJSIP/223-0000001a", "RC=34") in new stack
    -- Executing [s-CONGESTION@macro-dialout-trunk:2] Goto("PJSIP/223-0000001a", "34,1") in new stack
    -- Goto (macro-dialout-trunk,34,1)
    -- Executing [34@macro-dialout-trunk:1] Goto("PJSIP/223-0000001a", "continue,1") in new stack
    -- Goto (macro-dialout-trunk,continue,1)
    -- Executing [continue@macro-dialout-trunk:1] NoOp("PJSIP/223-0000001a", "TRUNK Dial failed due to CONGESTION HANGUPCAUSE: 34 - failing through to other trunks") in new stack
    -- Executing [continue@macro-dialout-trunk:2] ExecIf("PJSIP/223-0000001a", "1?Set(CALLERID(number)=223)") in new stack

And here one that goes right:

 == Spawn extension (from-pstn, 87654321, 1) exited non-zero on 'PJSIP/MyCompany-00000025'
    -- PJSIP/MyCompany-00000025 Internal Gosub(func-apply-sipheaders,s,1(1)) complete GOSUB_RETVAL=
    -- Called PJSIP/01187654321@MyCompany
       > 0x7f0540022550 -- Strict RTP learning after remote address set to: yyy.yyy.yyy.yyy:14556
    -- PJSIP/MyCompany-00000025 answered PJSIP/223-00000024
    -- PJSIP/MyCompany-00000025 Internal Gosub(sub-send-obroute-email,s,1(01187654321,87654321,1,1716405287,,5511MyPhone)) start
    -- Executing [s@sub-send-obroute-email:1] GotoIf("PJSIP/MyCompany-00000025", "0?sendEmail") in new stack
    -- Executing [s@sub-send-obroute-email:2] NoOp("PJSIP/MyCompany-00000025", "email notifications disabled..exiting.") in new stack
    -- Executing [s@sub-send-obroute-email:3] Return("PJSIP/MyCompany-00000025", "") in new stack
  == Spawn extension (from-pstn, , 1) exited non-zero on 'PJSIP/MyCompany-00000025'
    -- PJSIP/MyCompany-00000025 Internal Gosub(sub-send-obroute-email,s,1(01187654321,87654321,1,1716405287,,5511MyPhone)) complete GOSUB_RETVAL=
       > 0x7f0540089b30 -- Strict RTP learning after remote address set to: xxx.xxx.xxx.xxx:2232
    -- Channel PJSIP/MyCompany-00000025 joined 'simple_bridge' basic-bridge <90c9ce80-c00c-4852-b798-90da03ea661a>
    -- Channel PJSIP/223-00000024 joined 'simple_bridge' basic-bridge <90c9ce80-c00c-4852-b798-90da03ea661a>
       > 0x7f0540022550 -- Strict RTP switching to RTP target address yyy.yyy.yyy.yyy:14556 as source
       > 0x7f0540089b30 -- Strict RTP qualifying stream type: audio
       > 0x7f0540089b30 -- Strict RTP switching source address to xxx.xxx.xxx.xxx:3191
    -- Channel PJSIP/223-00000024 left 'simple_bridge' basic-bridge <90c9ce80-c00c-4852-b798-90da03ea661a>
  == Spawn extension (macro-dialout-trunk, s, 28) exited non-zero on 'PJSIP/223-00000024' in macro 'dialout-trunk'
  == Spawn extension (from-internal, 87654321, 11) exited non-zero on 'PJSIP/223-00000024'

I turned on the PJSIP log, but I got a lot of lines and I don’t know if it is useful.

Stewart1 · May 22, 2024, 8:04pm

It is very useful, at least as a start. With pjsip logger on, make a failing test call, paste the Asterisk log for the call at pastebin.com and post the link here. It’s better to take the relevant section of /var/log/asterisk/full , rather than the console, because the time stamps are often useful.

AndySilvestre · May 22, 2024, 8:14pm

Ok, I’m editing the file to take off the IP’s and numbers. I’ll post it as fast as I can.
Thank You.

Stewart1 · May 22, 2024, 8:59pm

Make sure it is understood what each redacted value stands for (my public IP, provider server address, my LAN address, etc.) Likewise remove only the last 4-6 digits of phone numbers, so it is clear what country you are calling, whether landline or mobile, etc.

dorbe · May 23, 2024, 7:15am

Hi Andy,

The “All circuits are busy now” recording is a default recording on FreePBX.
You will hear it when call is failing to reach or be answered by the trunk, and the system does not have any other trunks to failover the call through.

I assume you have only one trunk on your outbound route, and that’s the reason for this sound message.

(you can also see the system try to find another trunk as failover from the log you attached: == Everyone is busy/congested at this time (1:0/1/0))

I assume PJSIP/MyCompany-0000001b is your call provider.
You should see the real status of the failed call on /var/log/asterisk/full and more relevant data.

It can be connection / network issue between your server and the provider or something wrong on your provider side which you can resolve with them.

As you mentioned, it is happened not in all calls so maybe something is wrong with number format?

I will recommend to check with the provider, then you could understand whether they got the call and failed it from their end for some reason, or if it is a connection issue.

AndySilvestre · May 23, 2024, 2:27pm

@Stewart1 I upload the PJSIP debug in pastebin https://pastebin.com/hHzWhY74
I hope this has some useful information.

And thanks for the answer @dorbe. You’re right, we have only one outbound route with one trunk. In the case of PJSIP/MyCompany is the name of the trunk. I’m talking with my provider to see if the problem is on their side.
I got the log of the full file. Here are some lines:


[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:30] ExecIf("PJSIP/223-000000a5", "1?Set(CALLERID(all)=55115585xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:31] ExecIf("PJSIP/223-000000a5", "0?Set(CALLERID(all)=)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:32] ExecIf("PJSIP/223-000000a5", "0?Set(CALLERID(all)=)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:33] ExecIf("PJSIP/223-000000a5", "0?Set(CALLERID(all)=223)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:34] ExecIf("PJSIP/223-000000a5", "0?Set(CALLERID(all)=223)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:35] Set("PJSIP/223-000000a5", "TIOHIDE=no") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:36] ExecIf("PJSIP/223-000000a5", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:37] ExecIf("PJSIP/223-000000a5", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:38] ExecIf("PJSIP/223-000000a5", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:39] ExecIf("PJSIP/223-000000a5", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:40] Set("PJSIP/223-000000a5", "CDR(outbound_cnum)=55115585xxxx") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outbound-callerid:41] Set("PJSIP/223-000000a5", "CDR(outbound_cnam)=") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:14] GosubIf("PJSIP/223-000000a5", "1?sub-flp-1,s,1()") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:1] ExecIf("PJSIP/223-000000a5", "0?Set(TARGET_FLP_1=0110113624xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:2] GotoIf("PJSIP/223-000000a5", "0?match") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:3] ExecIf("PJSIP/223-000000a5", "0?Set(TARGET_FLP_1=00113624xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:4] GotoIf("PJSIP/223-000000a5", "0?match") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:5] ExecIf("PJSIP/223-000000a5", "0?Set(TARGET_FLP_1=00113624xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:6] GotoIf("PJSIP/223-000000a5", "0?match") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:7] ExecIf("PJSIP/223-000000a5", "0?Set(TARGET_FLP_1=00113624xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:8] GotoIf("PJSIP/223-000000a5", "0?match") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:9] Return("PJSIP/223-000000a5", "") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:15] Set("PJSIP/223-000000a5", "OUTNUM=0113624xxxx") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:16] Set("PJSIP/223-000000a5", "custom=PJSIP") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:17] ExecIf("PJSIP/223-000000a5", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:18] ExecIf("PJSIP/223-000000a5", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:19] ExecIf("PJSIP/223-000000a5", "0?AGI(allowlist-autoadd.agi,)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:20] Macro("PJSIP/223-000000a5", "dialout-trunk-predial-hook,") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("PJSIP/223-000000a5", "") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:21] GotoIf("PJSIP/223-000000a5", "0?bypass,1") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:22] ExecIf("PJSIP/223-000000a5", "1?Set(CONNECTEDLINE(num,i)=0113624xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:23] ExecIf("PJSIP/223-000000a5", "1?Set(CONNECTEDLINE(name,i)=CID:55115585xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:24] ExecIf("PJSIP/223-000000a5", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)55115585xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:25] GotoIf("PJSIP/223-000000a5", "0?customtrunk") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:26] ExecIf("PJSIP/223-000000a5", "0?Set(DIAL_TRUNK_OPTIONS=)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:27] Set("PJSIP/223-000000a5", "HASH(__SIPHEADERS,Alert-Info)=unset") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:28] Dial("PJSIP/223-000000a5", "PJSIP/0113624xxxx@MyTrunk,300,Tb(func-apply-sipheaders^s^1,(1))U(sub-send-obroute-email^0113624xxxx^3624xxxx^1^1716463668^^55115585xxxx)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] app_stack.c: PJSIP/MyTrunk-000000a6 Internal Gosub(func-apply-sipheaders,s,1(1)) start
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp("PJSIP/MyTrunk-000000a6", "Applying SIP Headers to channel PJSIP/MyTrunk-000000a6") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:2] Set("PJSIP/MyTrunk-000000a6", "TECH=PJSIP") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:3] Set("PJSIP/MyTrunk-000000a6", "SIPHEADERKEYS=Alert-Info") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:4] While("PJSIP/MyTrunk-000000a6", "1") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:5] Set("PJSIP/MyTrunk-000000a6", "sipheader=unset") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:6] ExecIf("PJSIP/MyTrunk-000000a6", "1?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack
[2024-05-23 08:27:48] ERROR[19124] res_pjsip_header_funcs.c: No headers had been previously added to this session.
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf("PJSIP/MyTrunk-000000a6", "0?Set(sipheader=<http://127.0.0.1>;info=unset)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:8] ExecIf("PJSIP/MyTrunk-000000a6", "0?Set(sipheader=<http://127.0.0.1>unset)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:9] ExecIf("PJSIP/MyTrunk-000000a6", "0?Set(PJSIP_HEADER(add,Alert-Info)=unset)") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:10] EndWhile("PJSIP/MyTrunk-000000a6", "") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:4] While("PJSIP/MyTrunk-000000a6", "0") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@func-apply-sipheaders:11] Return("PJSIP/MyTrunk-000000a6", "") in new stack
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] app_stack.c: Spawn extension (from-pstn, 3624xxxx, 1) exited non-zero on 'PJSIP/MyTrunk-000000a6'
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] app_stack.c: PJSIP/MyTrunk-000000a6 Internal Gosub(func-apply-sipheaders,s,1(1)) complete GOSUB_RETVAL=
[2024-05-23 08:27:48] VERBOSE[17200][C-0000004e] app_dial.c: Called PJSIP/0113624xxxx@MyTrunk
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] app_dial.c: Everyone is busy/congested at this time (1:0/1/0)
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:29] NoOp("PJSIP/223-000000a5", "Dial failed for some reason with DIALSTATUS = CONGESTION and HANGUPCAUSE = 34") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-dialout-trunk:30] GotoIf("PJSIP/223-000000a5", "0?continue,1:s-CONGESTION,1") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx_builtins.c: Goto (macro-dialout-trunk,s-CONGESTION,1)
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [s-CONGESTION@macro-dialout-trunk:1] Set("PJSIP/223-000000a5", "RC=34") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [s-CONGESTION@macro-dialout-trunk:2] Goto("PJSIP/223-000000a5", "34,1") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx_builtins.c: Goto (macro-dialout-trunk,34,1)
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [34@macro-dialout-trunk:1] Goto("PJSIP/223-000000a5", "continue,1") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx_builtins.c: Goto (macro-dialout-trunk,continue,1)
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [continue@macro-dialout-trunk:1] NoOp("PJSIP/223-000000a5", "TRUNK Dial failed due to CONGESTION HANGUPCAUSE: 34 - failing through to other trunks") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [continue@macro-dialout-trunk:2] ExecIf("PJSIP/223-000000a5", "1?Set(CALLERID(number)=223)") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [3624xxxx@from-internal:12] Macro("PJSIP/223-000000a5", "outisbusy,") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outisbusy:1] Progress("PJSIP/223-000000a5", "") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outisbusy:2] GotoIf("PJSIP/223-000000a5", "0?emergency,1") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outisbusy:3] GotoIf("PJSIP/223-000000a5", "0?intracompany,1") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outisbusy:4] Playback("PJSIP/223-000000a5", "all-circuits-busy-now&please-try-call-later, noanswer") in new stack
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] file.c: <PJSIP/223-000000a5> Playing 'all-circuits-busy-now.ulaw' (language 'en')
[2024-05-23 08:28:20] VERBOSE[19124] res_rtp_asterisk.c: 0x7f055c031120 -- Strict RTP learning after remote address set to: xxx.xxx.xxx.xxx:2230
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] res_rtp_asterisk.c: 0x7f055c031120 -- Strict RTP qualifying stream type: audio
[2024-05-23 08:28:20] VERBOSE[17200][C-0000004e] res_rtp_asterisk.c: 0x7f055c031120 -- Strict RTP switching source address to xxx.xxx.xxx.xxx:3206
[2024-05-23 08:28:22] VERBOSE[17200][C-0000004e] file.c: <PJSIP/223-000000a5> Playing 'please-try-call-later.ulaw' (language 'en')
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-outisbusy:5] Congestion("PJSIP/223-000000a5", "20") in new stack
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] app_macro.c: Spawn extension (macro-outisbusy, s, 5) exited non-zero on 'PJSIP/223-000000a5' in macro 'outisbusy'
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] pbx.c: Spawn extension (from-internal, 3624xxxx, 12) exited non-zero on 'PJSIP/223-000000a5'
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] pbx.c: Executing [h@from-internal:1] Macro("PJSIP/223-000000a5", "hangupcall") in new stack
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/223-000000a5", "1?theend") in new stack
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2024-05-23 08:28:24] ERROR[2776] cdr.c: Unable to find CDR for channel PJSIP/223-000000a5
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/223-000000a5", "0?Set(CDR(recordingfile)=)") in new stack
[2024-05-23 08:28:24] ERROR[2776] cdr.c: Unable to find CDR for channel PJSIP/223-000000a5
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] pbx.c: Executing [s@macro-hangupcall:4] Hangup("PJSIP/223-000000a5", "") in new stack
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'PJSIP/223-000000a5' in macro 'hangupcall'
[2024-05-23 08:28:24] VERBOSE[17200][C-0000004e] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'PJSIP/223-000000a5'

I saw that in this line it changes the fone to 01101136…

VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:1] ExecIf("PJSIP/223-000000a5", "0?Set(TARGET_FLP_1=0110113624xxxx)") in new stack

But in the lines below it becomes 01136… Maybe is that the problem?

Stewart1 · May 23, 2024, 3:41pm

AndySilvestre:

I saw that in this line it changes the fone to 01101136…
VERBOSE[17200][C-0000004e] pbx.c: Executing [s@sub-flp-1:1] ExecIf("PJSIP/223-000000a5", "0?Set(TARGET_FLP_1=0110113624xxxx)") in new stack
But in the lines below it becomes 01136… Maybe is that the problem?

No, because the if condition tested in that line was false (that’s what the 0 before the ? means), the set did not happen and TARGET_FLP_1 was not modified.

In the SIP trace, the provider challenged the original INVITE (that started on line 270) with a 407 (starting on line 314). Asterisk correctly responded starting on line 337, but the paste cut off in the middle of a packet after line 378, so the interesting response (that may show why the call was rejected) is not present. Please paste the next ~100 lines.

Just guessing, do you know what format numbers the provider expects? Possibly, 0113624xxxx is invalid and they expect 55113624xxxx or +55113624xxxx, or maybe even 0ss113624xxxx, where ss is their carrier selection code.

AndySilvestre · May 23, 2024, 6:27pm

I put the rest of the log in the same file at https://pastebin.com/hHzWhY74
So in the new part has the lines (lines 639-640)

CSeq: 358 CANCEL
Reason: Q.850;cause=127

I’ll search for what is this error ‘127’.
And about the number format, I think it’s right because if I make a call to another number in the same city it works.

david55 · May 23, 2024, 6:56pm

Redacting the call-ID, especially without retaining a one to one mapping between redacted and unredacted values is not a sensible thing to do when asking people to analyze a SIP log. Also screen scraping, rather than using the log file, is not a good idea where timing is relevant.

The B side accepts the call request, but the call neither completes nor fails. The caller eventually gives up causing the CANCELs. The screen scraping means it is difficult to tell whether the caller waited long enough before giving up.

Stewart1 · May 23, 2024, 7:43pm

Please confirm: Calling some landline numbers in São Paulo works, but others fail, even if they are served by the same carrier.

Unrelated to the failing calls, you have a problem where extension 223 is misconfigured and repeatedly trying to SUBSCRIBE to messages at address “1”, which Asterisk does not have, resulting in the log filling with garbage.

It’s been more than 10 years since I last saw a Poly SPIP and I don’t remember the details.

On a VVX, the relevant settings are
msg.mwi.1.callBack="*97"
msg.mwi.1.callBackMode="contact"
msg.mwi.1.subscribe=""

I’m guessing that you have something like
msg.mwi.1.subscribe="1"
and if changing “1” to “” doesn’t work, you need to find out what should go in place of the 1.

If you can’t easily fix this, just paste at least 30 seconds of log after the call was initiated.

system · June 23, 2024, 7:43pm

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.