Here is a trace on ssh using asterisk -rvvv
-- dialparties.agi: DbDel CALLTRACE/1200 - Caller ID is not defined
-- dialparties.agi: Filtered ARG3: 1200
== Manager 'admin' logged off from 127.0.0.1
-- AGI Script dialparties.agi completed, returning 0
-- Executing [s@macro-dial:7] Dial("SIP/213.166.5.134-b7b7e8b0", "SIP/1200|15|trw") in new stack
-- Called 1200
-- SIP/1200-0912e4c0 is ringing
-- Nobody picked up in 15000 ms
-- Executing [s@macro-dial:8] Set("SIP/213.166.5.134-b7b7e8b0", "DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-dial:9] GosubIf("SIP/213.166.5.134-b7b7e8b0", "0?NOANSWER|1") in new stack
-- Executing [s@macro-exten-vm:10] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?exit|return") in new stack
-- Executing [s@macro-exten-vm:11] Set("SIP/213.166.5.134-b7b7e8b0", "SV_DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-exten-vm:12] GosubIf("SIP/213.166.5.134-b7b7e8b0", "0?docfu|1") in new stack
-- Executing [s@macro-exten-vm:13] GosubIf("SIP/213.166.5.134-b7b7e8b0", "0?docfb|1") in new stack
-- Executing [s@macro-exten-vm:14] Set("SIP/213.166.5.134-b7b7e8b0", "DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-exten-vm:15] NoOp("SIP/213.166.5.134-b7b7e8b0", "Voicemail is 1200") in new stack
-- Executing [s@macro-exten-vm:16] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?s-NOANSWER|1") in new stack
-- Executing [s@macro-exten-vm:17] NoOp("SIP/213.166.5.134-b7b7e8b0", "Sending to Voicemail box 1200") in new stack
-- Executing [s@macro-exten-vm:18] Macro("SIP/213.166.5.134-b7b7e8b0", "vm|1200|NOANSWER|") in new stack
-- Executing [s@macro-vm:1] Macro("SIP/213.166.5.134-b7b7e8b0", "user-callerid|SKIPTTL") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/213.166.5.134-b7b7e8b0", "AMPUSER=") in new stack
-- Executing [s@macro-user-callerid:2] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?report") in new stack
-- Executing [s@macro-user-callerid:3] ExecIf("SIP/213.166.5.134-b7b7e8b0", "1|Set|REALCALLERIDNUM=") in new stack
-- Executing [s@macro-user-callerid:4] Set("SIP/213.166.5.134-b7b7e8b0", "AMPUSER=") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/213.166.5.134-b7b7e8b0", "AMPUSERCIDNAME=") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?report") in new stack
-- Goto (macro-user-callerid,s,10)
-- Executing [s@macro-user-callerid:10] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?continue") in new stack
-- Goto (macro-user-callerid,s,19)
-- Executing [s@macro-user-callerid:19] NoOp("SIP/213.166.5.134-b7b7e8b0", "Using CallerID "anonymous" <>") in new stack
-- Executing [s@macro-vm:2] Set("SIP/213.166.5.134-b7b7e8b0", "VMGAIN=""") in new stack
-- Executing [s@macro-vm:3] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?vmx|1") in new stack
-- Goto (macro-vm,vmx,1)
-- Executing [vmx@macro-vm:1] Set("SIP/213.166.5.134-b7b7e8b0", "MEXTEN=1200") in new stack
-- Executing [vmx@macro-vm:2] Set("SIP/213.166.5.134-b7b7e8b0", "MMODE=NOANSWER") in new stack
-- Executing [vmx@macro-vm:3] Set("SIP/213.166.5.134-b7b7e8b0", "RETVM=") in new stack
-- Executing [vmx@macro-vm:4] Set("SIP/213.166.5.134-b7b7e8b0", "MODE=unavail") in new stack
-- Executing [vmx@macro-vm:5] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?chknomsg") in new stack
-- Goto (macro-vm,vmx,7)
-- Executing [vmx@macro-vm:7] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?s-NOANSWER|1") in new stack
-- Executing [vmx@macro-vm:8] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?notdirect") in new stack
-- Goto (macro-vm,vmx,10)
-- Executing [vmx@macro-vm:10] NoOp("SIP/213.166.5.134-b7b7e8b0", "Checking if ext 1200 is enabled: ") in new stack
-- Executing [vmx@macro-vm:11] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?s-NOANSWER|1") in new stack
-- Goto (macro-vm,s-NOANSWER,1)
-- Executing [s-NOANSWER@macro-vm:1] Macro("SIP/213.166.5.134-b7b7e8b0", "get-vmcontext|1200") in new stack
-- Executing [s@macro-get-vmcontext:1] Set("SIP/213.166.5.134-b7b7e8b0", "VMCONTEXT=default") in new stack
-- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?200:300") in new stack
-- Goto (macro-get-vmcontext,s,300)
-- Executing [s@macro-get-vmcontext:300] NoOp("SIP/213.166.5.134-b7b7e8b0", "") in new stack
-- Executing [s-NOANSWER@macro-vm:2] VoiceMail("SIP/213.166.5.134-b7b7e8b0", "1200@default|u") in new stack
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'SIP/213.166.5.134-b7b7e8b0' in macro 'vm'
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'SIP/213.166.5.134-b7b7e8b0' in macro 'exten-vm'
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'SIP/213.166.5.134-b7b7e8b0'
== End MixMonitor Recording SIP/213.166.5.134-b7b7e8b0
-- dialparties.agi: DbDel CALLTRACE/1200 - Caller ID is not defined
-- dialparties.agi: Filtered ARG3: 1200
== Manager 'admin' logged off from 127.0.0.1
-- AGI Script dialparties.agi completed, returning 0
-- Executing [s@macro-dial:7] Dial("SIP/213.166.5.134-b7b7e8b0", "SIP/1200|15|trw") in new stack
-- Called 1200
-- SIP/1200-0912e4c0 is ringing
-- Nobody picked up in 15000 ms
-- Executing [s@macro-dial:8] Set("SIP/213.166.5.134-b7b7e8b0", "DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-dial:9] GosubIf("SIP/213.166.5.134-b7b7e8b0", "0?NOANSWER|1") in new stack
-- Executing [s@macro-exten-vm:10] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?exit|return") in new stack
-- Executing [s@macro-exten-vm:11] Set("SIP/213.166.5.134-b7b7e8b0", "SV_DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-exten-vm:12] GosubIf("SIP/213.166.5.134-b7b7e8b0", "0?docfu|1") in new stack
-- Executing [s@macro-exten-vm:13] GosubIf("SIP/213.166.5.134-b7b7e8b0", "0?docfb|1") in new stack
-- Executing [s@macro-exten-vm:14] Set("SIP/213.166.5.134-b7b7e8b0", "DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-exten-vm:15] NoOp("SIP/213.166.5.134-b7b7e8b0", "Voicemail is 1200") in new stack
-- Executing [s@macro-exten-vm:16] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?s-NOANSWER|1") in new stack
-- Executing [s@macro-exten-vm:17] NoOp("SIP/213.166.5.134-b7b7e8b0", "Sending to Voicemail box 1200") in new stack
-- Executing [s@macro-exten-vm:18] Macro("SIP/213.166.5.134-b7b7e8b0", "vm|1200|NOANSWER|") in new stack
-- Executing [s@macro-vm:1] Macro("SIP/213.166.5.134-b7b7e8b0", "user-callerid|SKIPTTL") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/213.166.5.134-b7b7e8b0", "AMPUSER=") in new stack
-- Executing [s@macro-user-callerid:2] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?report") in new stack
-- Executing [s@macro-user-callerid:3] ExecIf("SIP/213.166.5.134-b7b7e8b0", "1|Set|REALCALLERIDNUM=") in new stack
-- Executing [s@macro-user-callerid:4] Set("SIP/213.166.5.134-b7b7e8b0", "AMPUSER=") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/213.166.5.134-b7b7e8b0", "AMPUSERCIDNAME=") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?report") in new stack
-- Goto (macro-user-callerid,s,10)
-- Executing [s@macro-user-callerid:10] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?continue") in new stack
-- Goto (macro-user-callerid,s,19)
-- Executing [s@macro-user-callerid:19] NoOp("SIP/213.166.5.134-b7b7e8b0", "Using CallerID "anonymous" <>") in new stack
-- Executing [s@macro-vm:2] Set("SIP/213.166.5.134-b7b7e8b0", "VMGAIN=""") in new stack
-- Executing [s@macro-vm:3] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?vmx|1") in new stack
-- Goto (macro-vm,vmx,1)
-- Executing [vmx@macro-vm:1] Set("SIP/213.166.5.134-b7b7e8b0", "MEXTEN=1200") in new stack
-- Executing [vmx@macro-vm:2] Set("SIP/213.166.5.134-b7b7e8b0", "MMODE=NOANSWER") in new stack
-- Executing [vmx@macro-vm:3] Set("SIP/213.166.5.134-b7b7e8b0", "RETVM=") in new stack
-- Executing [vmx@macro-vm:4] Set("SIP/213.166.5.134-b7b7e8b0", "MODE=unavail") in new stack
-- Executing [vmx@macro-vm:5] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?chknomsg") in new stack
-- Goto (macro-vm,vmx,7)
-- Executing [vmx@macro-vm:7] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?s-NOANSWER|1") in new stack
-- Executing [vmx@macro-vm:8] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?notdirect") in new stack
-- Goto (macro-vm,vmx,10)
-- Executing [vmx@macro-vm:10] NoOp("SIP/213.166.5.134-b7b7e8b0", "Checking if ext 1200 is enabled: ") in new stack
-- Executing [vmx@macro-vm:11] GotoIf("SIP/213.166.5.134-b7b7e8b0", "1?s-NOANSWER|1") in new stack
-- Goto (macro-vm,s-NOANSWER,1)
-- Executing [s-NOANSWER@macro-vm:1] Macro("SIP/213.166.5.134-b7b7e8b0", "get-vmcontext|1200") in new stack
-- Executing [s@macro-get-vmcontext:1] Set("SIP/213.166.5.134-b7b7e8b0", "VMCONTEXT=default") in new stack
-- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/213.166.5.134-b7b7e8b0", "0?200:300") in new stack
-- Goto (macro-get-vmcontext,s,300)
-- Executing [s@macro-get-vmcontext:300] NoOp("SIP/213.166.5.134-b7b7e8b0", "") in new stack
-- Executing [s-NOANSWER@macro-vm:2] VoiceMail("SIP/213.166.5.134-b7b7e8b0", "1200@default|u") in new stack
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'SIP/213.166.5.134-b7b7e8b0' in macro 'vm'
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'SIP/213.166.5.134-b7b7e8b0' in macro 'exten-vm'
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'SIP/213.166.5.134-b7b7e8b0'
== End MixMonitor Recording SIP/213.166.5.134-b7b7e8b0