Snom 715 phones disconnect after 30 seconds? - resolved

Consistently, whether to voicemail or other extensions the phones hang up after 30 seconds.
Anyone seen this?

Can you provide logs from asterisk CLI?

[2016-01-04 09:56:26] VERBOSE[2015][C-000000d6] netsock2.c: == Using SIP RTP TOS bits 184 [2016-01-04 09:56:26] VERBOSE[2015][C-000000d6] netsock2.c: == Using SIP RTP CoS mark 5 [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@from-internal:1] Macro("SIP/9415-000000e6", "user-callerid,LIMIT") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/9415-000000e6", "TOUCH_MONITOR=1451919386.230") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:2] Set("SIP/9415-000000e6", "AMPUSER=9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:3] GotoIf("SIP/9415-000000e6", "0?report") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:4] ExecIf("SIP/9415-000000e6", "1?Set(REALCALLERIDNUM=9415)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/9415-000000e6", "AMPUSER=9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/9415-000000e6", "0?limit") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/9415-000000e6", "AMPUSERCIDNAME=James x9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:8] GotoIf("SIP/9415-000000e6", "0?report") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:9] Set("SIP/9415-000000e6", "AMPUSERCID=9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:10] Set("SIP/9415-000000e6", "__DIAL_OPTIONS=Ttr") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:11] Set("SIP/9415-000000e6", "CALLERID(all)="James x9415" <9415>") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:12] GotoIf("SIP/9415-000000e6", "0?limit") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:13] ExecIf("SIP/9415-000000e6", "1?Set(GROUP(concurrency_limit)=9415)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:14] GosubIf("SIP/9415-000000e6", "7?sub-ccss,s,1(from-internal,5552221011)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-ccss:1] ExecIf("SIP/9415-000000e6", "0?Return()") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-ccss:2] Set("SIP/9415-000000e6", "CCSS_SETUP=TRUE") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-ccss:3] GosubIf("SIP/9415-000000e6", "0?monitor_config,1(from-internal,5552221011):monitor_default,1(from-internal,5552221011)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [monitor_default@sub-ccss:1] GotoIf("SIP/9415-000000e6", "0?is_exten") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [monitor_default@sub-ccss:2] StackPop("SIP/9415-000000e6", "") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [monitor_default@sub-ccss:3] Return("SIP/9415-000000e6", "FALSE") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:15] ExecIf("SIP/9415-000000e6", "0?Set(CHANNEL(language)=)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:16] GotoIf("SIP/9415-000000e6", "1?continue") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (macro-user-callerid,s,30) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:30] Set("SIP/9415-000000e6", "CALLERID(number)=9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:31] Set("SIP/9415-000000e6", "CALLERID(name)=James x9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:32] Set("SIP/9415-000000e6", "CDR(cnum)=9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:33] Set("SIP/9415-000000e6", "CDR(cnam)=James x9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:34] Set("SIP/9415-000000e6", "CHANNEL(language)=en") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-user-callerid:35] GosubIf("SIP/9415-000000e6", "0?app-check-classofservce,s,1()") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@from-internal:2] Set("SIP/9415-000000e6", "ROUTEUSER=9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@from-internal:3] GotoIf("SIP/9415-000000e6", "1?notblind") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (from-internal,5552221011,6) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@from-internal:6] GotoIf("SIP/9415-000000e6", "1?restrictedroute-c4ca4238a0b923820dcc509a6f75849b,5552221011,2:outbound-allroutes,5552221011,2") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (restrictedroute-c4ca4238a0b923820dcc509a6f75849b,5552221011,2) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@restrictedroute-c4ca4238a0b923820dcc509a6f75849b:2] Gosub("SIP/9415-000000e6", "sub-record-check,s,1(out,5552221011,dontcare)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/9415-000000e6", "0?initialized") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:2] Set("SIP/9415-000000e6", "__REC_STATUS=INITIALIZED") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:3] Set("SIP/9415-000000e6", "NOW=1451919386") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:4] Set("SIP/9415-000000e6", "__DAY=04") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:5] Set("SIP/9415-000000e6", "__MONTH=01") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/9415-000000e6", "__YEAR=2016") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:7] Set("SIP/9415-000000e6", "__TIMESTR=20160104-095626") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:8] Set("SIP/9415-000000e6", "__FROMEXTEN=9415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:9] Set("SIP/9415-000000e6", "__MON_FMT=wav") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:10] NoOp("SIP/9415-000000e6", "Recordings initialized") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:11] ExecIf("SIP/9415-000000e6", "0?Set(ARG3=dontcare)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/9415-000000e6", "REC_POLICY_MODE_SAVE=") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/9415-000000e6", "0?Set(REC_STATUS=NO)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:14] GotoIf("SIP/9415-000000e6", "3?checkaction") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (sub-record-check,s,17) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@sub-record-check:17] GotoIf("SIP/9415-000000e6", "1?sub-record-check,out,1") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (sub-record-check,out,1) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [out@sub-record-check:1] NoOp("SIP/9415-000000e6", "Outbound Recording Check from 9415 to 5552221011") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [out@sub-record-check:2] Set("SIP/9415-000000e6", "RECMODE=dontcare") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [out@sub-record-check:3] ExecIf("SIP/9415-000000e6", "1?Goto(routewins)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (sub-record-check,out,7) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [out@sub-record-check:7] Gosub("SIP/9415-000000e6", "recordcheck,1(dontcare,out,5552221011)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/9415-000000e6", "Starting recording check against dontcare") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [recordcheck@sub-record-check:2] Goto("SIP/9415-000000e6", "dontcare") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (sub-record-check,recordcheck,3) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [recordcheck@sub-record-check:3] Return("SIP/9415-000000e6", "") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [out@sub-record-check:8] Return("SIP/9415-000000e6", "") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@restrictedroute-c4ca4238a0b923820dcc509a6f75849b:3] ExecIf("SIP/9415-000000e6", "0 ?Set(CDR(accountcode)=)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@restrictedroute-c4ca4238a0b923820dcc509a6f75849b:4] Set("SIP/9415-000000e6", "MOHCLASS=default") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@restrictedroute-c4ca4238a0b923820dcc509a6f75849b:5] ExecIf("SIP/9415-000000e6", "0?Set(TRUNKCIDOVERRIDE=<5551119409>)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@restrictedroute-c4ca4238a0b923820dcc509a6f75849b:6] Set("SIP/9415-000000e6", "_NODEST=") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [5552221011@restrictedroute-c4ca4238a0b923820dcc509a6f75849b:7] Macro("SIP/9415-000000e6", "dialout-trunk,2,5552221011,,off") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/9415-000000e6", "DIAL_TRUNK=2") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/9415-000000e6", "0?sub-pincheck,s,1()") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/9415-000000e6", "0?disabletrunk,1") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/9415-000000e6", "DIAL_NUMBER=5552221011") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/9415-000000e6", "DIAL_TRUNK_OPTIONS=Ttr") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/9415-000000e6", "OUTBOUND_GROUP=OUT_2") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/9415-000000e6", "0?nomax") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:8] GotoIf("SIP/9415-000000e6", "0?chanfull") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/9415-000000e6", "0?skipoutcid") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/9415-000000e6", "DIAL_TRUNK_OPTIONS=Tt") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/9415-000000e6", "outbound-callerid,2") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/9415-000000e6", "0?Set(CALLERPRES()=)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/9415-000000e6", "0?Set(REALCALLERIDNUM=9415)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/9415-000000e6", "1?normcid") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (macro-outbound-callerid,s,6) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:6] Set("SIP/9415-000000e6", "USEROUTCID=<5551119415>") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:7] Set("SIP/9415-000000e6", "EMERGENCYCID=") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:8] Set("SIP/9415-000000e6", "TRUNKOUTCID=<5551119409>") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/9415-000000e6", "1?trunkcid") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (macro-outbound-callerid,s,14) [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/9415-000000e6", "1?Set(CALLERID(all)=<5551119409>)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/9415-000000e6", "1?Set(CALLERID(all)=<5551119415>)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:16] ExecIf("SIP/9415-000000e6", "0?Set(CALLERID(all)=)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:17] ExecIf("SIP/9415-000000e6", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:18] Set("SIP/9415-000000e6", "CDR(outbound_cnum)=5551119415") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-outbound-callerid:19] Set("SIP/9415-000000e6", "CDR(outbound_cnam)=") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/9415-000000e6", "0?sub-flp-2,s,1()") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/9415-000000e6", "OUTNUM=5552221011") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/9415-000000e6", "custom=SIP/voip.ms_1") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/9415-000000e6", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/9415-000000e6", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:17] Macro("SIP/9415-000000e6", "dialout-trunk-predial-hook,") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/9415-000000e6", "") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/9415-000000e6", "0?bypass,1") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:19] ExecIf("SIP/9415-000000e6", "1?Set(CONNECTEDLINE(num,i)=5552221011)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:20] ExecIf("SIP/9415-000000e6", "1?Set(CONNECTEDLINE(name,i)=CID:5551119415)") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:21] GotoIf("SIP/9415-000000e6", "0?customtrunk") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-dialout-trunk:22] Dial("SIP/9415-000000e6", "SIP/voip.ms_1/5552221011,300,Tt") in new stack [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] netsock2.c: == Using SIP RTP TOS bits 184 [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] netsock2.c: == Using SIP RTP CoS mark 5 [2016-01-04 09:56:26] VERBOSE[29473][C-000000d6] app_dial.c: -- Called SIP/voip.ms_1/5552221011 [2016-01-04 09:56:30] VERBOSE[29473][C-000000d6] app_dial.c: -- SIP/voip.ms_1-000000e7 is making progress passing it to SIP/9415-000000e6 [2016-01-04 09:56:32] VERBOSE[29473][C-000000d6] app_dial.c: -- SIP/voip.ms_1-000000e7 answered SIP/9415-000000e6 [2016-01-04 09:57:03] NOTICE[2015] chan_sip.c: Disconnecting call 'SIP/9415-000000e6' for lack of RTP activity in 31 seconds [2016-01-04 09:57:03] NOTICE[2015] chan_sip.c: Disconnecting call 'SIP/voip.ms_1-000000e7' for lack of RTP activity in 31 seconds [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [h@macro-dialout-trunk:1] Macro("SIP/9415-000000e6", "hangupcall,") in new stack [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-hangupcall:1] ExecIf("SIP/9415-000000e6", "0?Set(CDR(recordingfile)=.wav)") in new stack [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-hangupcall:2] GotoIf("SIP/9415-000000e6", "1?theend") in new stack [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] pbx.c: -- Goto (macro-hangupcall,s,4) [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] pbx.c: -- Executing [s@macro-hangupcall:4] Hangup("SIP/9415-000000e6", "") in new stack [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/9415-000000e6' in macro 'hangupcall' [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] pbx.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/9415-000000e6' [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'SIP/9415-000000e6' in macro 'dialout-trunk' [2016-01-04 09:57:03] VERBOSE[29473][C-000000d6] pbx.c: == Spawn extension (restrictedroute-c4ca4238a0b923820dcc509a6f75849b, 5552221011, 7) exited non-zero on 'SIP/9415-000000e6'

Here was a recent one.

And here is an internal call. Also, no audio is transmitted using the handsets-I can dial in and get VM message and leave messages, so audio is being passed to the server, but the phones don’t appear to be sending/receiving audio.

[2016-01-04 10:06:48] VERBOSE[2015][C-000000d7] netsock2.c: == Using SIP RTP TOS bits 184
[2016-01-04 10:06:48] VERBOSE[2015][C-000000d7] netsock2.c: == Using SIP RTP CoS mark 5
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [9415@from-internal:1] GotoIf("SIP/9410-000000e8", "1?ext-local,9415,1") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (ext-local,9415,1)
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [9415@ext-local:1] Set("SIP/9410-000000e8", "__RINGTIMER=15") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [9415@ext-local:2] Macro("SIP/9410-000000e8", "exten-vm,9415,9415,0,0,0") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:1] Macro("SIP/9410-000000e8", "user-callerid,") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/9410-000000e8", "TOUCH_MONITOR=1451920008.232") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:2] Set("SIP/9410-000000e8", "AMPUSER=9410") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:3] GotoIf("SIP/9410-000000e8", "0?report") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:4] ExecIf("SIP/9410-000000e8", "1?Set(REALCALLERIDNUM=9410)") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/9410-000000e8", "AMPUSER=9410") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/9410-000000e8", "0?limit") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/9410-000000e8", "AMPUSERCIDNAME=Samantha x9410") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:8] GotoIf("SIP/9410-000000e8", "0?report") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:9] Set("SIP/9410-000000e8", "AMPUSERCID=9410") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:10] Set("SIP/9410-000000e8", "__DIAL_OPTIONS=Ttr") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:11] Set("SIP/9410-000000e8", "CALLERID(all)="Samantha x9410" <9410>") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:12] GotoIf("SIP/9410-000000e8", "0?limit") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:13] ExecIf("SIP/9410-000000e8", "0?Set(GROUP(concurrency_limit)=9410)") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:14] GosubIf("SIP/9410-000000e8", "7?sub-ccss,s,1(macro-exten-vm,9415)") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-ccss:1] ExecIf("SIP/9410-000000e8", "0?Return()") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-ccss:2] Set("SIP/9410-000000e8", "CCSS_SETUP=TRUE") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-ccss:3] GosubIf("SIP/9410-000000e8", "0?monitor_config,1(macro-exten-vm,9415):monitor_default,1(macro-exten-vm,9415)") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [monitor_default@sub-ccss:1] GotoIf("SIP/9410-000000e8", "1?is_exten") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (sub-ccss,monitor_default,4)
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [monitor_default@sub-ccss:4] Set("SIP/9410-000000e8", "CALLCOMPLETION(cc_monitor_policy)=generic") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [monitor_default@sub-ccss:5] Set("SIP/9410-000000e8", "CALLCOMPLETION(cc_max_monitors)=5") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [monitor_default@sub-ccss:6] Return("SIP/9410-000000e8", "TRUE") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-ccss:4] GosubIf("SIP/9410-000000e8", "7?agent_config,1():agent_default,1()") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:1] Set("SIP/9410-000000e8", "CALLCOMPLETION(cc_agent_policy)=generic") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:2] Set("SIP/9410-000000e8", "CALLCOMPLETION(cc_offer_timer)=30") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:3] Set("SIP/9410-000000e8", "CALLCOMPLETION(ccbs_available_timer)=") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:4] Set("SIP/9410-000000e8", "CALLCOMPLETION(ccnr_available_timer)=") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:5] Set("SIP/9410-000000e8", "CALLCOMPLETION(cc_callback_macro)=ccss-default") in new stack
[2016-01-04 10:06:48] WARNING[29931][C-000000d7] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:6] ExecIf("SIP/9410-000000e8", "1?Set(CALLCOMPLETION(cc_recall_timer)=)") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:7] ExecIf("SIP/9410-000000e8", "1?Set(CALLCOMPLETION(cc_max_agents)=)") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:8] ExecIf("SIP/9410-000000e8", "0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/9410_9415@from-ccss-)") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:9] Set("SIP/9410-000000e8", "CALLCOMPLETION(cc_callback_macro)=ccss-default") in new stack
[2016-01-04 10:06:48] WARNING[29931][C-000000d7] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [agent_config@sub-ccss:10] Return("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-ccss:5] Set("SIP/9410-000000e8", "DB(AMPUSER/9410/ccss/last_number)=9415") in new stack
[2016-01-04 10:06:48] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-ccss:6] Return("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:15] ExecIf("SIP/9410-000000e8", "0?Set(CHANNEL(language)=)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:16] GotoIf("SIP/9410-000000e8", "0?continue") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:17] ExecIf("SIP/9410-000000e8", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:18] Set("SIP/9410-000000e8", "__TTL=64") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:19] GotoIf("SIP/9410-000000e8", "1?continue") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (macro-user-callerid,s,30)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:30] Set("SIP/9410-000000e8", "CALLERID(number)=9410") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:31] Set("SIP/9410-000000e8", "CALLERID(name)=Samantha x9410") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:32] Set("SIP/9410-000000e8", "CDR(cnum)=9410") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:33] Set("SIP/9410-000000e8", "CDR(cnam)=Samantha x9410") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:34] Set("SIP/9410-000000e8", "CHANNEL(language)=en") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-user-callerid:35] GosubIf("SIP/9410-000000e8", "0?app-check-classofservce,s,1()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:2] Set("SIP/9410-000000e8", "RingGroupMethod=none") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:3] Set("SIP/9410-000000e8", "__EXTTOCALL=9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:4] Set("SIP/9410-000000e8", "__PICKUPMARK=9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:5] Set("SIP/9410-000000e8", "RT=15") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:6] ExecIf("SIP/9410-000000e8", "0?Macro(vm,9415,DIRECTDIAL,)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:7] ExecIf("SIP/9410-000000e8", "0?MacroExit()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:8] Gosub("SIP/9410-000000e8", "sub-record-check,s,1(exten,9415,dontcare)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/9410-000000e8", "0?initialized") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:2] Set("SIP/9410-000000e8", "__REC_STATUS=INITIALIZED") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:3] Set("SIP/9410-000000e8", "NOW=1451920009") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:4] Set("SIP/9410-000000e8", "__DAY=04") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:5] Set("SIP/9410-000000e8", "__MONTH=01") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/9410-000000e8", "__YEAR=2016") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:7] Set("SIP/9410-000000e8", "__TIMESTR=20160104-100649") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:8] Set("SIP/9410-000000e8", "__FROMEXTEN=9410") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:9] Set("SIP/9410-000000e8", "__MON_FMT=wav") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:10] NoOp("SIP/9410-000000e8", "Recordings initialized") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:11] ExecIf("SIP/9410-000000e8", "0?Set(ARG3=dontcare)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/9410-000000e8", "REC_POLICY_MODE_SAVE=") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/9410-000000e8", "0?Set(REC_STATUS=NO)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:14] GotoIf("SIP/9410-000000e8", "5?checkaction") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (sub-record-check,s,17)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-record-check:17] GotoIf("SIP/9410-000000e8", "1?sub-record-check,exten,1") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (sub-record-check,exten,1)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:1] NoOp("SIP/9410-000000e8", "Exten Recording Check between 9410 and 9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:2] Set("SIP/9410-000000e8", "CALLTYPE=internal") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:3] ExecIf("SIP/9410-000000e8", "0?Set(CALLTYPE=)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:4] Set("SIP/9410-000000e8", "CALLEE=dontcare") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:5] ExecIf("SIP/9410-000000e8", "0?Set(CALLEE=dontcare)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:6] GotoIf("SIP/9410-000000e8", "0?callee") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:7] GotoIf("SIP/9410-000000e8", "1?caller") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (sub-record-check,exten,13)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:13] Set("SIP/9410-000000e8", "RECMODE=dontcare") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:14] ExecIf("SIP/9410-000000e8", "0?Set(RECMODE=dontcare)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:15] ExecIf("SIP/9410-000000e8", "1?Set(RECMODE=dontcare)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:16] Gosub("SIP/9410-000000e8", "recordcheck,1(dontcare,internal,9415)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/9410-000000e8", "Starting recording check against dontcare") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [recordcheck@sub-record-check:2] Goto("SIP/9410-000000e8", "dontcare") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (sub-record-check,recordcheck,3)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [recordcheck@sub-record-check:3] Return("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [exten@sub-record-check:17] Return("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:9] GotoIf("SIP/9410-000000e8", "1?macrodial") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (macro-exten-vm,s,15)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:15] GosubIf("SIP/9410-000000e8", "0?clrheader,1()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-exten-vm:16] Macro("SIP/9410-000000e8", "dial-one,15,Ttr,9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:1] Set("SIP/9410-000000e8", "DEXTEN=9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:2] Set("SIP/9410-000000e8", "DIALSTATUS_CW=") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:3] GosubIf("SIP/9410-000000e8", "0?screen,1()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:4] GosubIf("SIP/9410-000000e8", "0?cf,1()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:5] GotoIf("SIP/9410-000000e8", "1?skip1") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (macro-dial-one,s,8)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:8] GotoIf("SIP/9410-000000e8", "0?nodial") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:9] GotoIf("SIP/9410-000000e8", "0?continue") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:10] Set("SIP/9410-000000e8", "EXTHASCW=ENABLED") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:11] GotoIf("SIP/9410-000000e8", "0?next1:cwinusebusy") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (macro-dial-one,s,23)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:23] GotoIf("SIP/9410-000000e8", "1?next3:continue") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (macro-dial-one,s,24)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:24] ExecIf("SIP/9410-000000e8", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:25] GotoIf("SIP/9410-000000e8", "0?nodial") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:26] GosubIf("SIP/9410-000000e8", "1?dstring,1():dlocal,1()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:1] Set("SIP/9410-000000e8", "DSTRING=") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:2] Set("SIP/9410-000000e8", "DEVICES=9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/9410-000000e8", "0?Return()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:4] ExecIf("SIP/9410-000000e8", "0?Set(DEVICES=415)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:5] Set("SIP/9410-000000e8", "LOOPCNT=1") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:6] Set("SIP/9410-000000e8", "ITER=1") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:7] Set("SIP/9410-000000e8", "THISDIAL=SIP/9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/9410-000000e8", "1?zap2dahdi,1()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/9410-000000e8", "0?Return()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/9410-000000e8", "NEWDIAL=") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/9410-000000e8", "LOOPCNT2=1") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/9410-000000e8", "ITER2=1") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/9410-000000e8", "THISPART2=SIP/9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/9410-000000e8", "0?Set(THISPART2=DAHDI/9415)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/9410-000000e8", "NEWDIAL=SIP/9415&") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/9410-000000e8", "ITER2=2") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/9410-000000e8", "0?begin2") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/9410-000000e8", "THISDIAL=SIP/9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:9] GotoIf("SIP/9410-000000e8", "1?doset") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (macro-dial-one,dstring,13)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:13] Set("SIP/9410-000000e8", "DSTRING=SIP/9415&") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:14] Set("SIP/9410-000000e8", "ITER=2") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:15] GotoIf("SIP/9410-000000e8", "0?begin") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:16] ExecIf("SIP/9410-000000e8", "0?Return()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:17] Set("SIP/9410-000000e8", "DSTRING=SIP/9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [dstring@macro-dial-one:18] Return("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:27] GotoIf("SIP/9410-000000e8", "0?nodial") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:28] GotoIf("SIP/9410-000000e8", "0?skiptrace") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:29] GosubIf("SIP/9410-000000e8", "1?ctset,1():ctclear,1()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [ctset@macro-dial-one:1] Set("SIP/9410-000000e8", "DB(CALLTRACE/9415)=9410") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [ctset@macro-dial-one:2] Return("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:30] Set("SIP/9410-000000e8", "D_OPTIONS=Ttr") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:31] ExecIf("SIP/9410-000000e8", "0?SIPAddHeader(Alert-Info: )") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:32] ExecIf("SIP/9410-000000e8", "0?SIPAddHeader()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:33] ExecIf("SIP/9410-000000e8", "0?Set(CHANNEL(musicclass)=)") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:34] GosubIf("SIP/9410-000000e8", "0?qwait,1()") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:35] Set("SIP/9410-000000e8", "__CWIGNORE=") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:36] Set("SIP/9410-000000e8", "__KEEPCID=TRUE") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:37] GotoIf("SIP/9410-000000e8", "0?usegoto,1") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:38] GotoIf("SIP/9410-000000e8", "0?godial") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:39] Gosub("SIP/9410-000000e8", "sub-presencestate-display,s,1(9415)") in new stack
[2016-01-04 10:06:49] WARNING[29931][C-000000d7] func_presencestate.c: PRESENCE_STATE unknown
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@sub-presencestate-display:1] Goto("SIP/9410-000000e8", "state-,1") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (sub-presencestate-display,state-,1)
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [state-@sub-presencestate-display:1] Set("SIP/9410-000000e8", "PRESENCESTATE_DISPLAY=") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [state-@sub-presencestate-display:2] Return("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:40] Set("SIP/9410-000000e8", "CONNECTEDLINE(name,i)=James x9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:41] Set("SIP/9410-000000e8", "CONNECTEDLINE(num)=9415") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:42] Set("SIP/9410-000000e8", "D_OPTIONS=TtrI") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:43] Macro("SIP/9410-000000e8", "dialout-one-predial-hook,") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dialout-one-predial-hook:1] MacroExit("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-dial-one:44] Dial("SIP/9410-000000e8", "SIP/9415,15,TtrI") in new stack
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] netsock2.c: == Using SIP RTP TOS bits 184
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] netsock2.c: == Using SIP RTP CoS mark 5
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] app_dial.c: -- Called SIP/9415
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] app_dial.c: -- Connected line update to SIP/9410-000000e8 prevented.
[2016-01-04 10:06:49] VERBOSE[29931][C-000000d7] app_dial.c: -- SIP/9415-000000e9 is ringing
[2016-01-04 10:06:50] VERBOSE[29931][C-000000d7] app_dial.c: -- SIP/9415-000000e9 is ringing
[2016-01-04 10:06:51] VERBOSE[29931][C-000000d7] app_dial.c: -- SIP/9415-000000e9 is ringing
[2016-01-04 10:06:53] VERBOSE[29931][C-000000d7] app_dial.c: -- SIP/9415-000000e9 is ringing
[2016-01-04 10:06:57] VERBOSE[29931][C-000000d7] app_dial.c: -- SIP/9415-000000e9 is ringing
[2016-01-04 10:06:57] VERBOSE[29931][C-000000d7] app_dial.c: -- Connected line update to SIP/9410-000000e8 prevented.
[2016-01-04 10:06:57] VERBOSE[29931][C-000000d7] app_dial.c: -- SIP/9415-000000e9 answered SIP/9410-000000e8
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [h@macro-dial-one:1] Macro("SIP/9410-000000e8", "hangupcall,") in new stack
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-hangupcall:1] ExecIf("SIP/9410-000000e8", "0?Set(CDR(recordingfile)=.wav)") in new stack
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-hangupcall:2] GotoIf("SIP/9410-000000e8", "1?theend") in new stack
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] pbx.c: -- Goto (macro-hangupcall,s,4)
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] pbx.c: -- Executing [s@macro-hangupcall:4] Hangup("SIP/9410-000000e8", "") in new stack
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/9410-000000e8' in macro 'hangupcall'
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] pbx.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on 'SIP/9410-000000e8'
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] app_macro.c: == Spawn extension (macro-dial-one, s, 44) exited non-zero on 'SIP/9410-000000e8' in macro 'dial-one'
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] app_macro.c: == Spawn extension (macro-exten-vm, s, 16) exited non-zero on 'SIP/9410-000000e8' in macro 'exten-vm'
[2016-01-04 10:07:06] VERBOSE[29931][C-000000d7] pbx.c: == Spawn extension (ext-local, 9415, 2) exited non-zero on 'SIP/9410-000000e8'

Also- its definitely specific to the Snom phones: the Polycoms behave as expected.

Okay- so the line to flag is:

So my next question is WHY is no RTP traffic being passed? I think if I hit that nail, then I’m ok for my other issues.

So this was caused by the phones resetting to the wrong VLAN and not working properly from there. When on the proper VLAN they work fine (now to figure out how to get EPM to fix that issue).