ccepting AUTHENTICATED call from 192.168.24.3:
       > requested format = gsm,
       > requested prefs = (gsm),
       > actual format = gsm,
       > host prefs = (gsm),
       > priority = mine
    -- Executing Macro("IAX2/stlchicago-3", "exten-vm|6643|6643") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "user-callerid") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "user-callerid: Chicago Test Extension 8818") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSER=8818") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?report") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?start") in new stack
    -- Executing Set("IAX2/stlchicago-3", "REALCALLERIDNUM=8818") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "REALCALLERIDNUM is 8818") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSER=") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSERCIDNAME=") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?report") in new stack
    -- Goto (macro-user-callerid,s,13)
    -- Executing NoOp("IAX2/stlchicago-3", "TTL:  ARG1: 6643") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?continue") in new stack
    -- Executing Set("IAX2/stlchicago-3", "__TTL=64") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,23)
    -- Executing NoOp("IAX2/stlchicago-3", "Using CallerID "Chicago Test Extension" <8818>") in new stack
    -- Executing Set("IAX2/stlchicago-3", "FROMCONTEXT=exten-vm") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMBOX=6643") in new stack
    -- Executing Set("IAX2/stlchicago-3", "EXTTOCALL=6643") in new stack
    -- Executing Set("IAX2/stlchicago-3", "CFUEXT=") in new stack
    -- Executing Set("IAX2/stlchicago-3", "CFBEXT=") in new stack
    -- Executing Set("IAX2/stlchicago-3", "RT=15") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "record-enable|6643|IN") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?2:4") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing AGI("IAX2/stlchicago-3", "recordingcheck|20071218-190936|1198026576.46") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
    -- Accepting AUTHENTICATED call from 192.168.24.3:
       > requested format = gsm,
       > requested prefs = (gsm),
       > actual format = gsm,
       > host prefs = (gsm),
       > priority = mine
    -- Executing Macro("IAX2/stlchicago-3", "exten-vm|6643|6643") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "user-callerid") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "user-callerid: Chicago Test Extension 8818") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSER=8818") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?report") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?start") in new stack
    -- Executing Set("IAX2/stlchicago-3", "REALCALLERIDNUM=8818") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "REALCALLERIDNUM is 8818") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSER=") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSERCIDNAME=") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?report") in new stack
    -- Goto (macro-user-callerid,s,13)
    -- Executing NoOp("IAX2/stlchicago-3", "TTL:  ARG1: 6643") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?continue") in new stack
    -- Executing Set("IAX2/stlchicago-3", "__TTL=64") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,23)
    -- Executing NoOp("IAX2/stlchicago-3", "Using CallerID "Chicago Test Extension" <8818>") in new stack
    -- Executing Set("IAX2/stlchicago-3", "FROMCONTEXT=exten-vm") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMBOX=6643") in new stack
    -- Executing Set("IAX2/stlchicago-3", "EXTTOCALL=6643") in new stack
    -- Executing Set("IAX2/stlchicago-3", "CFUEXT=") in new stack
    -- Executing Set("IAX2/stlchicago-3", "CFBEXT=") in new stack
    -- Executing Set("IAX2/stlchicago-3", "RT=15") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "record-enable|6643|IN") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?2:4") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing AGI("IAX2/stlchicago-3", "recordingcheck|20071218-190936|1198026576.46") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
  recordingcheck|20071218-190936|1198026576.46: Inbound recording not enabled
  recordingcheck|20071218-190936|1198026576.46: Inbound recording not enabled
    -- AGI Script recordingcheck completed, returning 0
    -- Executing NoOp("IAX2/stlchicago-3", "No recording needed") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "dial|15|trwW|6643") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing AGI("IAX2/stlchicago-3", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
    -- AGI Script recordingcheck completed, returning 0
    -- Executing NoOp("IAX2/stlchicago-3", "No recording needed") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "dial|15|trwW|6643") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing AGI("IAX2/stlchicago-3", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
  dialparties.agi: Starting New Dialparties.agi
  dialparties.agi: Starting New Dialparties.agi
  == Parsing '/etc/asterisk/manager.conf': Found
  == Parsing '/etc/asterisk/manager_additional.conf': Found
  == Parsing '/etc/asterisk/manager_custom.conf': Found
  == Manager 'admin' logged on from 127.0.0.1
  == Parsing '/etc/asterisk/manager.conf': Found
  == Parsing '/etc/asterisk/manager_additional.conf': Found
  == Parsing '/etc/asterisk/manager_custom.conf': Found
  == Manager 'admin' logged on from 127.0.0.1
  dialparties.agi: Caller ID name is 'Chicago Test Extension' number is '8818'
  dialparties.agi: Caller ID name is 'Chicago Test Extension' number is '8818'
  dialparties.agi: USE_CONFIRMATION:  'FALSE'
  dialparties.agi: USE_CONFIRMATION:  'FALSE'
  dialparties.agi: RINGGROUP_INDEX:   ''
  dialparties.agi: RINGGROUP_INDEX:   ''
  dialparties.agi: Methodology of ring is  'none'
  dialparties.agi: Methodology of ring is  'none'
    --  dialparties.agi: Added extension 6643 to extension map
    --  dialparties.agi: Added extension 6643 to extension map
    --  dialparties.agi: Extension 6643 cf is disabled
    --  dialparties.agi: Extension 6643 cf is disabled
    --  dialparties.agi: Extension 6643 do not disturb is disabled
    --  dialparties.agi: Extension 6643 do not disturb is disabled
       >  dialparties.agi: extnum 6643 has:  cw: 1; hascfb: 0 [] hascfu: 0 []
       >  dialparties.agi: extnum 6643 has:  cw: 1; hascfb: 0 [] hascfu: 0 []
       >  dialparties.agi: ExtensionState: 0
       >  dialparties.agi: ExtensionState: 0
    --  dialparties.agi: dbset CALLTRACE/6643 to 8818
    --  dialparties.agi: dbset CALLTRACE/6643 to 8818
  == Manager 'admin' logged off from 127.0.0.1
  == Manager 'admin' logged off from 127.0.0.1
    -- AGI Script dialparties.agi completed, returning 0
    -- Executing Dial("IAX2/stlchicago-3", "SIP/6643|15|trwW") in new stack
    -- Called 6643
    -- AGI Script dialparties.agi completed, returning 0
    -- Executing Dial("IAX2/stlchicago-3", "SIP/6643|15|trwW") in new stack
    -- Called 6643
    -- SIP/6643-08806098 is ringing
    -- SIP/6643-08806098 is ringing
    -- Nobody picked up in 15000 ms
    -- Executing Set("IAX2/stlchicago-3", "DIALSTATUS=NOANSWER") in new stack
    -- Executing Set("IAX2/stlchicago-3", "SV_DIALSTATUS=NOANSWER") in new stack
    -- Executing GosubIf("IAX2/stlchicago-3", "0?docfu|1") in new stack
    -- Executing GosubIf("IAX2/stlchicago-3", "0?docfb|1") in new stack
    -- Executing Set("IAX2/stlchicago-3", "DIALSTATUS=NOANSWER") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "Voicemail is 6643") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?s-NOANSWER|1") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "Sending to Voicemail box 6643") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "vm|6643|NOANSWER") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "user-callerid|SKIPTTL") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "user-callerid: Chicago Test Extension 8818") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSER=8818") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?report") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?start") in new stack
    -- Goto (macro-user-callerid,s,6)
    -- Executing NoOp("IAX2/stlchicago-3", "REALCALLERIDNUM is 8818") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSER=") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSERCIDNAME=") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?report") in new stack
    -- Goto (macro-user-callerid,s,13)
    -- Executing NoOp("IAX2/stlchicago-3", "TTL: 64 ARG1: SKIPTTL") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,23)
    -- Executing NoOp("IAX2/stlchicago-3", "Using CallerID "Chicago Test Extension" <8818>") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMGAIN=") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?vmx|1") in new stack
    -- Goto (macro-vm,vmx,1)
    -- Executing GotoIf("IAX2/stlchicago-3", "0?s-NOANSWER|1") in new stack
    -- Executing Set("IAX2/stlchicago-3", "MODE=unavail") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?notdirect") in new stack
    -- Goto (macro-vm,vmx,5)
    -- Executing NoOp("IAX2/stlchicago-3", "Checking if ext 6643 is enabled: enabled") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?s-NOANSWER|1") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "get-vmcontext|6643") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMCONTEXT=default") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?200:300") in new stack
    -- Goto (macro-get-vmcontext,s,300)
    -- Executing NoOp("IAX2/stlchicago-3", "") in new stack
    -- Executing AGI("IAX2/stlchicago-3", "checksound.agi|/var/spool/asterisk/voicemail/default/6643/unavail") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/checksound.agi
    -- Nobody picked up in 15000 ms
    -- Executing Set("IAX2/stlchicago-3", "DIALSTATUS=NOANSWER") in new stack
    -- Executing Set("IAX2/stlchicago-3", "SV_DIALSTATUS=NOANSWER") in new stack
    -- Executing GosubIf("IAX2/stlchicago-3", "0?docfu|1") in new stack
    -- Executing GosubIf("IAX2/stlchicago-3", "0?docfb|1") in new stack
    -- Executing Set("IAX2/stlchicago-3", "DIALSTATUS=NOANSWER") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "Voicemail is 6643") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?s-NOANSWER|1") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "Sending to Voicemail box 6643") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "vm|6643|NOANSWER") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "user-callerid|SKIPTTL") in new stack
    -- Executing NoOp("IAX2/stlchicago-3", "user-callerid: Chicago Test Extension 8818") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSER=8818") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?report") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?start") in new stack
    -- Goto (macro-user-callerid,s,6)
    -- Executing NoOp("IAX2/stlchicago-3", "REALCALLERIDNUM is 8818") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSER=") in new stack
    -- Executing Set("IAX2/stlchicago-3", "AMPUSERCIDNAME=") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?report") in new stack
    -- Goto (macro-user-callerid,s,13)
    -- Executing NoOp("IAX2/stlchicago-3", "TTL: 64 ARG1: SKIPTTL") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,23)
    -- Executing NoOp("IAX2/stlchicago-3", "Using CallerID "Chicago Test Extension" <8818>") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMGAIN=") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?vmx|1") in new stack
    -- Goto (macro-vm,vmx,1)
    -- Executing GotoIf("IAX2/stlchicago-3", "0?s-NOANSWER|1") in new stack
    -- Executing Set("IAX2/stlchicago-3", "MODE=unavail") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "1?notdirect") in new stack
    -- Goto (macro-vm,vmx,5)
    -- Executing NoOp("IAX2/stlchicago-3", "Checking if ext 6643 is enabled: enabled") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?s-NOANSWER|1") in new stack
    -- Executing Macro("IAX2/stlchicago-3", "get-vmcontext|6643") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMCONTEXT=default") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?200:300") in new stack
    -- Goto (macro-get-vmcontext,s,300)
    -- Executing NoOp("IAX2/stlchicago-3", "") in new stack
    -- Executing AGI("IAX2/stlchicago-3", "checksound.agi|/var/spool/asterisk/voicemail/default/6643/unavail") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/checksound.agi
    -- AGI Script checksound.agi completed, returning 0
    -- Executing GotoIf("IAX2/stlchicago-3", "0?nofile") in new stack
    -- Executing Set("IAX2/stlchicago-3", "LOOPCOUNT=0") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?vmxtime") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMX_REPEAT=1") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?vmxloops") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMX_TIMEOUT=2") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?vmxanswer") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMX_LOOPS=1") in new stack
    -- Executing Answer("IAX2/stlchicago-3", "") in new stack
    -- Executing Read("IAX2/stlchicago-3", "ACTION|/var/spool/asterisk/voicemail/default/6643/unavail|1|skip|1|2") in new stack
    -- Accepting a maximum of 1 digits.
    -- Playing '/var/spool/asterisk/voicemail/default/6643/unavail' (language 'en')
    -- AGI Script checksound.agi completed, returning 0
    -- Executing GotoIf("IAX2/stlchicago-3", "0?nofile") in new stack
    -- Executing Set("IAX2/stlchicago-3", "LOOPCOUNT=0") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?vmxtime") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMX_REPEAT=1") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?vmxloops") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMX_TIMEOUT=2") in new stack
    -- Executing GotoIf("IAX2/stlchicago-3", "0?vmxanswer") in new stack
    -- Executing Set("IAX2/stlchicago-3", "VMX_LOOPS=1") in new stack
    -- Executing Answer("IAX2/stlchicago-3", "") in new stack
    -- Executing Read("IAX2/stlchicago-3", "ACTION|/var/spool/asterisk/voicemail/default/6643/unavail|1|skip|1|2") in new stack
    -- Accepting a maximum of 1 digits.
    -- Playing '/var/spool/asterisk/voicemail/default/6643/unavail' (language 'en')
    -- User disconnected
  == Spawn extension (macro-vm, vmx, 18) exited non-zero on 'IAX2/stlchicago-3' in macro 'vm'
  == Spawn extension (macro-vm, vmx, 18) exited non-zero on 'IAX2/stlchicago-3' in macro 'exten-vm'
  == Spawn extension (macro-vm, vmx, 18) exited non-zero on 'IAX2/stlchicago-3'
    -- Hungup 'IAX2/stlchicago-3'
    -- User disconnected
  == Spawn extension (macro-vm, vmx, 18) exited non-zero on 'IAX2/stlchicago-3' in macro 'vm'
  == Spawn extension (macro-vm, vmx, 18) exited non-zero on 'IAX2/stlchicago-3' in macro 'exten-vm'
  == Spawn extension (macro-vm, vmx, 18) exited non-zero on 'IAX2/stlchicago-3'
    -- Hungup 'IAX2/stlchicago-3'