Dropped calls

clyde277 · August 24, 2018, 6:25pm

Hi there

I am having some significant issues with some random dropped calls. Specifically from some conference phones that we use. I have here some logs from freepbx. No sure if this is going to help, but I can also do a packet trace if it’s needed. Briefly about my setup: I am using Mikrotik queuing and Mangle. Recently I have added some firewall rules regarding some vulnerabilities that mikrotik have, but not sure if that has affected anything. Here is the log from asterisk from the call initiation until it dropped:

2018-08-24 13:02:34] VERBOSE[2149][C-00000183] netsock2.c: == Using SIP RTP TOS bits 184
[2018-08-24 13:02:34] VERBOSE[2149][C-00000183] netsock2.c: == Using SIP RTP CoS mark 5
[2018-08-24 13:02:34] SECURITY[2100] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“1535133754-641794”,Severity=“Informational”,Service=“SIP”,EventVersion=“1”,AccountID=“6506673621”,SessionID=“0x3cc3018”,LocalAddress=“IPV4/UDP/162.221.91.219/5060”,RemoteAddress=“IPV4/UDP/50.234.75.46/1040”,UsingPassword=“1”
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@from-internal:1] Macro(“SIP/226-00000273”, “user-callerid,LIMIT”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/226-00000273”, “TOUCH_MONITOR=1535133754.699”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/226-00000273”, “AMPUSER=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/226-00000273”, “0?report”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/226-00000273”, “1?Set(REALCALLERIDNUM=226)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/226-00000273”, “AMPUSER=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/226-00000273”, “0?limit”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/226-00000273”, "AMPUSERCIDNAME=Sweet Potato Huddle Room ") in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:8] ExecIf(“SIP/226-00000273”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:9] GotoIf(“SIP/226-00000273”, “0?report”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:10] Set(“SIP/226-00000273”, “AMPUSERCID=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/226-00000273”, “__DIAL_OPTIONS=Ttr”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:12] Set(“SIP/226-00000273”, "CALLERID(all)=“Sweet Potato Huddle Room " <226>”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:13] GotoIf(“SIP/226-00000273”, “0?limit”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:14] ExecIf(“SIP/226-00000273”, “1?Set(GROUP(concurrency_limit)=226)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:15] ExecIf(“SIP/226-00000273”, “0?Set(CHANNEL(language)=)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:16] NoOp(“SIP/226-00000273”, “Macro Depth is 1”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:17] GotoIf(“SIP/226-00000273”, “1?report2:macroerror”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (macro-user-callerid,s,18)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:18] GotoIf(“SIP/226-00000273”, “1?continue”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (macro-user-callerid,s,37)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:37] Set(“SIP/226-00000273”, “CALLERID(number)=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:38] Set(“SIP/226-00000273”, "CALLERID(name)=Sweet Potato Huddle Room ") in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:39] GotoIf(“SIP/226-00000273”, “0?cnum”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:40] Set(“SIP/226-00000273”, “CDR(cnam)=Sweet Potato Huddle Room”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:41] Set(“SIP/226-00000273”, “CDR(cnum)=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-user-callerid:42] Set(“SIP/226-00000273”, “CHANNEL(language)=en”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@from-internal:2] Set(“SIP/226-00000273”, “ROUTEUSER=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@from-internal:3] Set(“SIP/226-00000273”, “ROUTEUSER=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@from-internal:4] GotoIf(“SIP/226-00000273”, “1?notblind”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (from-internal,6506673621,7)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@from-internal:7] GotoIf(“SIP/226-00000273”, “1?restrictedroute-c81e728d9d4c2f636f067f89cc14862c,6506673621,2:outbound-allroutes,6506673621,2”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (restrictedroute-c81e728d9d4c2f636f067f89cc14862c,6506673621,2)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@restrictedroute-c81e728d9d4c2f636f067f89cc14862c:2] Gosub(“SIP/226-00000273”, “sub-record-check,s,1(out,6506673621,dontcare)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/226-00000273”, “0?initialized”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:2] Set(“SIP/226-00000273”, “__REC_STATUS=INITIALIZED”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:3] Set(“SIP/226-00000273”, “NOW=1535133754”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:4] Set(“SIP/226-00000273”, “__DAY=24”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:5] Set(“SIP/226-00000273”, “__MONTH=08”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:6] Set(“SIP/226-00000273”, “__YEAR=2018”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/226-00000273”, “__TIMESTR=20180824-130234”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:8] Set(“SIP/226-00000273”, “__FROMEXTEN=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:9] Set(“SIP/226-00000273”, “__MON_FMT=wav”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:10] NoOp(“SIP/226-00000273”, “Recordings initialized”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/226-00000273”, “0?Set(ARG3=dontcare)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/226-00000273”, “REC_POLICY_MODE_SAVE=”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/226-00000273”, “0?Set(REC_STATUS=NO)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:14] GotoIf(“SIP/226-00000273”, “3?checkaction”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (sub-record-check,s,17)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@sub-record-check:17] GotoIf(“SIP/226-00000273”, “1?sub-record-check,out,1”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (sub-record-check,out,1)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [out@sub-record-check:1] NoOp(“SIP/226-00000273”, “Outbound Recording Check from 226 to 6506673621”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [out@sub-record-check:2] Set(“SIP/226-00000273”, “RECMODE=dontcare”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [out@sub-record-check:3] ExecIf(“SIP/226-00000273”, “1?Goto(routewins)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (sub-record-check,out,7)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [out@sub-record-check:7] Gosub(“SIP/226-00000273”, “recordcheck,1(dontcare,out,6506673621)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/226-00000273”, “Starting recording check against dontcare”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/226-00000273”, “dontcare”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/226-00000273”, “”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [out@sub-record-check:8] Return(“SIP/226-00000273”, “”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@restrictedroute-c81e728d9d4c2f636f067f89cc14862c:3] ExecIf(“SIP/226-00000273”, “0 ?Set(CDR(accountcode)=)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@restrictedroute-c81e728d9d4c2f636f067f89cc14862c:4] Set(“SIP/226-00000273”, “MOHCLASS=default”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@restrictedroute-c81e728d9d4c2f636f067f89cc14862c:5] ExecIf(“SIP/226-00000273”, “1?Set(TRUNKCIDOVERRIDE=<7734926327>)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@restrictedroute-c81e728d9d4c2f636f067f89cc14862c:6] Set(“SIP/226-00000273”, “_NODEST=”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [6506673621@restrictedroute-c81e728d9d4c2f636f067f89cc14862c:7] Macro(“SIP/226-00000273”, “dialout-trunk,2,16506673621,off”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/226-00000273”, “DIAL_TRUNK=2”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:2] ExecIf(“SIP/226-00000273”, “0?Set(DIAL_OPTIONS=tr)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:3] GosubIf(“SIP/226-00000273”, “0?sub-pincheck,s,1()”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:4] GotoIf(“SIP/226-00000273”, “0?disabletrunk,1”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/226-00000273”, “DIAL_NUMBER=16506673621”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/226-00000273”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:7] Set(“SIP/226-00000273”, “OUTBOUND_GROUP=OUT_2”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:8] Set(“SIP/226-00000273”, “DIAL_TRUNK_OPTIONS=T”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/226-00000273”, “1?nomax”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (macro-dialout-trunk,s,11)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:11] GotoIf(“SIP/226-00000273”, “0?skipoutcid”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:12] Macro(“SIP/226-00000273”, “outbound-callerid,2”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/226-00000273”, “0?Set(CALLERPRES(name-pres)=)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/226-00000273”, “0?Set(CALLERPRES(num-pres)=)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:3] ExecIf(“SIP/226-00000273”, “0?Set(REALCALLERIDNUM=226)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:4] ExecIf(“SIP/226-00000273”, “0?Set(AMPUSER=226)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:5] GotoIf(“SIP/226-00000273”, “1?normcid”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (macro-outbound-callerid,s,9)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:9] Set(“SIP/226-00000273”, “USEROUTCID=”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:10] Set(“SIP/226-00000273”, “EMERGENCYCID=”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:11] Set(“SIP/226-00000273”, “TRUNKOUTCID=”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:12] GotoIf(“SIP/226-00000273”, “1?trunkcid”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Goto (macro-outbound-callerid,s,17)
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:17] ExecIf(“SIP/226-00000273”, “0?Set(CALLERID(all)=)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:18] ExecIf(“SIP/226-00000273”, “0?Set(CALLERID(all)=)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:19] ExecIf(“SIP/226-00000273”, “1?Set(CALLERID(all)=<7734926327>)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:20] ExecIf(“SIP/226-00000273”, “0?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:21] ExecIf(“SIP/226-00000273”, “0?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:22] Set(“SIP/226-00000273”, “CDR(outbound_cnum)=7734926327”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-outbound-callerid:23] Set(“SIP/226-00000273”, “CDR(outbound_cnam)=”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:13] GosubIf(“SIP/226-00000273”, “0?sub-flp-2,s,1()”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/226-00000273”, “OUTNUM=16506673621”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:15] Set(“SIP/226-00000273”, “custom=SIP/FlowRoute”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/226-00000273”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:17] ExecIf(“SIP/226-00000273”, “0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:18] Macro(“SIP/226-00000273”, “dialout-trunk-predial-hook,”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/226-00000273”, “”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:19] GotoIf(“SIP/226-00000273”, “0?skipcrm”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:20] Set(“SIP/226-00000273”, “__CRM_DIRECTION=OUTBOUND”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:21] Set(“SIP/226-00000273”, “__CRM_DESTINATION=16506673621”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:22] Set(“SIP/226-00000273”, “__CRM_SOURCE=226”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:23] AGI(“SIP/226-00000273”, “sangomacrm.agi”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] res_agi.c: – <SIP/226-00000273>AGI Script sangomacrm.agi completed, returning 0
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:24] Set(“SIP/226-00000273”, “CHANNEL(hangup_handler_push)=crm-hangup,s,1”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:25] NoOp(“SIP/226-00000273”, “CRM Finished”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:26] GotoIf(“SIP/226-00000273”, “0?bypass,1”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:27] ExecIf(“SIP/226-00000273”, “1?Set(CONNECTEDLINE(num,i)=16506673621)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:28] ExecIf(“SIP/226-00000273”, “1?Set(CONNECTEDLINE(name,i)=CID:7734926327)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:29] ExecIf(“SIP/226-00000273”, “0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)7734926327)”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:30] GotoIf(“SIP/226-00000273”, “0?customtrunk”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] pbx.c: – Executing [s@macro-dialout-trunk:31] Dial(“SIP/226-00000273”, “SIP/FlowRoute/16506673621,300,T”) in new stack
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] netsock2.c: == Using SIP RTP TOS bits 184
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] netsock2.c: == Using SIP RTP CoS mark 5
[2018-08-24 13:02:34] VERBOSE[29627][C-00000183] app_dial.c: – Called SIP/FlowRoute/16506673621
[2018-08-24 13:02:36] VERBOSE[29627][C-00000183] app_dial.c: – SIP/FlowRoute-00000274 is making progress passing it to SIP/226-00000273
[2018-08-24 13:02:36] VERBOSE[29627][C-00000183] app_dial.c: – SIP/FlowRoute-00000274 answered SIP/226-00000273
[2018-08-24 13:02:39] VERBOSE[29381][C-00000182] file.c: – <SIP/FlowRoute-00000271> Playing ‘vm-intro.ulaw’ (language ‘en’)
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF begin ‘4’ received on SIP/226-00000273
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘4’ on SIP/226-00000273
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF end ‘4’ received on SIP/226-00000273, duration 260 ms
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘4’ on SIP/226-00000273
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘4’ on SIP/226-00000273
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF begin ‘6’ received on SIP/226-00000273
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘6’ on SIP/226-00000273
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF end ‘6’ received on SIP/226-00000273, duration 220 ms
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘6’ on SIP/226-00000273
[2018-08-24 13:02:42] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘6’ on SIP/226-00000273
[2018-08-24 13:02:44] DTMF[29627][C-00000183] channel.c: DTMF begin ‘2’ received on SIP/226-00000273
[2018-08-24 13:02:44] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘2’ on SIP/226-00000273
[2018-08-24 13:02:44] DTMF[29627][C-00000183] channel.c: DTMF end ‘2’ received on SIP/226-00000273, duration 280 ms
[2018-08-24 13:02:44] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘2’ on SIP/226-00000273
[2018-08-24 13:02:44] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘2’ on SIP/226-00000273
[2018-08-24 13:02:45] VERBOSE[29381][C-00000182] file.c: – <SIP/FlowRoute-00000271> Playing ‘beep.ulaw’ (language ‘en’)
[2018-08-24 13:02:45] DTMF[29627][C-00000183] channel.c: DTMF begin ‘7’ received on SIP/226-00000273
[2018-08-24 13:02:45] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘7’ on SIP/226-00000273
[2018-08-24 13:02:45] VERBOSE[29381][C-00000182] app_voicemail.c: – Recording the message
[2018-08-24 13:02:45] VERBOSE[29381][C-00000182] app.c: – x=0, open writing: /var/spool/asterisk/voicemail/default/209/tmp/OJoicA format: wav, 0x2a2c1e8
[2018-08-24 13:02:45] DTMF[29627][C-00000183] channel.c: DTMF end ‘7’ received on SIP/226-00000273, duration 240 ms
[2018-08-24 13:02:45] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘7’ on SIP/226-00000273
[2018-08-24 13:02:45] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘7’ on SIP/226-00000273
[2018-08-24 13:02:45] DTMF[29627][C-00000183] channel.c: DTMF begin ‘9’ received on SIP/226-00000273
[2018-08-24 13:02:45] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘9’ on SIP/226-00000273
[2018-08-24 13:02:46] DTMF[29627][C-00000183] channel.c: DTMF end ‘9’ received on SIP/226-00000273, duration 260 ms
[2018-08-24 13:02:46] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘9’ on SIP/226-00000273
[2018-08-24 13:02:46] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘9’ on SIP/226-00000273
[2018-08-24 13:02:46] DTMF[29627][C-00000183] channel.c: DTMF begin ‘8’ received on SIP/226-00000273
[2018-08-24 13:02:46] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘8’ on SIP/226-00000273
[2018-08-24 13:02:46] DTMF[29627][C-00000183] channel.c: DTMF end ‘8’ received on SIP/226-00000273, duration 360 ms
[2018-08-24 13:02:46] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘8’ on SIP/226-00000273
[2018-08-24 13:02:46] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘8’ on SIP/226-00000273
[2018-08-24 13:02:47] DTMF[29627][C-00000183] channel.c: DTMF begin ‘7’ received on SIP/226-00000273
[2018-08-24 13:02:47] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘7’ on SIP/226-00000273
[2018-08-24 13:02:47] DTMF[29627][C-00000183] channel.c: DTMF end ‘7’ received on SIP/226-00000273, duration 240 ms
[2018-08-24 13:02:47] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘7’ on SIP/226-00000273
[2018-08-24 13:02:47] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘7’ on SIP/226-00000273
[2018-08-24 13:02:47] DTMF[29627][C-00000183] channel.c: DTMF begin ‘5’ received on SIP/226-00000273
[2018-08-24 13:02:47] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘5’ on SIP/226-00000273
[2018-08-24 13:02:48] DTMF[29627][C-00000183] channel.c: DTMF end ‘5’ received on SIP/226-00000273, duration 260 ms
[2018-08-24 13:02:48] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘5’ on SIP/226-00000273
[2018-08-24 13:02:48] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘5’ on SIP/226-00000273
[2018-08-24 13:02:48] DTMF[29627][C-00000183] channel.c: DTMF begin ‘0’ received on SIP/226-00000273
[2018-08-24 13:02:48] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘0’ on SIP/226-00000273
[2018-08-24 13:02:48] DTMF[29627][C-00000183] channel.c: DTMF end ‘0’ received on SIP/226-00000273, duration 340 ms
[2018-08-24 13:02:48] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘0’ on SIP/226-00000273
[2018-08-24 13:02:48] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘0’ on SIP/226-00000273
[2018-08-24 13:02:49] DTMF[29627][C-00000183] channel.c: DTMF begin ‘#’ received on SIP/226-00000273
[2018-08-24 13:02:49] DTMF[29627][C-00000183] channel.c: DTMF begin passthrough ‘#’ on SIP/226-00000273
[2018-08-24 13:02:49] DTMF[29627][C-00000183] channel.c: DTMF end ‘#’ received on SIP/226-00000273, duration 200 ms
[2018-08-24 13:02:49] DTMF[29627][C-00000183] channel.c: DTMF end accepted with begin ‘#’ on SIP/226-00000273
[2018-08-24 13:02:49] DTMF[29627][C-00000183] channel.c: DTMF end passthrough ‘#’ on SIP/226-00000273
[2018-08-24 13:02:59] SECURITY[2100] res_security_log.c: SecurityEvent=“ChallengeSent”,EventTV=“1535133779-95006”,Severity=“Informational”,Service=“SIP”,EventVersion=“1”,AccountID=“223”,SessionID=“0x3d02a48”,LocalAddress=“IPV4/UDP/162.221.91.219/5060”,RemoteAddress=“IPV4/UDP/50.234.75.46/5060”,Challenge=“09695a06”
[2018-08-24 13:02:59] SECURITY[2100] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“1535133779-119584”,Severity=“Informational”,Service=“SIP”,EventVersion=“1”,AccountID=“223”,SessionID=“0x3d02a48”,LocalAddress=“IPV4/UDP/162.221.91.219/5060”,RemoteAddress=“IPV4/UDP/50.234.75.46/5060”,UsingPassword=“1”
[2018-08-24 13:03:00] SECURITY[2100] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“1535133780-34679”,Severity=“Informational”,Service=“AMI”,EventVersion=“1”,AccountID=“admin”,SessionID=“0x267cd18”,LocalAddress=“IPV4/TCP/0.0.0.0/5038”,RemoteAddress=“IPV4/TCP/127.0.0.1/58024”,UsingPassword=“0”,SessionTV=“1535133780-34673”
[2018-08-24 13:03:01] SECURITY[2100] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“1535133781-750491”,Severity=“Informational”,Service=“AMI”,EventVersion=“1”,AccountID=“admin”,SessionID=“0x267cd18”,LocalAddress=“IPV4/TCP/0.0.0.0/5038”,RemoteAddress=“IPV4/TCP/127.0.0.1/58028”,UsingPassword=“0”,SessionTV=“1535133781-750484”
[2018-08-24 13:03:02] SECURITY[2100] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“1535133782-142539”,Severity=“Informational”,Service=“AMI”,EventVersion=“1”,AccountID=“admin”,SessionID=“0x2ac0c38”,LocalAddress=“IPV4/TCP/0.0.0.0/5038”,RemoteAddress=“IPV4/TCP/127.0.0.1/58032”,UsingPassword=“0”,SessionTV=“1535133782-142530”
[2018-08-24 13:03:02] SECURITY[2100] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“1535133782-347223”,Severity=“Informational”,Service=“AMI”,EventVersion=“1”,AccountID=“admin”,SessionID=“0x267cd18”,LocalAddress=“IPV4/TCP/0.0.0.0/5038”,RemoteAddress=“IPV4/TCP/127.0.0.1/58036”,UsingPassword=“0”,SessionTV=“1535133782-347209”
[2018-08-24 13:03:12] VERBOSE[29381][C-00000182] app.c: – User hung up
[2018-08-24 13:03:12] VERBOSE[29381][C-00000182] config.c: == Parsing ‘/var/spool/asterisk/voicemail/default/209/INBOX/msg0009.txt’: Found
[2018-08-24 13:03:12] VERBOSE[29381][C-00000182] config.c: == Parsing ‘/var/spool/asterisk/voicemail/default/209/INBOX/msg0009.txt’: Found
[2018-08-24 13:03:12] VERBOSE[29381][C-00000182] config.c: == Parsing ‘/var/spool/asterisk/voicemail/default/209/INBOX/msg0009.txt’: Found
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] app_macro.c: == Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘SIP/FlowRoute-00000271’ in macro ‘vm’
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: == Spawn extension (ext-local, 209, 4) exited non-zero on ‘SIP/FlowRoute-00000271’
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [h@ext-local:1] Macro(“SIP/FlowRoute-00000271”, “hangupcall,”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@macro-hangupcall:1] ExecIf(“SIP/FlowRoute-00000271”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@macro-hangupcall:2] GotoIf(“SIP/FlowRoute-00000271”, “1?theend”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Goto (macro-hangupcall,s,4)
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@macro-hangupcall:4] ExecIf(“SIP/FlowRoute-00000271”, “0?Set(CDR(recordingfile)=)”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@macro-hangupcall:5] Hangup(“SIP/FlowRoute-00000271”, “”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] app_macro.c: == Spawn extension (macro-hangupcall, s, 5) exited non-zero on ‘SIP/FlowRoute-00000271’ in macro ‘hangupcall’
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: == Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/FlowRoute-00000271’
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] app_stack.c: – SIP/FlowRoute-00000271 Internal Gosub(crm-hangup,s,1) start
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@crm-hangup:1] NoOp(“SIP/FlowRoute-00000271”, “Sending Hangup to CRM”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@crm-hangup:2] NoOp(“SIP/FlowRoute-00000271”, “HANGUP CAUSE: 16”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@crm-hangup:3] ExecIf(“SIP/FlowRoute-00000271”, “1?Set(__CRM_VOICEMAIL=SUCCESS)”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@crm-hangup:4] NoOp(“SIP/FlowRoute-00000271”, “MASTER CHANNEL: 1535133697.697 = 1535133697.697”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@crm-hangup:5] GotoIf(“SIP/FlowRoute-00000271”, “0?return”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@crm-hangup:6] Set(“SIP/FlowRoute-00000271”, “__CRM_HANGUP=1”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@crm-hangup:7] AGI(“SIP/FlowRoute-00000271”, “sangomacrm.agi”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2018-08-24 13:03:13] SECURITY[2100] res_security_log.c: SecurityEvent=“SuccessfulAuth”,EventTV=“1535133793-174813”,Severity=“Informational”,Service=“AMI”,EventVersion=“1”,AccountID=“admin”,SessionID=“0x267cd18”,LocalAddress=“IPV4/TCP/0.0.0.0/5038”,RemoteAddress=“IPV4/TCP/127.0.0.1/58042”,UsingPassword=“0”,SessionTV=“1535133793-174808”
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] res_agi.c: – <SIP/FlowRoute-00000271>AGI Script sangomacrm.agi completed, returning 0
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] pbx.c: – Executing [s@crm-hangup:8] Return(“SIP/FlowRoute-00000271”, “”) in new stack
[2018-08-24 13:03:13] VERBOSE[29381][C-00000182] app_stack.c: == Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/FlowRoute-00000271’

