| Summary: | ASTERISK-20834: Call Recording Fails (mixmonitor) | ||||||
| Reporter: | Philippe Lindheimer (p_lindheimer) | Labels: | |||||
| Date Opened: | 2012-12-20 15:43:22.000-0600 | Date Closed: | 2013-01-09 13:56:01.000-0600 | ||||
| Priority: | Blocker | Regression? | No | ||||
| Status: | Closed/Complete | Components: | Applications/app_mixmonitor | ||||
| Versions: | 10.11.0-digiumphones | Frequency of Occurrence | Constant | ||||
| Related Issues: |
| ||||||
| Environment: | FreePBX versions 2.10 and 2.11 and probably earlier | Attachments: | ( 0) ASTERISK-20834.patch | ||||
| Description: | when trying to record calls whether directly through mix monitor or indirectly in queues and conferences it returns with a format error. Here is an example of the error log:
{noformat} [2012-12-20 15:55:57] WARNING[25595]: file.c:1241 ast_writefile: No such format 'Ãó' -- Executing [record@sub-record-check:4] Set("SIP/201-00000017", "CDR(recordingfile)=out-XXXXXXXXXX5-201-20121220-155557-1356011757.23.WAV") in new stack [2012-12-20 15:55:57] ERROR[25595]: app_mixmonitor.c:517 mixmonitor_save_prep: Cannot open /var/spool/asterisk/monitor/2012/12/20/out-XXXXXXXXXX-201-20121220-155557-1356011757.23.Ãó {noformat} This has failed since 10.9.0 (or earlier). It has been tested in both 1.8.19 and 11.1 and the error is not present in those releases so seems to be isolated to 10 for now. | ||||||
| Comments: | By: Philippe Lindheimer (p_lindheimer) 2012-12-20 15:54:09.845-0600 Here is a call trace including the leadup for the call recording check using 10.11.0. Note thought that it fails with queues and conferences as well and the setup for each of these is a little different: [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:1] GotoIf("SIP/701-00000000", "1?check") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Goto (sub-record-check,s,6) [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:6] Set("SIP/701-00000000", "__MON_FMT=wav") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:7] GotoIf("SIP/701-00000000", "1?next") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Goto (sub-record-check,s,10) [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:10] ExecIf("SIP/701-00000000", "0?Return()") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:11] GotoIf("SIP/701-00000000", "0?out,1") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:12] Set("SIP/701-00000000", "__REC_STATUS=INITIALIZED") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:13] ExecIf("SIP/701-00000000", "0?Set(__REC_POLICY_MODE=)") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:14] Set("SIP/701-00000000", "NOW=1356037555") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:15] Set("SIP/701-00000000", "__DAY=20") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:16] Set("SIP/701-00000000", "__MONTH=12") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:17] Set("SIP/701-00000000", "__YEAR=2012") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:18] Set("SIP/701-00000000", "__TIMESTR=20121220-130555") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:19] Set("SIP/701-00000000", "__FROMEXTEN=701") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:20] Set("SIP/701-00000000", "__CALLFILENAME=out-4257365924-701-20121220-130555-1356037555.0") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@sub-record-check:21] Goto("SIP/701-00000000", "out,1") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Goto (sub-record-check,out,1) [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [out@sub-record-check:1] NoOp("SIP/701-00000000", "[TRACE](3) Recording Check out 4257365924") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [out@sub-record-check:2] ExecIf("SIP/701-00000000", "1?Set(__REC_POLICY_MODE=always)") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [out@sub-record-check:3] GosubIf("SIP/701-00000000", "1?record,1(exten,4257365924,701)") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [record@sub-record-check:1] NoOp("SIP/701-00000000", "[TRACE](3) Setting up recording: exten, 4257365924, 701") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [record@sub-record-check:2] Set("SIP/701-00000000", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [record@sub-record-check:3] MixMonitor("SIP/701-00000000", "2012/12/20/out-4257365924-701-20121220-130555-1356037555.0.wav,,") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [record@sub-record-check:4] Set("SIP/701-00000000", "__REC_STATUS=RECORDING") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [record@sub-record-check:5] Set("SIP/701-00000000", "CDR(recordingfile)=out-4257365924-701-20121220-130555-1356037555.0.wav") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [record@sub-record-check:6] Return("SIP/701-00000000", "") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [out@sub-record-check:4] Return("SIP/701-00000000", "") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [4257365924@outbound-1-2-3-4-5-6-9:8] Macro("SIP/701-00000000", "dialout-trunk,2,4257365924,,off") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/701-00000000", "DIAL_TRUNK=2") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/701-00000000", "0?sub-pincheck,s,1()") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/701-00000000", "0?disabletrunk,1") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/701-00000000", "DIAL_NUMBER=4257365924") in new stack [2012-12-20 13:05:55] VERBOSE[12428] pbx.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/701-00000000", "DIAL_TRUNK_OPTIONS=Ttr") in new stack [2012-12-20 13:05:55] VERBOSE[12429] app_mixmonitor.c: == Begin MixMonitor Recording SIP/701-00000000 [2012-12-20 13:05:55] WARNING[12429] file.c: No such format '<81>Ãó^W^V' [2012-12-20 13:05:55] ERROR[12429] app_mixmonitor.c: Cannot open /var/spool/asterisk/monitor/2012/12/20/out-4257365924-701-20121220-130555-1356037555.0.<81>Ãó^W^V Here is the dialplan used for setting up call recordings in general: [sub-record-check] include => sub-record-check-custom exten => s,1,GotoIf($["${BLINDTRANSFER}" = ""]?check) exten => s,n,ResetCDR() exten => s,n,GotoIf($["${REC_STATUS}" != "RECORDING"]?check) exten => s,n,Set(AUDIOHOOK_INHERIT(MixMonitor)=yes) exten => s,n,MixMonitor(${MIXMON_DIR}${YEAR}/${MONTH}/${DAY}/${CALLFILENAME}.${MIXMON_FORMAT},a,${MIXMON_POST}) exten => s,n(check),Set(__MON_FMT=${IF($["${MIXMON_FORMAT}"="wav49"]?WAV:${MIXMON_FORMAT})}) exten => s,n,GotoIf($["${REC_STATUS}"!="RECORDING"]?next) exten => s,n,Set(CDR(recordingfile)=${CALLFILENAME}.${MON_FMT}) exten => s,n,Return() exten => s,n(next),ExecIf($[!${LEN(${ARG1})}]?Return()) exten => s,n,GotoIf($["${REC_STATUS}"!=""]?${ARG1},1) exten => s,n,Set(__REC_STATUS=INITIALIZED) exten => s,n,ExecIf($["${REC_POLICY_MODE}"="" & "${ARG3}"!=""]?Set(__REC_POLICY_MODE=${ARG3})) exten => s,n,Set(NOW=${EPOCH}) exten => s,n,Set(__DAY=${STRFTIME(${NOW},,%d)}) exten => s,n,Set(__MONTH=${STRFTIME(${NOW},,%m)}) exten => s,n,Set(__YEAR=${STRFTIME(${NOW},,%Y)}) exten => s,n,Set(__TIMESTR=${YEAR}${MONTH}${DAY}-${STRFTIME(${NOW},,%H%M%S)}) exten => s,n,Set(__FROMEXTEN=${IF($[${LEN(${AMPUSER})}]?${AMPUSER}:${IF($[${LEN(${REALCALLERIDNUM})}]?${REALCALLERIDNUM}:unknown)})}) exten => s,n,Set(__CALLFILENAME=${ARG1}-${ARG2}-${FROMEXTEN}-${TIMESTR}-${UNIQUEID}) exten => s,n,Goto(${ARG1},1) exten => rg,1,Noop([TRACE](3) Recording Check ${EXTEN} ${ARG2}) exten => rg,n,GosubIf($["${REC_POLICY_MODE}"="always"]?record,1(${EXTEN},${REC_POLICY_MODE},${FROMEXTEN})) exten => rg,n,Return() exten => force,1,Noop([TRACE](3) Recording Check ${EXTEN} ${ARG2}) exten => force,n,GosubIf($["${REC_POLICY_MODE}"="always"]?record,1(${EXTEN},${REC_POLICY_MODE},${FROMEXTEN})) exten => force,n,Return() exten => q,1,Noop([TRACE](3) Recording Check ${EXTEN} ${ARG2}) exten => q,n,GosubIf($["${REC_POLICY_MODE}"="always"]?recq,1(${EXTEN},${ARG2},${FROMEXTEN})) exten => q,n,Return() exten => out,1,Noop([TRACE](3) Recording Check ${EXTEN} ${ARG2}) exten => out,n,ExecIf($["${REC_POLICY_MODE}"=""]?Set(__REC_POLICY_MODE=${DB(AMPUSER/${FROMEXTEN}/recording/out/external)})) exten => out,n,GosubIf($["${REC_POLICY_MODE}"="always"]?record,1(exten,${ARG2},${FROMEXTEN})) exten => out,n,Return() exten => exten,1,Noop([TRACE](3) Recording Check ${EXTEN} ${ARG2}) exten => exten,n,GotoIf($["${REC_POLICY_MODE}"!=""]?callee) exten => exten,n,Set(__REC_POLICY_MODE=${IF($[${LEN(${FROM_DID})}]?${DB(AMPUSER/${ARG2}/recording/in/external)}:${DB(AMPUSER/${ARG2}/recording/in/internal)})}) exten => exten,n,GotoIf($["${REC_POLICY_MODE}"="dontcare"]?caller) exten => exten,n,GotoIf($["${DB(AMPUSER/${FROMEXTEN}/recording/out/internal)}"="dontcare" | "${FROM_DID}"!=""]?callee) exten => exten,n,ExecIf($[${LEN(${DB(AMPUSER/${FROMEXTEN}/recording/priority)})}]?Set(CALLER_PRI=${DB(AMPUSER/${FROMEXTEN}/recording/priority)}):Set(CALLER_PRI=0)) exten => exten,n,ExecIf($[${LEN(${DB(AMPUSER/${ARG2}/recording/priority)})}]?Set(CALLEE_PRI=${DB(AMPUSER/${ARG2}/recording/priority)}):Set(CALLEE_PRI=0)) exten => exten,n,GotoIf($["${CALLER_PRI}"="${CALLEE_PRI}"]?${REC_POLICY}:${IF($[${CALLER_PRI}>${CALLEE_PRI}]?caller:callee)}) exten => exten,n(callee),GosubIf($["${REC_POLICY_MODE}"="always"]?record,1(${EXTEN},${ARG2},${FROMEXTEN})) exten => exten,n,Return() exten => exten,n(caller),Set(__REC_POLICY_MODE=${DB(AMPUSER/${FROMEXTEN}/recording/out/internal)}) exten => exten,n,GosubIf($["${REC_POLICY_MODE}"="always"]?record,1(${EXTEN},${ARG2},${FROMEXTEN})) exten => exten,n,Return() exten => conf,1,Noop([TRACE](3) Recording Check ${EXTEN} ${ARG2}) exten => conf,n,Gosub(recconf,1(${EXTEN},${ARG2},${ARG2})) exten => conf,n,Return() exten => page,1,Noop([TRACE](3) Recording Check ${EXTEN} ${ARG2}) exten => page,n,GosubIf($["${REC_POLICY_MODE}"="always"]?recconf,1(${EXTEN},${ARG2},${FROMEXTEN})) exten => page,n,Return() exten => record,1,Noop([TRACE](3) Setting up recording: ${ARG1}, ${ARG2}, ${ARG3}) exten => record,n,Set(AUDIOHOOK_INHERIT(MixMonitor)=yes) exten => record,n,MixMonitor(${MIXMON_DIR}${YEAR}/${MONTH}/${DAY}/${CALLFILENAME}.${MIXMON_FORMAT},,${MIXMON_POST}) exten => record,n,Set(__REC_STATUS=RECORDING) exten => record,n,Set(CDR(recordingfile)=${CALLFILENAME}.${MON_FMT}) exten => record,n,Return() exten => recq,1,Noop([TRACE](3) Setting up recording: ${ARG1}, ${ARG2}, ${ARG3}) exten => recq,n,Set(AUDIOHOOK_INHERIT(MixMonitor)=yes) exten => recq,n,Set(MONITOR_FILENAME=${MIXMON_DIR}${YEAR}/${MONTH}/${DAY}/${CALLFILENAME}) exten => recq,n,Set(__REC_STATUS=RECORDING) exten => recq,n,Set(CDR(recordingfile)=${CALLFILENAME}.${MON_FMT}) exten => recq,n,Return() exten => recconf,1,Noop([TRACE](3) Setting up recording: ${ARG1}, ${ARG2}, ${ARG3}) exten => recconf,n,Set(__CALLFILENAME=${IF($[${CONFBRIDGE_INFO(parties,${ARG2})}]?${DB(RECCONF/${ARG2})}:${ARG1}-${ARG2}-${ARG3}-${TIMESTR}-${UNIQUEID})}) exten => recconf,n,ExecIf($[!${CONFBRIDGE_INFO(parties,${ARG2})}]?Set(DB(RECCONF/${ARG2})=${CALLFILENAME})) exten => recconf,n,Set(CONFBRIDGE(bridge,record_file)=${MIXMON_DIR}${YEAR}/${MONTH}/${DAY}/${CALLFILENAME}.${MON_FMT}) exten => recconf,n,ExecIf($["${REC_POLICY_MODE}"!="always"]?Return()) exten => recconf,n,Set(CONFBRIDGE(bridge,record_conference)=yes) exten => recconf,n,Set(__REC_STATUS=RECORDING) exten => recconf,n,Set(CDR(recordingfile)=${CALLFILENAME}.${MON_FMT}) exten => recconf,n,Return() ;--== end of [sub-record-check] ==--; By: Mark Michelson (mmichelson) 2012-12-21 09:50:23.335-0600 Give [^ASTERISK-20834.patch] a try. It fixed the problem for me locally. | ||||||