FreePBX rejected some incoming calls

FreePBX Providers
1

I have FreePBX 16 setup with a SIP trunk provided by flowroute. Most of the incoming calls work, but in probably 1 out of 5 incoming calls, FreePBX does no take the call and causes flowroute to failover to my failover route I put in my Flowroute portal. I talked to Flowroute about this, as I was able to isolate a call FreePBX didn’t pick up and they said the PBX wasn’t sending back a signal to them that it saw the call.

Here is the log entries I captured for the call. FreePBX sees it, but it isn’t taking the call:

[2024-11-25 16:04:23] VERBOSE[2483][C-0000006c] netsock2.c: Using SIP RTP TOS bits 184
[2024-11-25 16:04:23] VERBOSE[2483][C-0000006c] netsock2.c: Using SIP RTP CoS mark 5
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [15036881270@from-trunk:1] Set(“SIP/US West OR Flowroute-00000068”, “__DIRECTION=INBOUND”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [15036881270@from-trunk:2] Gosub(“SIP/US West OR Flowroute-00000068”, “sub-record-check,s,1(in,15036881270,dontcare)”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/US West OR Flowroute-00000068”, “0?initialized”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:2] Set(“SIP/US West OR Flowroute-00000068”, “__REC_STATUS=INITIALIZED”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:3] Set(“SIP/US West OR Flowroute-00000068”, “NOW=1732579463”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:4] Set(“SIP/US West OR Flowroute-00000068”, “__DAY=25”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:5] Set(“SIP/US West OR Flowroute-00000068”, “__MONTH=11”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:6] Set(“SIP/US West OR Flowroute-00000068”, “__YEAR=2024”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:7] Set(“SIP/US West OR Flowroute-00000068”, “__TIMESTR=20241125-160423”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:8] Set(“SIP/US West OR Flowroute-00000068”, “__FROMEXTEN=unknown”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:9] Set(“SIP/US West OR Flowroute-00000068”, “__MON_FMT=wav”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/US West OR Flowroute-00000068”, “Recordings initialized”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/US West OR Flowroute-00000068”, “0?Set(ARG3=dontcare)”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/US West OR Flowroute-00000068”, “REC_POLICY_MODE_SAVE=”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/US West OR Flowroute-00000068”, “0?Set(REC_STATUS=NO)”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/US West OR Flowroute-00000068”, “2?checkaction”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx_builtins.c: Goto (sub-record-check,s,17)
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/US West OR Flowroute-00000068”, “1?sub-record-check,in,1”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx_builtins.c: Goto (sub-record-check,in,1)
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [in@sub-record-check:1] NoOp(“SIP/US West OR Flowroute-00000068”, “Inbound Recording Check to 15036881270”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [in@sub-record-check:2] Set(“SIP/US West OR Flowroute-00000068”, “FROMEXTEN=unknown”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [in@sub-record-check:3] ExecIf(“SIP/US West OR Flowroute-00000068”, “12?Set(FROMEXTEN=+15415218449)”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [in@sub-record-check:4] Gosub(“SIP/US West OR Flowroute-00000068”, “recordcheck,1(dontcare,in,15036881270)”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/US West OR Flowroute-00000068”, “Starting recording check against dontcare”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/US West OR Flowroute-00000068”, “dontcare”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/US West OR Flowroute-00000068”, “”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [in@sub-record-check:5] Return(“SIP/US West OR Flowroute-00000068”, “”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [15036881270@from-trunk:3] Set(“SIP/US West OR Flowroute-00000068”, “CHANNEL(tonezone)=us”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [15036881270@from-trunk:4] Set(“SIP/US West OR Flowroute-00000068”, “__FROM_DID=15036881270”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [15036881270@from-trunk:5] Set(“SIP/US West OR Flowroute-00000068”, “returnhere=1”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [15036881270@from-trunk:6] Gosub(“SIP/US West OR Flowroute-00000068”, “app-blacklist-check,s,1()”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“SIP/US West OR Flowroute-00000068”, “0?blacklisted”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-blacklist-check:2] Set(“SIP/US West OR Flowroute-00000068”, “CALLED_BLACKLIST=1”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-blacklist-check:3] Return(“SIP/US West OR Flowroute-00000068”, “”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [15036881270@from-trunk:7] Set(“SIP/US West OR Flowroute-00000068”, “CDR(did)=15036881270”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [h@from-trunk:1] Macro(“SIP/US West OR Flowroute-00000068”, “hangupcall,”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@macro-hangupcall:1] Set(“SIP/US West OR Flowroute-00000068”, “__MCVMSTATUS=”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@macro-hangupcall:2] Gosub(“SIP/US West OR Flowroute-00000068”, “app-missedcall-hangup,s,1()”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-missedcall-hangup:1] NoOp(“SIP/US West OR Flowroute-00000068”, “Dialed: s”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-missedcall-hangup:2] NoOp(“SIP/US West OR Flowroute-00000068”, "Caller: ") in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-missedcall-hangup:3] GotoIf(“SIP/US West OR Flowroute-00000068”, “0?exit”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-missedcall-hangup:4] Set(“SIP/US West OR Flowroute-00000068”, “EXTENNUM=s”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-missedcall-hangup:5] Set(“SIP/US West OR Flowroute-00000068”, “FEXTENNUM=s”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-missedcall-hangup:6] GotoIf(“SIP/US West OR Flowroute-00000068”, “0?exit”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-missedcall-hangup:7] AGI(“SIP/US West OR Flowroute-00000068”, “missedcallnotify.php,s,s,0,SIP/US West OR Flowroute-00000068,”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/missedcallnotify.php
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] res_agi.c: <SIP/US West OR Flowroute-00000068>AGI Script missedcallnotify.php completed, returning 0
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@app-missedcall-hangup:8] Return(“SIP/US West OR Flowroute-00000068”, “”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@macro-hangupcall:3] GotoIf(“SIP/US West OR Flowroute-00000068”, “1?theend”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx_builtins.c: Goto (macro-hangupcall,s,5)
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@macro-hangupcall:5] ExecIf(“SIP/US West OR Flowroute-00000068”, “0?Set(CDR(recordingfile)=)”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Executing [s@macro-hangupcall:6] Hangup(“SIP/US West OR Flowroute-00000068”, “”) in new stack
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on ‘SIP/US West OR Flowroute-00000068’ in macro ‘hangupcall’
[2024-11-25 16:04:23] VERBOSE[29857][C-0000006c] pbx.c: Spawn extension (from-trunk, h, 1) exited non-zero on ‘SIP/US West OR Flowroute-00000068’

2

You need the full log, not just the VERBOSE one, and you need the CLI command “sip set debug on” to be in effect. Also note that chan_sip is no longer supported by the main Asterisk project.

3

Do you mean the entire log file or just those entries that are related to the dropped call?

I can convert the trunks to pjsip. That’s just the config I was used to using and I’ve yet to make the jump to Freepbx 17.

4

Just the failed call, but all the categories. I suspect there is a warning or a notice about why the call is considered to have ended.