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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:23] Return("SIP/fpbx-1-1X9zS3p60AwK-00000017", "") in new stack
[2021-11-16 08:22:12] VERBOSE[32338][C-0000003b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:1] Macro("SIP/fpbx-1-1X9zS3p60AwK-00000017", "hangupcall,") in new stack
[2021-11-16 08:22:13] VERBOSE[32338][C-0000003b] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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