[2013-04-24 21:44:11] VERBOSE[32593] pbx.c:     -- Executing [9177222103@from-voipms:1] Goto("SIP/148186_nyhq-00006e6b", "from-pstn,2122328280,1") in new stack
[2013-04-24 21:44:11] VERBOSE[32593] pbx.c:     -- Goto (from-pstn,2122328280,1)
[2013-04-24 21:44:11] VERBOSE[32593] pbx.c:     -- Executing [2122328280@from-pstn:1] Goto("SIP/148186_nyhq-00006e6b", "operator,s,1") in new stack
[2013-04-24 21:44:11] VERBOSE[32593] pbx.c:     -- Goto (operator,s,1)
[2013-04-24 21:44:11] VERBOSE[32593] pbx.c:     -- Executing [s@operator:1] Answer("SIP/148186_nyhq-00006e6b", "") in new stack
[2013-04-24 21:44:12] VERBOSE[32593] pbx.c:     -- Executing [s@operator:2] Dial("SIP/148186_nyhq-00006e6b", "SIP/8289&SIP/8287,17,Ttr") in new stack
[2013-04-24 21:44:12] VERBOSE[32593] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-04-24 21:44:12] VERBOSE[32593] app_dial.c:     -- Called SIP/8289
[2013-04-24 21:44:12] VERBOSE[32593] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-04-24 21:44:12] VERBOSE[32593] app_dial.c:     -- Called SIP/8287
[2013-04-24 21:44:12] VERBOSE[23503] chan_sip.c:   == Extension Changed 8287[hints] new state Ringing for Notify User 8289
[2013-04-24 21:44:12] VERBOSE[32593] app_dial.c:     -- SIP/8289-00006e6c connected line has changed. Saving it until answer for SIP/148186_nyhq-00006e6b
[2013-04-24 21:44:12] VERBOSE[32593] app_dial.c:     -- SIP/8287-00006e6d connected line has changed. Saving it until answer for SIP/148186_nyhq-00006e6b
[2013-04-24 21:44:12] VERBOSE[32593] app_dial.c:     -- SIP/8287-00006e6d is ringing
[2013-04-24 21:44:12] VERBOSE[32593] app_dial.c:     -- SIP/8289-00006e6c is ringing
[2013-04-24 21:44:14] VERBOSE[23510] dnsmgr.c:        > doing dnsmgr_lookup for 'newyork.voip.ms'
[2013-04-24 21:44:15] VERBOSE[23510] dnsmgr.c:        > doing dnsmgr_lookup for 'newyork.voip.ms'
[2013-04-24 21:44:15] VERBOSE[32593] app_dial.c:     -- SIP/8289-00006e6c connected line has changed. Saving it until answer for SIP/148186_nyhq-00006e6b
[2013-04-24 21:44:15] VERBOSE[32593] app_dial.c:     -- SIP/8289-00006e6c answered SIP/148186_nyhq-00006e6b
[2013-04-24 21:44:15] VERBOSE[23503] chan_sip.c:   == Extension Changed 8287[hints] new state Idle for Notify User 8289
[2013-04-24 21:44:40] VERBOSE[32593] res_musiconhold.c:     -- Started music on hold, class 'default', on SIP/148186_nyhq-00006e6b
[2013-04-24 21:44:44] VERBOSE[23510] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-04-24 21:44:46] VERBOSE[23510] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [2082@stationside:1] Gosub("SIP/8289-00006e6e", "ael-std-extension,~~s~~,1(2082,"YES")") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:1] MSet("SIP/8289-00006e6e", "LOCAL(extnum)=2082") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:2] MSet("SIP/8289-00006e6e", "LOCAL(voicemail-enabled)="YES"") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:3] MSet("SIP/8289-00006e6e", "LOCAL(~~EXTEN~~)=~~s~~") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:4] MSet("SIP/8289-00006e6e", "LOCAL(~~EXTEN~~)=~~s~~") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:5] Set("SIP/8289-00006e6e", "CDR(extension)=2082") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:6] Verbose("SIP/8289-00006e6e", "CDR accountcode is ") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] app_verbose.c: CDR accountcode is
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:7] Verbose("SIP/8289-00006e6e", ""SIPPEER accountcode is nyhq-recruiting"") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] app_verbose.c: SIPPEER accountcode is nyhq-recruiting
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:8] GotoIf("SIP/8289-00006e6e", "0?9:10") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Goto (ael-std-extension,~~s~~,10)
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:10] NoOp("SIP/8289-00006e6e", "Finish if_ael-std-extension_138") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:11] MSet("SIP/8289-00006e6e", "callhint="SIP/2082"") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:12] GotoIf("SIP/8289-00006e6e", "1?13:17") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Goto (ael-std-extension,~~s~~,13)
[2013-04-24 21:44:46] VERBOSE[32594] pbx.c:     -- Executing [~~s~~@ael-std-extension:13] Dial("SIP/8289-00006e6e", "SIP/2082,17,Ttr") in new stack
[2013-04-24 21:44:46] VERBOSE[32594] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-04-24 21:44:46] VERBOSE[23503] chan_sip.c:   == Extension Changed 2082[hints] new state Ringing for Notify User 8289
[2013-04-24 21:44:46] VERBOSE[32594] app_dial.c:     -- Called SIP/2082
[2013-04-24 21:44:47] VERBOSE[32594] app_dial.c:     -- SIP/2082-00006e6f is ringing
[2013-04-24 21:44:50] VERBOSE[32593] res_musiconhold.c:     -- Stopped music on hold on SIP/148186_nyhq-00006e6b
[2013-04-24 21:44:50] NOTICE[23510] chan_sip.c: Got OK on REFER Notify message
[2013-04-24 21:44:50] VERBOSE[32594] pbx.c:   == Spawn extension (ael-std-extension, ~~s~~, 13) exited non-zero on 'SIP/8289-00006e6e'
[2013-04-24 21:44:50] VERBOSE[32594] pbx.c:     -- Executing [h@ael-std-extension:1] Goto("SIP/8289-00006e6e", "9991") in new stack
[2013-04-24 21:44:50] VERBOSE[32594] pbx.c:     -- Goto (ael-std-extension,h,9991)
[2013-04-24 21:44:50] VERBOSE[32594] pbx.c:     -- Executing [h@ael-std-extension:9991] Set("SIP/8289-00006e6e", "~~parentcxt~~=stationside") in new stack
[2013-04-24 21:44:50] VERBOSE[32594] pbx.c:     -- Executing [h@ael-std-extension:9992] GotoIf("SIP/8289-00006e6e", "0?9996") in new stack
[2013-04-24 21:44:50] VERBOSE[32594] pbx.c:     -- Executing [h@ael-std-extension:9993] GotoIf("SIP/8289-00006e6e", "0?9994:9996") in new stack
[2013-04-24 21:44:50] VERBOSE[32594] pbx.c:     -- Goto (ael-std-extension,h,9996)
[2013-04-24 21:44:50] VERBOSE[32594] pbx.c:     -- Executing [h@ael-std-extension:9996] NoOp("SIP/8289-00006e6e", "") in new stack
[2013-04-24 21:44:50] VERBOSE[23503] chan_sip.c:   == Extension Changed 2082[hints] new state Idle for Notify User 8289
[2013-04-24 21:45:04] VERBOSE[23510] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [2082@stationside:1] Gosub("SIP/8289-00006e70", "ael-std-extension,~~s~~,1(2082,"YES")") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:1] MSet("SIP/8289-00006e70", "LOCAL(extnum)=2082") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:2] MSet("SIP/8289-00006e70", "LOCAL(voicemail-enabled)="YES"") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:3] MSet("SIP/8289-00006e70", "LOCAL(~~EXTEN~~)=~~s~~") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:4] MSet("SIP/8289-00006e70", "LOCAL(~~EXTEN~~)=~~s~~") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:5] Set("SIP/8289-00006e70", "CDR(extension)=2082") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:6] Verbose("SIP/8289-00006e70", "CDR accountcode is ") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] app_verbose.c: CDR accountcode is
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:7] Verbose("SIP/8289-00006e70", ""SIPPEER accountcode is nyhq-recruiting"") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] app_verbose.c: SIPPEER accountcode is nyhq-recruiting
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:8] GotoIf("SIP/8289-00006e70", "0?9:10") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Goto (ael-std-extension,~~s~~,10)l
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:10] NoOp("SIP/8289-00006e70", "Finish if_ael-std-extension_138") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:11] MSet("SIP/8289-00006e70", "callhint="SIP/2082"") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:12] GotoIf("SIP/8289-00006e70", "1?13:17") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Goto (ael-std-extension,~~s~~,13)
[2013-04-24 21:45:04] VERBOSE[32693] pbx.c:     -- Executing [~~s~~@ael-std-extension:13] Dial("SIP/8289-00006e70", "SIP/2082,17,Ttr") in new stack
[2013-04-24 21:45:04] VERBOSE[32693] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-04-24 21:45:04] VERBOSE[32693] app_dial.c:     -- Called SIP/2082
[2013-04-24 21:45:04] VERBOSE[23503] chan_sip.c:   == Extension Changed 2082[hints] new state Ringing for Notify User 8289
[2013-04-24 21:45:04] VERBOSE[32693] app_dial.c:     -- SIP/2082-00006e71 is ringing
[2013-04-24 21:45:04] VERBOSE[32593] pbx.c:   == Spawn extension (operator, s, 2) exited non-zero on 'SIP/148186_nyhq-00006e6b'