Remote extension drops calls. "no reply to our critical packet"

pehelpdesk · October 16, 2013, 7:01pm

I have a remote extension that is located in a residential area. The ISP for the location is Comcast.

When I dial the extension from my office, I either get a busy signal or straight to voicemail. Below are excerpt of the logs for when I call the extension from my office and when the remote extension calls me: Full logs at bottom of post.

Areas of note when I call the remote extension:
2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: 0 is an invalid value for ccbs_available_timer. Retaining value as 4800 [2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 7200 [2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead. [2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 20 [2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.

[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] app_dial.c: – Called SIP/2713
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] app_dial.c: – Connected line update to SIP/2767-000020a5 prevented.
[2013-10-16 11:36:27] WARNING[13264] chan_sip.c: Retransmission timeout reached on transmission 2391c74d7066f0fe5d08b36b786271ff@MY_SERVER:5060 for seqno 102 (Critical Request) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6399ms with no response
[2013-10-16 11:36:27] WARNING[13264] chan_sip.c: Hanging up call 2391c74d7066f0fe5d08b36b786271ff@MY_SERVER:5060 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).

Invalid values
Critical Packet loss

The router in the remote extensions network is set with an open NAT and I’ve port forwarded port 5060 and assigned it to the internal IP address of the phone for that network. I don’t know what could be blocking the packets.

Areas of note when the remote extension calls me:
[2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: 0 is an invalid value for ccbs_available_timer. Retaining value as 4800 [2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 7200 [2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead. [2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 20 [2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.

[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] app_dial.c: – Called SIP/2767
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] app_dial.c: – Connected line update to SIP/2713-000020b2 prevented.
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] app_dial.c: – SIP/2767-000020b3 is ringing
[2013-10-16 11:42:01] VERBOSE[12301][C-00001228] app_dial.c: – Connected line update to SIP/2713-000020b2 prevented.
[2013-10-16 11:42:01] VERBOSE[12301][C-00001228] app_dial.c: – SIP/2767-000020b3 answered SIP/2713-000020b2

[2013-10-16 11:42:07] WARNING[13264] chan_sip.c: Retransmission timeout reached on transmission [email protected] for seqno 2 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2013-10-16 11:42:07] WARNING[13264] chan_sip.c: Hanging up call [email protected] - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).

Invalid values
Critical Packet loss

When the remote extension calls me, the call connects and we can talk, but only for a few seconds before the call is disconnected automatically.

The router in the remote extensions network is set with an open NAT and I’ve port forwarded port 5060 and assigned it to the internal IP address(192.168.1.3) of the phone for that network.

Please help me. I don’t know what is blocking the critical packets and causing the connection issues. What should I do?

FULL LOGS (VERY LONG):
When I call the remote extension:
[2013-10-16 11:36:20] VERBOSE[13264][C-00001222] netsock2.c: == Using SIP RTP TOS bits 184 [2013-10-16 11:36:20] VERBOSE[13264][C-00001222] netsock2.c: == Using SIP RTP CoS mark 5 [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [2713@from-internal:1] Set(“SIP/2767-000020a5”, “__RINGTIMER=15”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [2713@from-internal:2] Macro(“SIP/2767-000020a5”, “exten-vm,novm,2713,0,0,0”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“SIP/2767-000020a5”, “user-callerid,”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/2767-000020a5”, “TOUCH_MONITOR=1381944980.9060”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/2767-000020a5”, “AMPUSER=2767”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/2767-000020a5”, “0?report”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/2767-000020a5”, “1?Set(REALCALLERIDNUM=2767)”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/2767-000020a5”, “AMPUSER=2767”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:6] Set(“SIP/2767-000020a5”, “AMPUSERCIDNAME=MY_NAME”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:7] GotoIf(“SIP/2767-000020a5”, “0?report”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:8] Set(“SIP/2767-000020a5”, “AMPUSERCID=2767”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:9] Set(“SIP/2767-000020a5”, “__DIAL_OPTIONS=Ttr”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:10] Set(“SIP/2767-000020a5”, “CALLERID(all)=“MY_NAME” <2767>”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:11] GotoIf(“SIP/2767-000020a5”, “0?limit”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:12] ExecIf(“SIP/2767-000020a5”, “0?Set(GROUP(concurrency_limit)=2767)”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:13] ExecIf(“SIP/2767-000020a5”, “0?Set(CHANNEL(language)=)”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:14] GosubIf(“SIP/2767-000020a5”, “7?sub-ccss,s,1(macro-exten-vm,2713)”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-ccss:1] ExecIf(“SIP/2767-000020a5”, “0?Return()”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-ccss:2] Set(“SIP/2767-000020a5”, “CCSS_SETUP=TRUE”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-ccss:3] GosubIf(“SIP/2767-000020a5”, “0?monitor_config,1(macro-exten-vm,2713):monitor_default,1(macro-exten-vm,2713)”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/2767-000020a5”, “1?is_exten”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (sub-ccss,monitor_default,4) [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [monitor_default@sub-ccss:4] Set(“SIP/2767-000020a5”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [monitor_default@sub-ccss:5] Set(“SIP/2767-000020a5”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [monitor_default@sub-ccss:6] Return(“SIP/2767-000020a5”, “TRUE”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-ccss:4] GosubIf(“SIP/2767-000020a5”, “7?agent_config,1():agent_default,1()”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:1] Set(“SIP/2767-000020a5”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:2] Set(“SIP/2767-000020a5”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack [2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:3] Set(“SIP/2767-000020a5”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack

[2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: 0 is an invalid value for ccbs_available_timer. Retaining value as 4800

[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:4] Set(“SIP/2767-000020a5”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack

[2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 7200

[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:5] Set(“SIP/2767-000020a5”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack

[2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.

[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:6] ExecIf(“SIP/2767-000020a5”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack

[2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 20

[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:7] ExecIf(“SIP/2767-000020a5”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:8] ExecIf(“SIP/2767-000020a5”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/2767_2713@from-ccss-)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:9] Set(“SIP/2767-000020a5”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack

[2013-10-16 11:36:20] WARNING[11991][C-00001222] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.

[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [agent_config@sub-ccss:10] Return(“SIP/2767-000020a5”, “”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-ccss:5] Set(“SIP/2767-000020a5”, “DB(AMPUSER/2767/ccss/last_number)=2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-ccss:6] Return(“SIP/2767-000020a5”, “”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“SIP/2767-000020a5”, “0?continue”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:16] Set(“SIP/2767-000020a5”, “__TTL=64”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:17] GotoIf(“SIP/2767-000020a5”, “1?continue”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (macro-user-callerid,s,28)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/2767-000020a5”, “CALLERID(number)=2767”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:29] Set(“SIP/2767-000020a5”, “CALLERID(name)=MY_NAME”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/2767-000020a5”, “CDR(cnum)=2767”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/2767-000020a5”, “CDR(cnam)=MY_NAME”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/2767-000020a5”, “CHANNEL(language)=en”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:2] Set(“SIP/2767-000020a5”, “RingGroupMethod=none”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:3] Set(“SIP/2767-000020a5”, “__EXTTOCALL=2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:4] Set(“SIP/2767-000020a5”, “__PICKUPMARK=2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:5] Set(“SIP/2767-000020a5”, “RT=”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:6] ExecIf(“SIP/2767-000020a5”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:7] ExecIf(“SIP/2767-000020a5”, “0?MacroExit()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:8] Gosub(“SIP/2767-000020a5”, “sub-record-check,s,1(exten,2713,)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:1] Set(“SIP/2767-000020a5”, “REC_POLICY_MODE_SAVE=”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:2] GotoIf(“SIP/2767-000020a5”, “1?check”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (sub-record-check,s,7)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/2767-000020a5”, “__MON_FMT=wav”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“SIP/2767-000020a5”, “1?next”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (sub-record-check,s,11)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/2767-000020a5”, “0?Return()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:12] ExecIf(“SIP/2767-000020a5”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:13] GotoIf(“SIP/2767-000020a5”, “0?exten,1”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/2767-000020a5”, “__REC_STATUS=INITIALIZED”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/2767-000020a5”, “NOW=1381944980”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/2767-000020a5”, “__DAY=16”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/2767-000020a5”, “__MONTH=10”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/2767-000020a5”, “__YEAR=2013”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/2767-000020a5”, “__TIMESTR=20131016-113620”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/2767-000020a5”, “__FROMEXTEN=2767”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:21] Set(“SIP/2767-000020a5”, “__CALLFILENAME=exten-2713-2767-20131016-113620-1381944980.9060”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@sub-record-check:22] Goto(“SIP/2767-000020a5”, “exten,1”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (sub-record-check,exten,1)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [exten@sub-record-check:1] GotoIf(“SIP/2767-000020a5”, “0?callee”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [exten@sub-record-check:2] Set(“SIP/2767-000020a5”, “__REC_POLICY_MODE=dontcare”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [exten@sub-record-check:3] GotoIf(“SIP/2767-000020a5”, “1?caller”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (sub-record-check,exten,10)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [exten@sub-record-check:10] Set(“SIP/2767-000020a5”, “__REC_POLICY_MODE=dontcare”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [exten@sub-record-check:11] GosubIf(“SIP/2767-000020a5”, “0?record,1(exten,2713,2767)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [exten@sub-record-check:12] Return(“SIP/2767-000020a5”, “”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:9] GotoIf(“SIP/2767-000020a5”, “1?macrodial”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (macro-exten-vm,s,15)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:15] GosubIf(“SIP/2767-000020a5”, “0?clrheader,1()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:16] Macro(“SIP/2767-000020a5”, “dial-one,Ttr,2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:1] Set(“SIP/2767-000020a5”, “DEXTEN=2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:2] Set(“SIP/2767-000020a5”, “DIALSTATUS_CW=”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“SIP/2767-000020a5”, “0?screen,1()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“SIP/2767-000020a5”, “0?cf,1()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“SIP/2767-000020a5”, “1?skip1”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (macro-dial-one,s,8)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“SIP/2767-000020a5”, “0?nodial”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“SIP/2767-000020a5”, “0?continue”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:10] Set(“SIP/2767-000020a5”, “EXTHASCW=ENABLED”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“SIP/2767-000020a5”, “0?next1:cwinusebusy”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (macro-dial-one,s,23)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:23] GotoIf(“SIP/2767-000020a5”, “1?next3:continue”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Goto (macro-dial-one,s,24)
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:24] ExecIf(“SIP/2767-000020a5”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“SIP/2767-000020a5”, “0?nodial”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“SIP/2767-000020a5”, “1?dstring,1():dlocal,1()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“SIP/2767-000020a5”, “DSTRING=”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“SIP/2767-000020a5”, “DEVICES=2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“SIP/2767-000020a5”, “0?Return()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“SIP/2767-000020a5”, “0?Set(DEVICES=713)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“SIP/2767-000020a5”, “LOOPCNT=1”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“SIP/2767-000020a5”, “ITER=1”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“SIP/2767-000020a5”, “THISDIAL=SIP/2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“SIP/2767-000020a5”, “1?zap2dahdi,1()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/2767-000020a5”, “0?Return()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/2767-000020a5”, “NEWDIAL=”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/2767-000020a5”, “LOOPCNT2=1”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/2767-000020a5”, “ITER2=1”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/2767-000020a5”, “THISPART2=SIP/2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/2767-000020a5”, “0?Set(THISPART2=DAHDI/2713)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/2767-000020a5”, “NEWDIAL=SIP/2713&”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/2767-000020a5”, “ITER2=2”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/2767-000020a5”, “0?begin2”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/2767-000020a5”, “THISDIAL=SIP/2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/2767-000020a5”, “”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“SIP/2767-000020a5”, “DSTRING=SIP/2713&”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“SIP/2767-000020a5”, “ITER=2”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“SIP/2767-000020a5”, “0?begin”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“SIP/2767-000020a5”, “DSTRING=SIP/2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“SIP/2767-000020a5”, “”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“SIP/2767-000020a5”, “0?nodial”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“SIP/2767-000020a5”, “0?skiptrace”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:29] GosubIf(“SIP/2767-000020a5”, “1?ctset,1():ctclear,1()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [ctset@macro-dial-one:1] Set(“SIP/2767-000020a5”, “DB(CALLTRACE/2713)=2767”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [ctset@macro-dial-one:2] Return(“SIP/2767-000020a5”, “”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:30] Set(“SIP/2767-000020a5”, “D_OPTIONS=Ttr”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“SIP/2767-000020a5”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“SIP/2767-000020a5”, “0?SIPAddHeader()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“SIP/2767-000020a5”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“SIP/2767-000020a5”, “0?qwait,1()”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:35] Set(“SIP/2767-000020a5”, “__CWIGNORE=”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:36] Set(“SIP/2767-000020a5”, “__KEEPCID=TRUE”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:37] GotoIf(“SIP/2767-000020a5”, “0?usegoto,1”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:38] GotoIf(“SIP/2767-000020a5”, “0?godial”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:39] Set(“SIP/2767-000020a5”, “CONNECTEDLINE(name,i)=John Wilkins”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:40] Set(“SIP/2767-000020a5”, “CONNECTEDLINE(num)=2713”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:41] Set(“SIP/2767-000020a5”, “D_OPTIONS=TtrI”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:42] Dial(“SIP/2767-000020a5”, “SIP/2713,TtrI”) in new stack
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] netsock2.c: == Using SIP RTP TOS bits 184
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] netsock2.c: == Using SIP RTP CoS mark 5
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] app_dial.c: – Called SIP/2713
[2013-10-16 11:36:20] VERBOSE[11991][C-00001222] app_dial.c: – Connected line update to SIP/2767-000020a5 prevented.

[2013-10-16 11:36:27] WARNING[13264] chan_sip.c: Retransmission timeout reached on transmission 2391c74d7066f0fe5d08b36b786271ff@MY_SERVER:5060 for seqno 102 (Critical Request) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6399ms with no response
[2013-10-16 11:36:27] WARNING[13264] chan_sip.c: Hanging up call 2391c74d7066f0fe5d08b36b786271ff@MY_SERVER:5060 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] app_dial.c: == Everyone is busy/congested at this time (1:0/0/1)
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:43] ExecIf(“SIP/2767-000020a5”, “0?MacroExit()”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:44] ExecIf(“SIP/2767-000020a5”, “0?Set(DIALSTATUS=)”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:45] GosubIf(“SIP/2767-000020a5”, “0?s-CHANUNAVAIL,1()”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-dial-one:46] MacroExit(“SIP/2767-000020a5”, “”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:17] Set(“SIP/2767-000020a5”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:18] GosubIf(“SIP/2767-000020a5”, “0?docfu,1()”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:19] GosubIf(“SIP/2767-000020a5”, “0?docfb,1()”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:20] Set(“SIP/2767-000020a5”, “DIALSTATUS=CHANUNAVAIL”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:21] ExecIf(“SIP/2767-000020a5”, “0?MacroExit()”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s@macro-exten-vm:22] GotoIf(“SIP/2767-000020a5”, “1?s-CHANUNAVAIL,1”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Goto (macro-exten-vm,s-CHANUNAVAIL,1)
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s-CHANUNAVAIL@macro-exten-vm:1] GotoIf(“SIP/2767-000020a5”, “0?exit,1”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s-CHANUNAVAIL@macro-exten-vm:2] PlayTones(“SIP/2767-000020a5”, “congestion”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [s-CHANUNAVAIL@macro-exten-vm:3] Congestion(“SIP/2767-000020a5”, “10”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] app_macro.c: == Spawn extension (macro-exten-vm, s-CHANUNAVAIL, 3) exited non-zero on ‘SIP/2767-000020a5’ in macro ‘exten-vm’
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: == Spawn extension (from-internal, 2713, 2) exited non-zero on ‘SIP/2767-000020a5’
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: – Executing [h@from-internal:1] Hangup(“SIP/2767-000020a5”, “”) in new stack
[2013-10-16 11:36:27] VERBOSE[11991][C-00001222] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/2767-000020a5’

When the remote extension calls into my line
[2013-10-16 11:41:57] VERBOSE[13264][C-00001228] netsock2.c: == Using SIP RTP TOS bits 184 [2013-10-16 11:41:57] VERBOSE[13264][C-00001228] netsock2.c: == Using SIP RTP CoS mark 5 [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [2767@from-internal:1] Set(“SIP/2713-000020b2”, “__RINGTIMER=15”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [2767@from-internal:2] Macro(“SIP/2713-000020b2”, “exten-vm,2767,2767,0,0,0”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“SIP/2713-000020b2”, “user-callerid,”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/2713-000020b2”, “TOUCH_MONITOR=1381945317.9077”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/2713-000020b2”, “AMPUSER=2713”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/2713-000020b2”, “0?report”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/2713-000020b2”, “1?Set(REALCALLERIDNUM=2713)”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/2713-000020b2”, “AMPUSER=2713”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:6] Set(“SIP/2713-000020b2”, “AMPUSERCIDNAME=REMOTE_NAME”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:7] GotoIf(“SIP/2713-000020b2”, “0?report”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:8] Set(“SIP/2713-000020b2”, “AMPUSERCID=2713”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:9] Set(“SIP/2713-000020b2”, “__DIAL_OPTIONS=Ttr”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:10] Set(“SIP/2713-000020b2”, “CALLERID(all)=“REMOTE_NAME” <2713>”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:11] GotoIf(“SIP/2713-000020b2”, “0?limit”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:12] ExecIf(“SIP/2713-000020b2”, “0?Set(GROUP(concurrency_limit)=2713)”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:13] ExecIf(“SIP/2713-000020b2”, “0?Set(CHANNEL(language)=)”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:14] GosubIf(“SIP/2713-000020b2”, “7?sub-ccss,s,1(macro-exten-vm,2767)”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-ccss:1] ExecIf(“SIP/2713-000020b2”, “0?Return()”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-ccss:2] Set(“SIP/2713-000020b2”, “CCSS_SETUP=TRUE”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-ccss:3] GosubIf(“SIP/2713-000020b2”, “7?monitor_config,1(macro-exten-vm,2767):monitor_default,1(macro-exten-vm,2767)”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [monitor_config@sub-ccss:1] Set(“SIP/2713-000020b2”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [monitor_config@sub-ccss:2] GotoIf(“SIP/2713-000020b2”, “1?set_monitor”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (sub-ccss,monitor_config,5) [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [monitor_config@sub-ccss:5] Set(“SIP/2713-000020b2”, “CALLCOMPLETION(cc_max_monitors)=”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [monitor_config@sub-ccss:6] Return(“SIP/2713-000020b2”, “TRUE”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-ccss:4] GosubIf(“SIP/2713-000020b2”, “7?agent_config,1():agent_default,1()”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:1] Set(“SIP/2713-000020b2”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:2] Set(“SIP/2713-000020b2”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack [2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:3] Set(“SIP/2713-000020b2”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack

[2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: 0 is an invalid value for ccbs_available_timer. Retaining value as 4800

[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:4] Set(“SIP/2713-000020b2”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack

[2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 7200

[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:5] Set(“SIP/2713-000020b2”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack

[2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.

[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:6] ExecIf(“SIP/2713-000020b2”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack

[2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 20

[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:7] ExecIf(“SIP/2713-000020b2”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:8] ExecIf(“SIP/2713-000020b2”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/2713_2767@from-ccss-)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:9] Set(“SIP/2713-000020b2”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack

[2013-10-16 11:41:57] WARNING[12301][C-00001228] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.

[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [agent_config@sub-ccss:10] Return(“SIP/2713-000020b2”, “”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-ccss:5] Set(“SIP/2713-000020b2”, “DB(AMPUSER/2713/ccss/last_number)=2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-ccss:6] Return(“SIP/2713-000020b2”, “”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“SIP/2713-000020b2”, “0?continue”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:16] Set(“SIP/2713-000020b2”, “__TTL=64”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:17] GotoIf(“SIP/2713-000020b2”, “1?continue”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (macro-user-callerid,s,28)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/2713-000020b2”, “CALLERID(number)=2713”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:29] Set(“SIP/2713-000020b2”, “CALLERID(name)=REMOTE_NAME”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/2713-000020b2”, “CDR(cnum)=2713”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/2713-000020b2”, “CDR(cnam)=REMOTE_NAME”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/2713-000020b2”, “CHANNEL(language)=en”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:2] Set(“SIP/2713-000020b2”, “RingGroupMethod=none”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:3] Set(“SIP/2713-000020b2”, “__EXTTOCALL=2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:4] Set(“SIP/2713-000020b2”, “__PICKUPMARK=2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:5] Set(“SIP/2713-000020b2”, “RT=15”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:6] ExecIf(“SIP/2713-000020b2”, “0?Macro(vm,2767,DIRECTDIAL,)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:7] ExecIf(“SIP/2713-000020b2”, “0?MacroExit()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:8] Gosub(“SIP/2713-000020b2”, “sub-record-check,s,1(exten,2767,)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:1] Set(“SIP/2713-000020b2”, “REC_POLICY_MODE_SAVE=”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:2] GotoIf(“SIP/2713-000020b2”, “1?check”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (sub-record-check,s,7)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/2713-000020b2”, “__MON_FMT=wav”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“SIP/2713-000020b2”, “1?next”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (sub-record-check,s,11)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/2713-000020b2”, “0?Return()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:12] ExecIf(“SIP/2713-000020b2”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:13] GotoIf(“SIP/2713-000020b2”, “0?exten,1”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/2713-000020b2”, “__REC_STATUS=INITIALIZED”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/2713-000020b2”, “NOW=1381945317”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/2713-000020b2”, “__DAY=16”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/2713-000020b2”, “__MONTH=10”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/2713-000020b2”, “__YEAR=2013”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/2713-000020b2”, “__TIMESTR=20131016-114157”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/2713-000020b2”, “__FROMEXTEN=2713”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:21] Set(“SIP/2713-000020b2”, “__CALLFILENAME=exten-2767-2713-20131016-114157-1381945317.9077”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@sub-record-check:22] Goto(“SIP/2713-000020b2”, “exten,1”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (sub-record-check,exten,1)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [exten@sub-record-check:1] GotoIf(“SIP/2713-000020b2”, “0?callee”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [exten@sub-record-check:2] Set(“SIP/2713-000020b2”, “__REC_POLICY_MODE=dontcare”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [exten@sub-record-check:3] GotoIf(“SIP/2713-000020b2”, “1?caller”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (sub-record-check,exten,10)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [exten@sub-record-check:10] Set(“SIP/2713-000020b2”, “__REC_POLICY_MODE=dontcare”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [exten@sub-record-check:11] GosubIf(“SIP/2713-000020b2”, “0?record,1(exten,2767,2713)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [exten@sub-record-check:12] Return(“SIP/2713-000020b2”, “”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:9] GotoIf(“SIP/2713-000020b2”, “1?macrodial”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (macro-exten-vm,s,15)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:15] GosubIf(“SIP/2713-000020b2”, “0?clrheader,1()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-exten-vm:16] Macro(“SIP/2713-000020b2”, “dial-one,15,Ttr,2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:1] Set(“SIP/2713-000020b2”, “DEXTEN=2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:2] Set(“SIP/2713-000020b2”, “DIALSTATUS_CW=”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“SIP/2713-000020b2”, “0?screen,1()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“SIP/2713-000020b2”, “0?cf,1()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“SIP/2713-000020b2”, “1?skip1”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (macro-dial-one,s,8)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“SIP/2713-000020b2”, “0?nodial”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“SIP/2713-000020b2”, “0?continue”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:10] Set(“SIP/2713-000020b2”, “EXTHASCW=ENABLED”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“SIP/2713-000020b2”, “0?next1:cwinusebusy”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (macro-dial-one,s,23)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:23] GotoIf(“SIP/2713-000020b2”, “1?next3:continue”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Goto (macro-dial-one,s,24)
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:24] ExecIf(“SIP/2713-000020b2”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“SIP/2713-000020b2”, “0?nodial”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“SIP/2713-000020b2”, “1?dstring,1():dlocal,1()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“SIP/2713-000020b2”, “DSTRING=”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“SIP/2713-000020b2”, “DEVICES=2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“SIP/2713-000020b2”, “0?Return()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“SIP/2713-000020b2”, “0?Set(DEVICES=767)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“SIP/2713-000020b2”, “LOOPCNT=1”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“SIP/2713-000020b2”, “ITER=1”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“SIP/2713-000020b2”, “THISDIAL=SIP/2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“SIP/2713-000020b2”, “1?zap2dahdi,1()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/2713-000020b2”, “0?Return()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/2713-000020b2”, “NEWDIAL=”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/2713-000020b2”, “LOOPCNT2=1”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/2713-000020b2”, “ITER2=1”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/2713-000020b2”, “THISPART2=SIP/2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/2713-000020b2”, “0?Set(THISPART2=DAHDI/2767)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/2713-000020b2”, “NEWDIAL=SIP/2767&”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/2713-000020b2”, “ITER2=2”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/2713-000020b2”, “0?begin2”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/2713-000020b2”, “THISDIAL=SIP/2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/2713-000020b2”, “”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“SIP/2713-000020b2”, “DSTRING=SIP/2767&”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“SIP/2713-000020b2”, “ITER=2”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“SIP/2713-000020b2”, “0?begin”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“SIP/2713-000020b2”, “DSTRING=SIP/2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“SIP/2713-000020b2”, “”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“SIP/2713-000020b2”, “0?nodial”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“SIP/2713-000020b2”, “0?skiptrace”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:29] GosubIf(“SIP/2713-000020b2”, “1?ctset,1():ctclear,1()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [ctset@macro-dial-one:1] Set(“SIP/2713-000020b2”, “DB(CALLTRACE/2767)=2713”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [ctset@macro-dial-one:2] Return(“SIP/2713-000020b2”, “”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:30] Set(“SIP/2713-000020b2”, “D_OPTIONS=Ttr”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“SIP/2713-000020b2”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“SIP/2713-000020b2”, “0?SIPAddHeader()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“SIP/2713-000020b2”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“SIP/2713-000020b2”, “0?qwait,1()”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:35] Set(“SIP/2713-000020b2”, “__CWIGNORE=”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:36] Set(“SIP/2713-000020b2”, “__KEEPCID=TRUE”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:37] GotoIf(“SIP/2713-000020b2”, “0?usegoto,1”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:38] GotoIf(“SIP/2713-000020b2”, “0?godial”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:39] Set(“SIP/2713-000020b2”, “CONNECTEDLINE(name,i)=Daniel Lewis”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:40] Set(“SIP/2713-000020b2”, “CONNECTEDLINE(num)=2767”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:41] Set(“SIP/2713-000020b2”, “D_OPTIONS=TtrI”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-dial-one:42] Dial(“SIP/2713-000020b2”, “SIP/2767,15,TtrI”) in new stack
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] netsock2.c: == Using SIP RTP TOS bits 184
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] netsock2.c: == Using SIP RTP CoS mark 5
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] app_dial.c: – Called SIP/2767
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] app_dial.c: – Connected line update to SIP/2713-000020b2 prevented.
[2013-10-16 11:41:57] VERBOSE[12301][C-00001228] app_dial.c: – SIP/2767-000020b3 is ringing
[2013-10-16 11:42:01] VERBOSE[12301][C-00001228] app_dial.c: – Connected line update to SIP/2713-000020b2 prevented.
[2013-10-16 11:42:01] VERBOSE[12301][C-00001228] app_dial.c: – SIP/2767-000020b3 answered SIP/2713-000020b2

[2013-10-16 11:42:07] WARNING[13264] chan_sip.c: Retransmission timeout reached on transmission [email protected] for seqno 2 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2013-10-16 11:42:07] WARNING[13264] chan_sip.c: Hanging up call [email protected] - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] pbx.c: – Executing [h@macro-dial-one:1] Macro(“SIP/2713-000020b2”, “hangupcall,”) in new stack
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/2713-000020b2”, “1?theend”) in new stack
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] pbx.c: – Goto (macro-hangupcall,s,3)
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-hangupcall:3] ExecIf(“SIP/2713-000020b2”, “0?Set(CDR(recordingfile)=)”) in new stack
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/2713-000020b2”, “”) in new stack
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/2713-000020b2’ in macro ‘hangupcall’
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] pbx.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on ‘SIP/2713-000020b2’
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘SIP/2713-000020b2’ in macro ‘dial-one’
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] app_macro.c: == Spawn extension (macro-exten-vm, s, 16) exited non-zero on ‘SIP/2713-000020b2’ in macro ‘exten-vm’
[2013-10-16 11:42:07] VERBOSE[12301][C-00001228] pbx.c: == Spawn extension (from-internal, 2767, 2) exited non-zero on ‘SIP/2713-000020b2’

tm1000 · October 16, 2013, 7:03pm

The critical packets are the RTP audio stream. Which you never mentioned you opened up. Those ports are typically 10000-20000 UDP.

pehelpdesk · October 16, 2013, 9:14pm

Thank you, that solved the packet loss, I’m not seeing that error anymore. Instead, when I dial the remote extension, it rings the line but when it’s answered, there is no voice. The remote extension also cannot dial out.

I get this error now
[2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] app_dial.c: – Called SIP/2713 [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] app_dial.c: – Connected line update to SIP/2767-00002137 prevented. [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] app_dial.c: – SIP/2713-00002138 is ringing [2013-10-16 15:03:36] VERBOSE[15254][C-0000126d] app_dial.c: – Connected line update to SIP/2767-00002137 prevented. [2013-10-16 15:03:36] VERBOSE[15254][C-0000126d] app_dial.c: – SIP/2713-00002138 answered SIP/2767-00002137

Full Log
[2013-10-16 15:03:30] VERBOSE[13264][C-0000126d] netsock2.c: == Using SIP RTP TOS bits 184 [2013-10-16 15:03:30] VERBOSE[13264][C-0000126d] netsock2.c: == Using SIP RTP CoS mark 5 [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [2713@from-internal:1] Set(“SIP/2767-00002137”, “__RINGTIMER=15”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [2713@from-internal:2] Macro(“SIP/2767-00002137”, “exten-vm,novm,2713,0,0,0”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“SIP/2767-00002137”, “user-callerid,”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/2767-00002137”, “TOUCH_MONITOR=1381957410.9214”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/2767-00002137”, “AMPUSER=2767”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/2767-00002137”, “0?report”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/2767-00002137”, “1?Set(REALCALLERIDNUM=2767)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/2767-00002137”, “AMPUSER=2767”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:6] Set(“SIP/2767-00002137”, “AMPUSERCIDNAME=MY_NAME”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:7] GotoIf(“SIP/2767-00002137”, “0?report”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:8] Set(“SIP/2767-00002137”, “AMPUSERCID=2767”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:9] Set(“SIP/2767-00002137”, “__DIAL_OPTIONS=Ttr”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:10] Set(“SIP/2767-00002137”, “CALLERID(all)=“MY_NAME” <2767>”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:11] GotoIf(“SIP/2767-00002137”, “0?limit”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:12] ExecIf(“SIP/2767-00002137”, “0?Set(GROUP(concurrency_limit)=2767)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:13] ExecIf(“SIP/2767-00002137”, “0?Set(CHANNEL(language)=)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:14] GosubIf(“SIP/2767-00002137”, “7?sub-ccss,s,1(macro-exten-vm,2713)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-ccss:1] ExecIf(“SIP/2767-00002137”, “0?Return()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-ccss:2] Set(“SIP/2767-00002137”, “CCSS_SETUP=TRUE”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-ccss:3] GosubIf(“SIP/2767-00002137”, “0?monitor_config,1(macro-exten-vm,2713):monitor_default,1(macro-exten-vm,2713)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/2767-00002137”, “1?is_exten”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (sub-ccss,monitor_default,4) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [monitor_default@sub-ccss:4] Set(“SIP/2767-00002137”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [monitor_default@sub-ccss:5] Set(“SIP/2767-00002137”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [monitor_default@sub-ccss:6] Return(“SIP/2767-00002137”, “TRUE”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-ccss:4] GosubIf(“SIP/2767-00002137”, “7?agent_config,1():agent_default,1()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:1] Set(“SIP/2767-00002137”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:2] Set(“SIP/2767-00002137”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:3] Set(“SIP/2767-00002137”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack [2013-10-16 15:03:30] WARNING[15254][C-0000126d] ccss.c: 0 is an invalid value for ccbs_available_timer. Retaining value as 4800 [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:4] Set(“SIP/2767-00002137”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack [2013-10-16 15:03:30] WARNING[15254][C-0000126d] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 7200 [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:5] Set(“SIP/2767-00002137”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack [2013-10-16 15:03:30] WARNING[15254][C-0000126d] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead. [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:6] ExecIf(“SIP/2767-00002137”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack [2013-10-16 15:03:30] WARNING[15254][C-0000126d] ccss.c: 0 is an invalid value for ccnr_available_timer. Retaining value as 20 [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:7] ExecIf(“SIP/2767-00002137”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:8] ExecIf(“SIP/2767-00002137”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/2767_2713@from-ccss-)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:9] Set(“SIP/2767-00002137”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack [2013-10-16 15:03:30] WARNING[15254][C-0000126d] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead. [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [agent_config@sub-ccss:10] Return(“SIP/2767-00002137”, “”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-ccss:5] Set(“SIP/2767-00002137”, “DB(AMPUSER/2767/ccss/last_number)=2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-ccss:6] Return(“SIP/2767-00002137”, “”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:15] GotoIf(“SIP/2767-00002137”, “0?continue”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:16] Set(“SIP/2767-00002137”, “__TTL=64”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:17] GotoIf(“SIP/2767-00002137”, “1?continue”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (macro-user-callerid,s,28) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/2767-00002137”, “CALLERID(number)=2767”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:29] Set(“SIP/2767-00002137”, “CALLERID(name)=MY_NAME”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/2767-00002137”, “CDR(cnum)=2767”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/2767-00002137”, “CDR(cnam)=MY_NAME”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/2767-00002137”, “CHANNEL(language)=en”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:2] Set(“SIP/2767-00002137”, “RingGroupMethod=none”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:3] Set(“SIP/2767-00002137”, “__EXTTOCALL=2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:4] Set(“SIP/2767-00002137”, “__PICKUPMARK=2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:5] Set(“SIP/2767-00002137”, “RT=”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:6] ExecIf(“SIP/2767-00002137”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:7] ExecIf(“SIP/2767-00002137”, “0?MacroExit()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:8] Gosub(“SIP/2767-00002137”, “sub-record-check,s,1(exten,2713,)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:1] Set(“SIP/2767-00002137”, “REC_POLICY_MODE_SAVE=”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:2] GotoIf(“SIP/2767-00002137”, “1?check”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (sub-record-check,s,7) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/2767-00002137”, “__MON_FMT=wav”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“SIP/2767-00002137”, “1?next”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (sub-record-check,s,11) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/2767-00002137”, “0?Return()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:12] ExecIf(“SIP/2767-00002137”, “0?Set(__REC_POLICY_MODE=)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:13] GotoIf(“SIP/2767-00002137”, “0?exten,1”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/2767-00002137”, “__REC_STATUS=INITIALIZED”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/2767-00002137”, “NOW=1381957410”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/2767-00002137”, “__DAY=16”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/2767-00002137”, “__MONTH=10”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/2767-00002137”, “__YEAR=2013”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/2767-00002137”, “__TIMESTR=20131016-150330”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/2767-00002137”, “__FROMEXTEN=2767”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:21] Set(“SIP/2767-00002137”, “__CALLFILENAME=exten-2713-2767-20131016-150330-1381957410.9214”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@sub-record-check:22] Goto(“SIP/2767-00002137”, “exten,1”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (sub-record-check,exten,1) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [exten@sub-record-check:1] GotoIf(“SIP/2767-00002137”, “0?callee”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [exten@sub-record-check:2] Set(“SIP/2767-00002137”, “__REC_POLICY_MODE=dontcare”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [exten@sub-record-check:3] GotoIf(“SIP/2767-00002137”, “1?caller”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (sub-record-check,exten,10) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [exten@sub-record-check:10] Set(“SIP/2767-00002137”, “__REC_POLICY_MODE=dontcare”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [exten@sub-record-check:11] GosubIf(“SIP/2767-00002137”, “0?record,1(exten,2713,2767)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [exten@sub-record-check:12] Return(“SIP/2767-00002137”, “”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:9] GotoIf(“SIP/2767-00002137”, “1?macrodial”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (macro-exten-vm,s,15) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:15] GosubIf(“SIP/2767-00002137”, “0?clrheader,1()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-exten-vm:16] Macro(“SIP/2767-00002137”, “dial-one,Ttr,2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:1] Set(“SIP/2767-00002137”, “DEXTEN=2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:2] Set(“SIP/2767-00002137”, “DIALSTATUS_CW=”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“SIP/2767-00002137”, “0?screen,1()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“SIP/2767-00002137”, “0?cf,1()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“SIP/2767-00002137”, “1?skip1”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (macro-dial-one,s,8) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“SIP/2767-00002137”, “0?nodial”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:9] GotoIf(“SIP/2767-00002137”, “0?continue”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:10] Set(“SIP/2767-00002137”, “EXTHASCW=ENABLED”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:11] GotoIf(“SIP/2767-00002137”, “0?next1:cwinusebusy”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (macro-dial-one,s,23) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:23] GotoIf(“SIP/2767-00002137”, “1?next3:continue”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Goto (macro-dial-one,s,24) [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:24] ExecIf(“SIP/2767-00002137”, “0?Set(DIALSTATUS_CW=BUSY)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:25] GotoIf(“SIP/2767-00002137”, “0?nodial”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:26] GosubIf(“SIP/2767-00002137”, “1?dstring,1():dlocal,1()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:1] Set(“SIP/2767-00002137”, “DSTRING=”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:2] Set(“SIP/2767-00002137”, “DEVICES=2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:3] ExecIf(“SIP/2767-00002137”, “0?Return()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:4] ExecIf(“SIP/2767-00002137”, “0?Set(DEVICES=713)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:5] Set(“SIP/2767-00002137”, “LOOPCNT=1”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:6] Set(“SIP/2767-00002137”, “ITER=1”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:7] Set(“SIP/2767-00002137”, “THISDIAL=SIP/2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“SIP/2767-00002137”, “1?zap2dahdi,1()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/2767-00002137”, “0?Return()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/2767-00002137”, “NEWDIAL=”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/2767-00002137”, “LOOPCNT2=1”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/2767-00002137”, “ITER2=1”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/2767-00002137”, “THISPART2=SIP/2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/2767-00002137”, “0?Set(THISPART2=DAHDI/2713)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/2767-00002137”, “NEWDIAL=SIP/2713&”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/2767-00002137”, “ITER2=2”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/2767-00002137”, “0?begin2”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/2767-00002137”, “THISDIAL=SIP/2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/2767-00002137”, “”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“SIP/2767-00002137”, “DSTRING=SIP/2713&”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“SIP/2767-00002137”, “ITER=2”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“SIP/2767-00002137”, “0?begin”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“SIP/2767-00002137”, “DSTRING=SIP/2713”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“SIP/2767-00002137”, “”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“SIP/2767-00002137”, “0?nodial”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“SIP/2767-00002137”, “0?skiptrace”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:29] GosubIf(“SIP/2767-00002137”, “1?ctset,1():ctclear,1()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [ctset@macro-dial-one:1] Set(“SIP/2767-00002137”, “DB(CALLTRACE/2713)=2767”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [ctset@macro-dial-one:2] Return(“SIP/2767-00002137”, “”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:30] Set(“SIP/2767-00002137”, “D_OPTIONS=Ttr”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“SIP/2767-00002137”, “0?SIPAddHeader(Alert-Info: )”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“SIP/2767-00002137”, “0?SIPAddHeader()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“SIP/2767-00002137”, “0?Set(CHANNEL(musicclass)=)”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“SIP/2767-00002137”, “0?qwait,1()”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:35] Set(“SIP/2767-00002137”, “__CWIGNORE=”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:36] Set(“SIP/2767-00002137”, “__KEEPCID=TRUE”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:37] GotoIf(“SIP/2767-00002137”, “0?usegoto,1”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:38] GotoIf(“SIP/2767-00002137”, “0?godial”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:39] Set(“SIP/2767-00002137”, “CONNECTEDLINE(name,i)=REMOTE_NAME”) in new stack [2013-10-16 15:03:30] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:40] Set(“SIP/2767-00002137”, “CONNECTEDLINE(num)=2713”) in new stack [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:41] Set(“SIP/2767-00002137”, “D_OPTIONS=TtrI”) in new stack [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-dial-one:42] Dial(“SIP/2767-00002137”, “SIP/2713,TtrI”) in new stack [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] netsock2.c: == Using SIP RTP TOS bits 184 [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] netsock2.c: == Using SIP RTP CoS mark 5 [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] app_dial.c: – Called SIP/2713 [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] app_dial.c: – Connected line update to SIP/2767-00002137 prevented. [2013-10-16 15:03:31] VERBOSE[15254][C-0000126d] app_dial.c: – SIP/2713-00002138 is ringing [2013-10-16 15:03:36] VERBOSE[15254][C-0000126d] app_dial.c: – Connected line update to SIP/2767-00002137 prevented. [2013-10-16 15:03:36] VERBOSE[15254][C-0000126d] app_dial.c: – SIP/2713-00002138 answered SIP/2767-00002137 [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] pbx.c: – Executing [h@macro-dial-one:1] Macro(“SIP/2767-00002137”, “hangupcall,”) in new stack [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/2767-00002137”, “1?theend”) in new stack [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] pbx.c: – Goto (macro-hangupcall,s,3) [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-hangupcall:3] ExecIf(“SIP/2767-00002137”, “0?Set(CDR(recordingfile)=)”) in new stack [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/2767-00002137”, “”) in new stack [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/2767-00002137’ in macro ‘hangupcall’ [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] pbx.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on ‘SIP/2767-00002137’ [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘SIP/2767-00002137’ in macro ‘dial-one’ [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] app_macro.c: == Spawn extension (macro-exten-vm, s, 16) exited non-zero on ‘SIP/2767-00002137’ in macro ‘exten-vm’ [2013-10-16 15:03:41] VERBOSE[15254][C-0000126d] pbx.c: == Spawn extension (from-internal, 2713, 2) exited non-zero on ‘SIP/2767-00002137’