clyde277 · August 24, 2018, 9:05pm

okay, so I also have some logs from CDR:

Time Event CNAM CNUM ANI DID AMA exten context App channel UserDefType EventExtra
2018-08-24 13:02:34 CHAN_START Sweet Potato Huddle Room 226 DEFAULT 6506673621 from-internal SIP/226-00000273
2018-08-24 13:02:34 CHAN_START DEFAULT s from-trunk SIP/FlowRoute-00000274
2018-08-24 13:02:36 ANSWER CID:7734926327 6506673621 DEFAULT 6506673621 from-trunk AppDial SIP/FlowRoute-00000274
2018-08-24 13:02:36 ANSWER 7734926327 226 6506673621 DEFAULT s macro-dialout-trunk Dial SIP/226-00000273
2018-08-24 13:02:36 BRIDGE_START 7734926327 226 6506673621 DEFAULT s macro-dialout-trunk Dial SIP/226-00000273
2018-08-24 13:05:09 BRIDGE_END 7734926327 226 6506673621 DEFAULT s macro-dialout-trunk Dial SIP/226-00000273
2018-08-24 13:05:09 HANGUP CID:7734926327 6506673621 DEFAULT macro-dialout-trunk AppDial SIP/FlowRoute-00000274
2018-08-24 13:05:09 CHAN_END CID:7734926327 6506673621 DEFAULT macro-dialout-trunk AppDial SIP/FlowRoute-00000274
2018-08-24 13:05:09 HANGUP 7734926327 226 6506673621 DEFAULT 6506673621 restrictedroute-c81e728d9d4c2f636f067f89cc14862c SIP/226-00000273
2018-08-24 13:05:09 CHAN_END 7734926327 226 6506673621 DEFAULT 6506673621 restrictedroute-c81e728d9d4c2f636f067f89cc14862c SIP/226-00000273
2018-08-24 13:05:09 LINKEDID_END 7734926327 226 6506673621 DEFAULT 6506673621 restrictedroute-c81e728d9d4c2f636f067f89cc14862c SIP/226-00000273

what is this restrictedroute-c81e728d9d4c2f636f067f89cc14862c SIP/226-00000273 about?
I use Extension route btw, is this related to that?

cynjut · August 27, 2018, 1:16pm

How are you using “Extension Route”?

Normally, a restricted route is one that you’ve configured to require things like PINs or specific extensions to be able to access. If you search through the archive of the forums, you’ll find plenty of cases where people have set up their systems like this, plus instructions on how to fix the problem.

clyde277 · August 27, 2018, 1:35pm

Hi Dave,

The reason why I use Extension Route is because I have multiple phone number numbers, inbound/outbound and I don’t want to mix up all my extensions into only on number. This module has been working well for the past year, and it seems odd to me that this module would contribute into a drop call, since the call has been established and extension route has certainly done its job in the first place. I have looked through pbx forums, but I haven’t found anything promising to be honest.

system · August 27, 2019, 1:35pm

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