Call recording settings being ignored?

Hi all,

I have an inbound route which plays an announcement before ringing the extension. I’ve set every setting I can find to ‘Record on Answer’ but it still records everything (announcement, phone ringing etc.)

Anyone know what I’ve missed?

A few things you missed are

  1. Giving us any version info and how the system was installed
  2. Telling us how it is configured
  3. Logs

Ok I’ll try

FreePBX 2.11.0.38 / Asterisk 11.11.0

Not entirely sure how it was installed (was a long time ago), but I suspect it would have been a FreePBX ISO

When the extension is called Follow Me plays a system recording before sending the call to the extension
The inbound route to that extension is set to record on answer
Call recording for that extension is set to record on answer
The recording options for the extension are all set to always (if set to Don’t care nothing gets recorded)

Log after calling extension from another extension (long)

[2014-08-12 13:36:44] VERBOSE[1550][C-000001e6] netsock2.c: == Using SIP RTP TOS bits 184
[2014-08-12 13:36:44] VERBOSE[1550][C-000001e6] netsock2.c: == Using SIP RTP CoS mark 5
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:1] GotoIf(“SIP/111-00000121”, “0?ext-local,100,1”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:2] Macro(“SIP/111-00000121”, “user-callerid,”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/111-00000121”, “TOUCH_MONITOR=1407847004.289”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/111-00000121”, “AMPUSER=111”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/111-00000121”, “0?report”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/111-00000121”, “1?Set(REALCALLERIDNUM=111)”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/111-00000121”, “AMPUSER=111”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/111-00000121”, “0?limit”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/111-00000121”, “AMPUSERCIDNAME=Test”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/111-00000121”, “0?report”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:9] Set(“SIP/111-00000121”, “AMPUSERCID=111”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:10] Set(“SIP/111-00000121”, “__DIAL_OPTIONS=Ttr”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/111-00000121”, “CALLERID(all)=“Test” <111>”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/111-00000121”, “0?limit”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:13] ExecIf(“SIP/111-00000121”, “0?Set(GROUP(concurrency_limit)=111)”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:14] GotoIf(“SIP/111-00000121”, “0?continue”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:15] Set(“SIP/111-00000121”, “__TTL=64”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/111-00000121”, “1?continue”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Goto (macro-user-callerid,s,27)
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:27] Set(“SIP/111-00000121”, “CALLERID(number)=111”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:28] Set(“SIP/111-00000121”, “CALLERID(name)=Test”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:29] Set(“SIP/111-00000121”, “CDR(cnum)=111”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/111-00000121”, “CDR(cnam)=Test”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/111-00000121”, “CHANNEL(language)=en”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:3] Set(“SIP/111-00000121”, “DIAL_OPTIONS=TtrI”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:4] Set(“SIP/111-00000121”, “CONNECTEDLINE(num)=100”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:5] Gosub(“SIP/111-00000121”, “sub-presencestate-display,s,1(100)”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-presencestate-display:1] Goto(“SIP/111-00000121”, “state-available,1”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Goto (sub-presencestate-display,state-available,1)
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [state-available@sub-presencestate-display:1] Set(“SIP/111-00000121”, “PRESENCESTATE_DISPLAY=(Available)”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [state-available@sub-presencestate-display:2] Return(“SIP/111-00000121”, “”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:6] Set(“SIP/111-00000121”, “CONNECTEDLINE(name,i)=Danny Horne(Available)”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:7] Set(“SIP/111-00000121”, “FM_DIALSTATUS=NOT_INUSE”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:8] Set(“SIP/111-00000121”, “__EXTTOCALL=100”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:9] Set(“SIP/111-00000121”, “__PICKUPMARK=100”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:10] Macro(“SIP/111-00000121”, “blkvm-setifempty,”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/111-00000121”, “1?init”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Goto (macro-blkvm-setifempty,s,4)
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-blkvm-setifempty:4] Set(“SIP/111-00000121”, “__BLKVM_CHANNEL=SIP/111-00000121”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-blkvm-setifempty:5] Set(“SIP/111-00000121”, “SHARED(BLKVM,SIP/111-00000121)=TRUE”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-blkvm-setifempty:6] Set(“SIP/111-00000121”, “GOSUB_RETVAL=TRUE”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/111-00000121”, “”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:11] GotoIf(“SIP/111-00000121”, “1?skipov”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Goto (from-internal,100,14)
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:14] Set(“SIP/111-00000121”, “RRNODEST=”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:15] Set(“SIP/111-00000121”, “__NODEST=100”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:16] GosubIf(“SIP/111-00000121”, “0?sub-fmsetcid,s,1()”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:17] Set(“SIP/111-00000121”, “RecordMethod=Group”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:18] Gosub(“SIP/111-00000121”, “sub-record-check,s,1(exten,100,)”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:1] Set(“SIP/111-00000121”, “REC_POLICY_MODE_SAVE=”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:2] GotoIf(“SIP/111-00000121”, “1?check”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Goto (sub-record-check,s,7)
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/111-00000121”, “__MON_FMT=wav”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:8] GotoIf(“SIP/111-00000121”, “1?next”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Goto (sub-record-check,s,11)
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/111-00000121”, “0?Return()”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:12] ExecIf(“SIP/111-00000121”, “0?Set(__REC_POLICY_MODE=)”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:13] GotoIf(“SIP/111-00000121”, “0?exten,1”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:14] Set(“SIP/111-00000121”, “__REC_STATUS=INITIALIZED”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:15] Set(“SIP/111-00000121”, “NOW=1407847004”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:16] Set(“SIP/111-00000121”, “__DAY=12”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:17] Set(“SIP/111-00000121”, “__MONTH=08”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:18] Set(“SIP/111-00000121”, “__YEAR=2014”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:19] Set(“SIP/111-00000121”, “__TIMESTR=20140812-133644”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:20] Set(“SIP/111-00000121”, “__FROMEXTEN=111”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:21] Set(“SIP/111-00000121”, “__CALLFILENAME=exten-100-111-20140812-133644-1407847004.289”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@sub-record-check:22] Goto(“SIP/111-00000121”, “exten,1”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Goto (sub-record-check,exten,1)
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [exten@sub-record-check:1] GotoIf(“SIP/111-00000121”, “0?callee”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [exten@sub-record-check:2] Set(“SIP/111-00000121”, “__REC_POLICY_MODE=always”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [exten@sub-record-check:3] GotoIf(“SIP/111-00000121”, “0?caller”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [exten@sub-record-check:4] GotoIf(“SIP/111-00000121”, “1?callee”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Goto (sub-record-check,exten,8)
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [exten@sub-record-check:8] GosubIf(“SIP/111-00000121”, “1?record,1(exten,100,111)”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [record@sub-record-check:1] Set(“SIP/111-00000121”, “AUDIOHOOK_INHERIT(MixMonitor)=yes”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [record@sub-record-check:2] MixMonitor(“SIP/111-00000121”, “2014/08/12/exten-100-111-20140812-133644-1407847004.289.wav,”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [record@sub-record-check:3] Set(“SIP/111-00000121”, “__REC_STATUS=RECORDING”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [record@sub-record-check:4] Set(“SIP/111-00000121”, “CDR(recordingfile)=exten-100-111-20140812-133644-1407847004.289.wav”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [record@sub-record-check:5] Return(“SIP/111-00000121”, “”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [exten@sub-record-check:9] Return(“SIP/111-00000121”, “”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:19] Set(“SIP/111-00000121”, “RingGroupMethod=ringallv2”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:20] Set(“SIP/111-00000121”, “_FMGRP=100”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:21] GotoIf(“SIP/111-00000121”, “0?DIALGRP”) in new stack
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:22] Answer(“SIP/111-00000121”, “”) in new stack
[2014-08-12 13:36:44] VERBOSE[47181][C-000001e6] app_mixmonitor.c: == Begin MixMonitor Recording SIP/111-00000121
[2014-08-12 13:36:44] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:23] Wait(“SIP/111-00000121”, “1”) in new stack
[2014-08-12 13:36:45] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:24] Playback(“SIP/111-00000121”, “custom/Flextel_inbound”) in new stack
[2014-08-12 13:36:45] VERBOSE[47180][C-000001e6] file.c: – <SIP/111-00000121> Playing ‘custom/Flextel_inbound.slin’ (language ‘en’)
[2014-08-12 13:36:46] NOTICE[47180][C-000001e6] res_rtp_asterisk.c: Unknown RTP codec 126 received from ‘192.168.0.223:49612’
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:25] GotoIf(“SIP/111-00000121”, “0?doconfirm”) in new stack
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] pbx.c: – Executing [100@from-internal:26] Macro(“SIP/111-00000121”, “dial,20,TtrI,100”) in new stack
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/111-00000121”, “1?dial”) in new stack
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] pbx.c: – Goto (macro-dial,s,3)
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/111-00000121”, “dialparties.agi”) in new stack
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: dialparties.agi: Caller ID name is ‘Test’ number is ‘111’
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: dialparties.agi: Methodology of ring is ‘ringallv2’
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: – dialparties.agi: Added extension 100 to extension map
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: – dialparties.agi: Extension 100 cf is disabled
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: – dialparties.agi: Extension 100 do not disturb is disabled
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: – dialparties.agi: dbset CALLTRACE/100 to 111
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: – dialparties.agi: Filtered ARG3: 100
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] res_agi.c: – <SIP/111-00000121>AGI Script dialparties.agi completed, returning 0
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/111-00000121”, “SIP/100,22,TtrIM(auto-blkvm)”) in new stack
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] netsock2.c: == Using SIP RTP TOS bits 184
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] netsock2.c: == Using SIP RTP CoS mark 5
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] app_dial.c: – Called SIP/100
[2014-08-12 13:36:54] VERBOSE[47180][C-000001e6] app_dial.c: – Connected line update to SIP/111-00000121 prevented.
[2014-08-12 13:36:56] VERBOSE[47180][C-000001e6] app_dial.c: – SIP/100-00000122 is ringing
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] app_dial.c: – Connected line update to SIP/111-00000121 prevented.
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] app_dial.c: – SIP/100-00000122 answered SIP/111-00000121
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/100-00000122”, “__MACRO_RESULT=”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-auto-blkvm:2] Set(“SIP/100-00000122”, “CFIGNORE=”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-auto-blkvm:3] Set(“SIP/100-00000122”, “MASTER_CHANNEL(CFIGNORE)=”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-auto-blkvm:4] Set(“SIP/100-00000122”, “FORWARD_CONTEXT=from-internal”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-auto-blkvm:5] Set(“SIP/100-00000122”, “MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-auto-blkvm:6] Macro(“SIP/100-00000122”, “blkvm-clr,”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/100-00000122”, “SHARED(BLKVM,SIP/111-00000121)=”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/100-00000122”, “GOSUB_RETVAL=”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/100-00000122”, “”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-auto-blkvm:7] ExecIf(“SIP/100-00000122”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=100)”) in new stack
[2014-08-12 13:36:58] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-auto-blkvm:8] ExecIf(“SIP/100-00000122”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Danny Horne)”) in new stack
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6] pbx.c: – Executing [h@macro-dial:1] Macro(“SIP/111-00000121”, “hangupcall”) in new stack
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/111-00000121”, “1?theend”) in new stack
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6] pbx.c: – Goto (macro-hangupcall,s,3)
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-hangupcall:3] ExecIf(“SIP/111-00000121”, “0?Set(CDR(recordingfile)=)”) in new stack
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/111-00000121”, “”) in new stack
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6]
app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited
non-zero on ‘SIP/111-00000121’ in macro ‘hangupcall’
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6] pbx.c: == Spawn extension (macro-dial, h, 1) exited non-zero on ‘SIP/111-00000121’
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/111-00000121’ in macro ‘dial’
[2014-08-12 13:37:05] VERBOSE[47180][C-000001e6] pbx.c: == Spawn extension (from-internal, 100, 26) exited non-zero on ‘SIP/111-00000121’
[2014-08-12 13:37:05] VERBOSE[47181][C-000001e6] app_mixmonitor.c: == MixMonitor close filestream (mixed)
[2014-08-12 13:37:05] VERBOSE[47181][C-000001e6] app_mixmonitor.c: == End MixMonitor Recording SIP/111-00000121

Well I can see from this section that recording is starting before the announcement, but how to set it to only record when the call is answered?