I am having this issue recently where sometimes when make a call, the line just rings once, then seems to hang up. I’m not really sure where to start.
I have 4 analog PSTN lines that are connected to an FXO device which then passes on trunks to FreePBX. The log files show all of this for the phone call where this problem occurred. I’m having a problem deciphering this. Any help would be appreciated.
[2013-06-19 18:26:12] VERBOSE[1704] netsock2.c: == Using SIP RTP TOS bits 184
[2013-06-19 18:26:12] VERBOSE[1704] netsock2.c: == Using SIP RTP CoS mark 5
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [4991395@from-internal:1] Macro(“SIP/156-00008492”, “user-callerid,LIMIT,”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/156-00008492”, “AMPUSER=156”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/156-00008492”, “0?report”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/156-00008492”, “1?Set(REALCALLERIDNUM=156)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/156-00008492”, “AMPUSER=156”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/156-00008492”, “AMPUSERCIDNAME=Coach”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/156-00008492”, “0?report”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/156-00008492”, “AMPUSERCID=156”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:8] Set(“SIP/156-00008492”, “CALLERID(all)=“Coach” <156>”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:9] GotoIf(“SIP/156-00008492”, “0?limit”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:10] ExecIf(“SIP/156-00008492”, “1?Set(GROUP(concurrency_limit)=156)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:11] ExecIf(“SIP/156-00008492”, “0?Set(CHANNEL(language)=)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:12] GosubIf(“SIP/156-00008492”, “7?sub-ccss,s,1(from-internal,4991395)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-ccss:1] ExecIf(“SIP/156-00008492”, “0?Return()”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-ccss:2] Set(“SIP/156-00008492”, “CCSS_SETUP=TRUE”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-ccss:3] GosubIf(“SIP/156-00008492”, “0?monitor_config,1(from-internal,4991395):monitor_default,1(from-internal,4991395)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/156-00008492”, “0?is_exten”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [monitor_default@sub-ccss:2] StackPop(“SIP/156-00008492”, “”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [monitor_default@sub-ccss:3] Return(“SIP/156-00008492”, “FALSE”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:13] GotoIf(“SIP/156-00008492”, “1?continue”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Goto (macro-user-callerid,s,26)
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:26] Set(“SIP/156-00008492”, “CALLERID(number)=156”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:27] Set(“SIP/156-00008492”, “CALLERID(name)=Coach”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/156-00008492”, “CHANNEL(language)=en”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [4991395@from-internal:2] Set(“SIP/156-00008492”, “MOHCLASS=default”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [4991395@from-internal:3] Set(“SIP/156-00008492”, “_NODEST=”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [4991395@from-internal:4] Gosub(“SIP/156-00008492”, “sub-record-check,s,1(out,4991395,)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/156-00008492”, “1?check”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Goto (sub-record-check,s,6)
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:6] Set(“SIP/156-00008492”, “__MON_FMT=wav”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:7] GotoIf(“SIP/156-00008492”, “1?next”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Goto (sub-record-check,s,10)
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:10] ExecIf(“SIP/156-00008492”, “0?Return()”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:11] GotoIf(“SIP/156-00008492”, “0?out,1”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/156-00008492”, “__REC_STATUS=INITIALIZED”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/156-00008492”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/156-00008492”, “NOW=1371680772”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/156-00008492”, “__DAY=19”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/156-00008492”, “__MONTH=06”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/156-00008492”, “__YEAR=2013”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/156-00008492”, “__TIMESTR=20130619-182612”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/156-00008492”, “__FROMEXTEN=156”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/156-00008492”, “__CALLFILENAME=out-4991395-156-20130619-182612-1371680772.67466”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@sub-record-check:21] Goto(“SIP/156-00008492”, “out,1”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Goto (sub-record-check,out,1)
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [out@sub-record-check:1] ExecIf(“SIP/156-00008492”, “1?Set(__REC_POLICY_MODE=dontcare)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [out@sub-record-check:2] GosubIf(“SIP/156-00008492”, “0?record,1(exten,4991395,156)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [out@sub-record-check:3] Return(“SIP/156-00008492”, “”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [4991395@from-internal:5] Macro(“SIP/156-00008492”, “dialout-trunk,4,4991395,”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/156-00008492”, “DIAL_TRUNK=4”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/156-00008492”, “0?sub-pincheck,s,1()”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/156-00008492”, “0?disabletrunk,1”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/156-00008492”, “DIAL_NUMBER=4991395”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/156-00008492”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/156-00008492”, “OUTBOUND_GROUP=OUT_4”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/156-00008492”, “1?nomax”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Goto (macro-dialout-trunk,s,9)
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/156-00008492”, “0?skipoutcid”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/156-00008492”, “DIAL_TRUNK_OPTIONS=”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/156-00008492”, “outbound-callerid,4”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/156-00008492”, “0?Set(CALLERPRES()=)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/156-00008492”, “0?Set(REALCALLERIDNUM=156)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/156-00008492”, “1?normcid”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Goto (macro-outbound-callerid,s,6)
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/156-00008492”, “USEROUTCID=”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/156-00008492”, “EMERGENCYCID=”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/156-00008492”, “TRUNKOUTCID=4940707”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/156-00008492”, “1?trunkcid”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Goto (macro-outbound-callerid,s,12)
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/156-00008492”, “1?Set(CALLERID(all)=4940707)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:13] ExecIf(“SIP/156-00008492”, “0?Set(CALLERID(all)=)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/156-00008492”, “0?Set(CALLERID(all)=)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/156-00008492”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/156-00008492”, “0?sub-flp-4,s,1()”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/156-00008492”, “OUTNUM=4991395”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/156-00008492”, “custom=SIP/4940707”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/156-00008492”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default))”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/156-00008492”, “0?Set(DIAL_TRUNK_OPTIONS=M(confirm))”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:17] Macro(“SIP/156-00008492”, “dialout-trunk-predial-hook,”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/156-00008492”, “”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/156-00008492”, “0?bypass,1”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/156-00008492”, “1?Set(CONNECTEDLINE(num,i)=4991395)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/156-00008492”, “1?Set(CONNECTEDLINE(name,i)=CID:4940707)”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:21] GotoIf(“SIP/156-00008492”, “0?customtrunk”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] pbx.c: – Executing [s@macro-dialout-trunk:22] Dial(“SIP/156-00008492”, “SIP/4940707/4991395,300,”) in new stack
[2013-06-19 18:26:12] VERBOSE[12579] netsock2.c: == Using SIP RTP TOS bits 184
[2013-06-19 18:26:12] VERBOSE[12579] netsock2.c: == Using SIP RTP CoS mark 5
[2013-06-19 18:26:12] VERBOSE[12579] app_dial.c: – Called SIP/4940707/4991395
[2013-06-19 18:26:14] VERBOSE[12579] app_dial.c: – SIP/4940707-00008493 is ringing
[2013-06-19 18:26:14] VERBOSE[12579] app_dial.c: – SIP/4940707-00008493 answered SIP/156-00008492
[2013-06-19 18:26:16] VERBOSE[12579] pbx.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/156-00008492”, “hangupcall,”) in new stack
[2013-06-19 18:26:16] VERBOSE[12579] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/156-00008492”, “1?theend”) in new stack
[2013-06-19 18:26:16] VERBOSE[12579] pbx.c: – Goto (macro-hangupcall,s,3)
[2013-06-19 18:26:16] VERBOSE[12579] pbx.c: – Executing [s@macro-hangupcall:3] ExecIf(“SIP/156-00008492”, “0?Set(CDR(recordingfile)=)”) in new stack
[2013-06-19 18:26:16] VERBOSE[12579] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/156-00008492”, “”) in new stack
[2013-06-19 18:26:16] VERBOSE[12579] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/156-00008492’ in macro ‘hangupcall’
[2013-06-19 18:26:16] VERBOSE[12579] features.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/156-00008492’
[2013-06-19 18:26:16] VERBOSE[12579] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on ‘SIP/156-00008492’ in macro ‘dialout-trunk’
[2013-06-19 18:26:16] VERBOSE[12579] pbx.c: == Spawn extension (from-internal, 4991395, 5) exited non-zero on ‘SIP/156-00008492’