PBX hanging up on incoming call

When calling the pbx hangs up immediately. Outgoing calls work fine. Everything was working for months until yesterday. Any help would be great.

[2021-11-16 08:22:12] VERBOSE[2546][C-0000003b] netsock2.c: Using SIP RTP CoS mark 5
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:1] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__DIRECTION=INBOUND") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:2] Gosub("SIP/fpbx-1-1X9zS3p60AwK-00000017", "sub-record-check,s,1(in,{PBX PHONE NUEBER},yes)") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?initialized") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:2] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__REC_STATUS=INITIALIZED") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:3] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "NOW=1637068932") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:4] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__DAY=16") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:5] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__MONTH=11") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:6] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__YEAR=2021") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:7] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__TIMESTR=20211116-082212") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:8] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__FROMEXTEN=unknown") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:9] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__MON_FMT=wav") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/fpbx-1-1X9zS3p60AwK-00000017", "Recordings initialized") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?Set(ARG3=dontcare)") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:12] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "REC_POLICY_MODE_SAVE=") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:13] ExecIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?Set(REC_STATUS=NO)") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:14] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "2?checkaction") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx_builtins.c: Goto (sub-record-check,s,17)
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@sub-record-check:17] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "1?sub-record-check,in,1") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx_builtins.c: Goto (sub-record-check,in,1)
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [in@sub-record-check:1] NoOp("SIP/fpbx-1-1X9zS3p60AwK-00000017", "Inbound Recording Check to {PBX PHONE NUEBER}") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [in@sub-record-check:2] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "FROMEXTEN=unknown") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [in@sub-record-check:3] ExecIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "11?Set(FROMEXTEN=1{INCOMMING PHONE NUEBER})") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [in@sub-record-check:4] Gosub("SIP/fpbx-1-1X9zS3p60AwK-00000017", "recordcheck,1(yes,in,{PBX PHONE NUEBER})") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/fpbx-1-1X9zS3p60AwK-00000017", "Starting recording check against yes") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/fpbx-1-1X9zS3p60AwK-00000017", "yes") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx_builtins.c: Goto (sub-record-check,recordcheck,9)
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:9] ExecIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?Return()") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:10] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__REC_POLICY_MODE=YES") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:11] Goto("SIP/fpbx-1-1X9zS3p60AwK-00000017", "startrec") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx_builtins.c: Goto (sub-record-check,recordcheck,16)
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:16] NoOp("SIP/fpbx-1-1X9zS3p60AwK-00000017", "Starting recording: in, {PBX PHONE NUEBER}") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:17] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__CALLFILENAME=in-{PBX PHONE NUEBER}-1{INCOMMING PHONE NUEBER}-20211116-082212-1637068932.55") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:18] MixMonitor("SIP/fpbx-1-1X9zS3p60AwK-00000017", "2021/11/16/in-{PBX PHONE NUEBER}-1{INCOMMING PHONE NUEBER}-20211116-082212-1637068932.55.wav,abi(LOCAL_MIXMON_ID),") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:19] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__MIXMON_ID=0x7fbb8c020570") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:20] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__RECORD_ID=SIP/fpbx-1-1X9zS3p60AwK-00000017") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:21] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__REC_STATUS=RECORDING") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:22] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "CDR(recordingfile)=in-{PBX PHONE NUEBER}-1{INCOMMING PHONE NUEBER}-20211116-082212-1637068932.55.wav") in new stack
[2021-11-16 08:22:12] VERBOSE[32339][C-0000003b] app_mixmonitor.c: Begin MixMonitor Recording SIP/fpbx-1-1X9zS3p60AwK-00000017
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [recordcheck@sub-record-check:23] Return("SIP/fpbx-1-1X9zS3p60AwK-00000017", "") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [in@sub-record-check:5] Return("SIP/fpbx-1-1X9zS3p60AwK-00000017", "") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:3] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "CHANNEL(tonezone)=us") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:4] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__FROM_DID={PBX PHONE NUEBER}") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:5] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "returnhere=1") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:6] Gosub("SIP/fpbx-1-1X9zS3p60AwK-00000017", "app-blacklist-check,s,1()") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?blacklisted") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@app-blacklist-check:2] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "CALLED_BLACKLIST=1") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@app-blacklist-check:3] Return("SIP/fpbx-1-1X9zS3p60AwK-00000017", "") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:7] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "CDR(did)={PBX PHONE NUEBER}") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:8] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:9] ExecIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0 ?Set(CALLERID(name)=1{INCOMMING PHONE NUEBER})") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:10] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__MOHCLASS=") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:11] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__REVERSAL_REJECT=FALSE") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:12] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "1?post-reverse-charge") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx_builtins.c: Goto (from-pstn,{PBX PHONE NUEBER},14)
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:14] NoOp("SIP/fpbx-1-1X9zS3p60AwK-00000017", "") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:15] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:16] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:17] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:18] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:19] NoOp("SIP/fpbx-1-1X9zS3p60AwK-00000017", "CallerID Entry Point") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:20] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "FAX_DEST=ext-fax^1^1") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:21] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "FAXOPT(faxdetect)=yes") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:22] Answer("SIP/fpbx-1-1X9zS3p60AwK-00000017", "") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Spawn extension (from-pstn, {PBX PHONE NUEBER}, 22) exited non-zero on 'SIP/fpbx-1-1X9zS3p60AwK-00000017'
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [h@from-pstn:1] Macro("SIP/fpbx-1-1X9zS3p60AwK-00000017", "hangupcall,") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "1?theend") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?Set(CDR(recordingfile)=)") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@macro-hangupcall:4] NoOp("SIP/fpbx-1-1X9zS3p60AwK-00000017", " montior file= /var/spool/asterisk/monitor/2021/11/16/in-{PBX PHONE NUEBER}-1{INCOMMING PHONE NUEBER}-20211116-082212-1637068932.55.wav") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "1?skipagi") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@macro-hangupcall:7] Hangup("SIP/fpbx-1-1X9zS3p60AwK-00000017", "") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'SIP/fpbx-1-1X9zS3p60AwK-00000017' in macro 'hangupcall'
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Spawn extension (from-pstn, h, 1) exited non-zero on 'SIP/fpbx-1-1X9zS3p60AwK-00000017'
[2021-11-16 08:22:13] VERBOSE[32339][C-0000003b] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2021-11-16 08:22:13] VERBOSE[32339][C-0000003b] app_mixmonitor.c: End MixMonitor Recording SIP/fpbx-1-1X9zS3p60AwK-00000017```
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [{PBX PHONE NUEBER}@from-pstn:6] Gosub("SIP/fpbx-1-1X9zS3p60AwK-00000017", "app-blacklist-check,s,1()") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?blacklisted") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@app-blacklist-check:2] Set("SIP/fpbx-1-1X9zS3p60AwK-00000017", "CALLED_BLACKLIST=1") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@app-blacklist-check:3] Return("SIP/fpbx-1-1X9zS3p60AwK-00000017", "") in new stack

I think what this means is that the call was blacklisted.

Not blacklisted. This part

[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("SIP/fpbx-1-1X9zS3p60AwK-00000017", "0?blacklisted") in new stack

GotoIf is a conditional, and the 0 preceeding the ? tells you the condition failed, so it did not goto the blacklisted destination.

Channel was disconnected immediately after the answer which hints there is something unexpected happening in the sip signaling.

2 Likes

Turn on SIP debug and provide another trace.
https://wiki.freepbx.org/display/SUP/Providing+Great+Debug

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