Inbound Monitored calls not playable in CEL or CDR

Stassen · May 19, 2020, 6:34am

I’m FreePBX 15.7.3 and use Visualdailplan for configuration puposes. Everything is working great for years now, but something remains unanswered even after a lot of reading.

My outbound calls can be played in whatever application in FreePBX so that is fine. Inbound is different. Recording is done and I can access these in /var/spool/asterisk/monitor and play these. Example name is 1589807230-SIP-1xx.xx.xx3.xx-000001ac.wav.

When I access the CEL or CDR via the admin login, these calls are there but not linked to the audio recorded by monitor. Monitor is early in flow and records everything so no recordings are missing. Only the link to the audio in CEL/CDR.

Any ideas anyone ?

PitzKey · May 19, 2020, 7:41am

Are the file permissions correct?

lgaetz · May 19, 2020, 10:43am

The subroutines that initiate the call recording, also set the CDR field with the recording filename. We can see this in the dialplan, so provide a call trace of an inbound call via pastebin:
https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs

What is this?

Stassen · May 19, 2020, 12:30pm

Overview of folder rights

Inbound calls (red boxes)

Call details

Below the logging… Ip-address substituted by zzz.yyy.kkk.ppp. I used extension 702 to create the converstation.

[2020-05-24 09:27:25] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘custom/optie1.ulaw’ (language ‘nl’)
[2020-05-24 09:27:29] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘silence/1.ulaw’ (language ‘nl’)
[2020-05-24 09:27:30] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘custom/optie2.ulaw’ (language ‘nl’)
[2020-05-24 09:27:32] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘silence/1.ulaw’ (language ‘nl’)
[2020-05-24 09:27:33] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘custom/optie3.ulaw’ (language ‘nl’)
[2020-05-24 09:27:36] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘silence/1.ulaw’ (language ‘nl’)
[2020-05-24 09:27:37] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘custom/optie4.ulaw’ (language ‘nl’)
[2020-05-24 09:27:40] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘silence/1.ulaw’ (language ‘nl’)
[2020-05-24 09:27:41] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘custom/assistente.slin’ (language ‘nl’)
[2020-05-24 09:27:43] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘silence/1.ulaw’ (language ‘nl’)
[2020-05-24 09:27:44] VERBOSE[11541][C-000000d3] pbx.c: Executing [s@IVR-mainmenu-open:4] WaitExten(“SIP/zzz.yyy.kkk.ppp-000001c4”, “30”) in new stack
[2020-05-24 09:27:51] VERBOSE[11541][C-000000d3] pbx.c: Executing [5@IVR-mainmenu-open:1] Goto(“SIP/zzz.yyy.kkk.ppp-000001c4”, “1,lbl_IVR-mainmenu-open_1”) in new stack
[2020-05-24 09:27:51] VERBOSE[11541][C-000000d3] pbx_builtins.c: Goto (IVR-mainmenu-open,1,2)
[2020-05-24 09:27:51] VERBOSE[11541][C-000000d3] pbx.c: Executing [1@IVR-mainmenu-open:2] Wait(“SIP/zzz.yyy.kkk.ppp-000001c4”, “1.5”) in new stack
[2020-05-24 09:27:52] VERBOSE[11541][C-000000d3] pbx.c: Executing [1@IVR-mainmenu-open:3] Playback(“SIP/zzz.yyy.kkk.ppp-000001c4”, “custom/uw_wordt_nu_doorgeschakeld”) in new stack
[2020-05-24 09:27:52] VERBOSE[11541][C-000000d3] file.c: <SIP/zzz.yyy.kkk.ppp-000001c4> Playing ‘custom/uw_wordt_nu_doorgeschakeld.ulaw’ (language ‘nl’)
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] pbx.c: Executing [1@IVR-mainmenu-open:4] Monitor(“SIP/zzz.yyy.kkk.ppp-000001c4”, “,mb”) in new stack
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] pbx.c: Executing [1@IVR-mainmenu-open:5] Set(“SIP/zzz.yyy.kkk.ppp-000001c4”, “CHANNEL(musicclass)=kempenfm”) in new stack
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] pbx.c: Executing [1@IVR-mainmenu-open:6] Dial(“SIP/zzz.yyy.kkk.ppp-000001c4”, “SIP/700&SIP/701&SIP/702,30,rw”) in new stack
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] netsock2.c: Using SIP RTP TOS bits 184
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] netsock2.c: Using SIP RTP CoS mark 5
[2020-05-24 09:27:54] WARNING[11541][C-000000d3] app_dial.c: Unable to create channel of type ‘SIP’ (cause 20 - Subscriber absent)
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] netsock2.c: Using SIP RTP TOS bits 184
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] netsock2.c: Using SIP RTP CoS mark 5
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] app_dial.c: Called SIP/700
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] app_dial.c: Called SIP/702
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] app_dial.c: SIP/702-000001c6 connected line has changed. Saving it until answer for SIP/zzz.yyy.kkk.ppp-000001c4
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] app_dial.c: SIP/700-000001c5 connected line has changed. Saving it until answer for SIP/zzz.yyy.kkk.ppp-000001c4
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] app_dial.c: SIP/702-000001c6 is ringing
[2020-05-24 09:27:54] VERBOSE[11541][C-000000d3] app_dial.c: SIP/700-000001c5 is ringing
[2020-05-24 09:27:57] VERBOSE[11541][C-000000d3] app_dial.c: SIP/702-000001c6 connected line has changed. Saving it until answer for SIP/zzz.yyy.kkk.ppp-000001c4
[2020-05-24 09:27:57] VERBOSE[11541][C-000000d3] app_dial.c: SIP/702-000001c6 answered SIP/zzz.yyy.kkk.ppp-000001c4
[2020-05-24 09:27:57] VERBOSE[11608][C-000000d3] bridge_channel.c: Channel SIP/702-000001c6 joined ‘simple_bridge’ basic-bridge <0f627914-4e61-431c-9a5e-046e163be253>
[2020-05-24 09:27:57] VERBOSE[11541][C-000000d3] bridge_channel.c: Channel SIP/zzz.yyy.kkk.ppp-000001c4 joined ‘simple_bridge’ basic-bridge <0f627914-4e61-431c-9a5e-046e163be253>
[2020-05-24 09:28:12] VERBOSE[11541][C-000000d3] bridge_channel.c: Channel SIP/zzz.yyy.kkk.ppp-000001c4 left ‘simple_bridge’ basic-bridge <0f627914-4e61-431c-9a5e-046e163be253>
[2020-05-24 09:28:12] VERBOSE[11541][C-000000d3] pbx.c: Spawn extension (IVR-mainmenu-open, 1, 6) exited non-zero on ‘SIP/zzz.yyy.kkk.ppp-000001c4’
[2020-05-24 09:28:12] VERBOSE[11608][C-000000d3] bridge_channel.c: Channel SIP/702-000001c6 left ‘simple_bridge’ basic-bridge <0f627914-4e61-431c-9a5e-046e163be253>

Code

exten => s,1(lbl_IVR-mainmenu-open_0),Set(TIMEOUT(response)=5)
exten => s,n,Set(TIMEOUT(digit)=3)
exten => s,n,Background(custom/optie1&silence/1&custom/optie2&silence/1&custom/optie3&silence/1&custom/optie4&silence/1&custom/assistente&silence/1,m)
exten => s,n,WaitExten(30)
exten => s,n,Hangup()
exten => 1,1,Playback(custom/optie1_uitleg_open)
exten => 1,n(lbl_IVR-mainmenu-open_1),Wait(1.5)
exten => 1,n,Playback(custom/uw_wordt_nu_doorgeschakeld)
exten => 1,n(lbl_IVR-mainmenu-open_2),Monitor(,mb)
exten => 1,n,Set(CHANNEL(musicclass)=kempenfm)
exten => 1,n,Dial(SIP/700&SIP/701&SIP/702,30,rw)
exten => 1,n,GotoIf($["${DIALSTATUS}" = “CHANUNAVAIL”]?lbl_IVR-mainmenu-open_4:)
exten => 1,n,GotoIf($["${DIALSTATUS}" = “CONGESTION”]?lbl_IVR-mainmenu-open_4:)
exten => 1,n,GotoIf($["${DIALSTATUS}" = “NOANSWER”]?lbl_IVR-mainmenu-open_4:)
exten => 1,n,GotoIf($["${DIALSTATUS}" = “BUSY”]?lbl_IVR-mainmenu-open_4:)
exten => 1,n(lbl_IVR-mainmenu-open_3),Hangup()
exten => 1,n(lbl_IVR-mainmenu-open_4),VoiceMail(700,b)

Meanwhile tried different recording options but no success. This config (extensions_vdp.conf) is on top of the default freepbx config.

Stassen · May 28, 2020, 6:21am

Any idea why

exten => 1,n(lbl_IVR-mainmenu-open_2),Monitor(,mb) is recording calls but not indicated as such in CDR or CEL in FreePBX.

Is there an know issue/limitation with the FreePBX UI of CDR/CEL when extension_custom.conf and the next #include level in this extension_custom is being used ?

lgaetz · May 28, 2020, 10:59am

In order to see the recordings linked in the CDR, you would have to use the built in subroutines for enabling call recording. As an example, if you enable call recording on an inbound route, the dialplan line for that would look something like:

Gosub(sub-record-check,s,1(in,${FROM_DID},yes)

Based on what you’ve provided, we can’t tell how much FreePBX dialplan you’re using, so you may have to modify that line to suit your needs.

Stassen · May 29, 2020, 10:26am

Thanks for your support so far…

Part of the untouched Freepbx extension_additional.conf

[sub-record-check]
include => sub-record-check-custom
exten => s,1,GotoIf($[${LEN(${FROMEXTEN})}]?initialized)
exten => s,n,Set(__REC_STATUS=INITIALIZED)
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(__MON_FMT=${IF($["${MIXMON_FORMAT}"=“wav49”]?WAV:${MIXMON_FORMAT})})
exten => s,n(initialized),Noop(Recordings initialized)
exten => s,n,ExecIf($[!${LEN(${ARG3})}]?Set(ARG3=dontcare))
exten => s,n,Set(REC_POLICY_MODE_SAVE=${REC_POLICY_MODE})
exten => s,n,ExecIf($["${BLINDTRANSFER}${ATTENDEDTRANSFER}" != “”]?Set(REC_STATUS=NO))
exten => s,n(next),GotoIf($[${LEN(${ARG1})}]?checkaction)
exten => s,n(recorderror),Playback(something-terribly-wrong,error)
exten => s,n,Hangup
exten => s,n(checkaction),GotoIf($[${DIALPLAN_EXISTS(sub-record-check,${ARG1})}]?sub-record-check,${ARG1},1)
exten => s,n,Noop(Generic ${ARG1} Recording Check - ${FROMEXTEN} ${ARG2})
exten => s,n,Gosub(recordcheck,1(${ARG3},${ARG1},${ARG2}))
exten => s,n,Return()

Updated extension_vdp.conf

;8. Mainmenu for IVR when Open
[IVR-mainmenu-open]

exten => s,1(lbl_IVR-mainmenu-open_0),Set(TIMEOUT(response)=5)
exten => s,n,Set(TIMEOUT(digit)=3)
exten => s,n,Background(custom/optie1&silence/1&custom/optie2&silence/1&custom/optie3&silence/1&custom/optie4&silence/1&custom/assistente&silence/1,m)
exten => s,n,WaitExten(30)
exten => s,n,Hangup()
exten => 1,1,Playback(custom/optie1_uitleg_open)
exten => 1,n(lbl_IVR-mainmenu-open_1),Wait(1.5)
exten => 1,n,Playback(custom/uw_wordt_nu_doorgeschakeld)
exten => 1,n(lbl_IVR-mainmenu-open_2),Set(CHANNEL(musicclass)=kempenfm)
exten => 1,n,(sub-record-check,s,1(in,${FROM_DID},yes)
exten => 1,n,Dial(SIP/700&SIP/701&SIP/702,30,rw)
exten => 1,n,GotoIf($["${DIALSTATUS}" = “CHANUNAVAIL”]?lbl_IVR-mainmenu-open_4:)
exten => 1,n,GotoIf($["${DIALSTATUS}" = “CONGESTION”]?lbl_IVR-mainmenu-open_4:)
exten => 1,n,GotoIf($["${DIALSTATUS}" = “NOANSWER”]?lbl_IVR-mainmenu-open_4:)
exten => 1,n,GotoIf($["${DIALSTATUS}" = “BUSY”]?lbl_IVR-mainmenu-open_4:)
exten => 1,n(lbl_IVR-mainmenu-open_3),StopMonitor()
exten => 1,n,Hangup()
exten => 1,n(lbl_IVR-mainmenu-open_4),VoiceMail(700,b)
exten => 1,n,Goto(lbl_IVR-mainmenu-open_3)
exten => 2,1,Playback(custom/optie2_uitleg_open)
exten => 2,n,Goto(1,lbl_IVR-mainmenu-open_1)
exten => i,1,Goto(s,lbl_IVR-mainmenu-open_0)
exten => t,1,Goto(s,lbl_IVR-mainmenu-open_0)
exten => 3,1,Playback(custom/optie3_uitleg_open)
exten => 3,n,Goto(1,lbl_IVR-mainmenu-open_1)
exten => 4,1,Playback(custom/optie4_uitleg_open)
exten => 4,n,Goto(1,lbl_IVR-mainmenu-open_1)
exten => 5,1,Goto(1,lbl_IVR-mainmenu-open_1)
exten => 8,1,Playback(custom/uw_wordt_nu_doorgeschakeld)
exten => 8,n,Goto(SupplierOption,s,1)
exten => 9,1,Playback(custom/uw_wordt_nu_doorgeschakeld)
exten => 9,n,Goto(PatientOption,s,1)
exten => Bel,1,Goto(1,lbl_IVR-mainmenu-open_2)

When using this sub routine it never gets to the next line (which I can imagine)

[2020-05-29 12:08:05] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:18] GotoIfTime("SIP/zzz.yyy.kkk.ppp-00000004", "9:00-17:00,*,*,*?lbl_Time-Day_9") in new stack
[2020-05-29 12:08:05] VERBOSE[28158][C-00000005] pbx_builtins.c: Goto (Time-Day,s,20)
[2020-05-29 12:08:05] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:20] Playback("SIP/zzz.yyy.kkk.ppp-00000004", "custom/welkom") in new stack
[2020-05-29 12:08:05] VERBOSE[28158][C-00000005] file.c: <SIP/zzz.yyy.kkk.ppp-00000004> Playing 'custom/welkom.ulaw' (language 'nl')
[2020-05-29 12:08:08] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:21] Wait("SIP/zzz.yyy.kkk.ppp-00000004", "1.5") in new stack
[2020-05-29 12:08:09] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:22] Playback("SIP/zzz.yyy.kkk.ppp-00000004", "custom/telefoongespreken_kunnen_worden_opgenomen_voor_analyse") in new stack
[2020-05-29 12:08:09] VERBOSE[28158][C-00000005] file.c: <SIP/zzz.yyy.kkk.ppp-00000004> Playing 'custom/telefoongespreken_kunnen_worden_opgenomen_voor_analyse.slin' (language 'nl')
[2020-05-29 12:08:12] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:23] Wait("SIP/zzz.yyy.kkk.ppp-00000004", "1.5") in new stack
[2020-05-29 12:08:14] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:24] Playback("SIP/zzz.yyy.kkk.ppp-00000004", "custom/Corona2") in new stack
[2020-05-29 12:08:14] WARNING[28158][C-00000005] file.c: File custom/Corona2 does not exist in any format
[2020-05-29 12:08:14] WARNING[28158][C-00000005] file.c: Unable to open custom/Corona2 (format (ulaw)): No such file or directory
[2020-05-29 12:08:14] WARNING[28158][C-00000005] app_playback.c: Playback failed on SIP/zzz.yyy.kkk.ppp-00000004 for custom/Corona2
[2020-05-29 12:08:14] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:25] Wait("SIP/zzz.yyy.kkk.ppp-00000004", "1.5") in new stack
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:26] GotoIf("SIP/zzz.yyy.kkk.ppp-00000004", "1?:lbl_Time-Day_10") in new stack
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] pbx.c: Executing [s@Time-Day:27] Goto("SIP/zzz.yyy.kkk.ppp-00000004", "IVR-mainmenu-open,s,1") in new stack
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] pbx_builtins.c: Goto (IVR-mainmenu-open,s,1)
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] pbx.c: Executing [s@IVR-mainmenu-open:1] Set("SIP/zzz.yyy.kkk.ppp-00000004", "TIMEOUT(response)=5") in new stack
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] func_timeout.c: Response timeout set to 5.000
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] pbx.c: Executing [s@IVR-mainmenu-open:2] Set("SIP/zzz.yyy.kkk.ppp-00000004", "TIMEOUT(digit)=3") in new stack
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] func_timeout.c: Digit timeout set to 3.000
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] pbx.c: Executing [s@IVR-mainmenu-open:3] BackGround("SIP/zzz.yyy.kkk.ppp-00000004", "custom/optie1&silence/1&custom/optie2&silence/1&custom/optie3&silence/1&custom/optie4&silence/1&custom/assistente&silence/1,m") in new stack
[2020-05-29 12:08:15] VERBOSE[28158][C-00000005] file.c: <SIP/zzz.yyy.kkk.ppp-00000004> Playing 'custom/optie1.ulaw' (language 'nl')
[2020-05-29 12:08:19] VERBOSE[28158][C-00000005] file.c: <SIP/zzz.yyy.kkk.ppp-00000004> Playing 'silence/1.ulaw' (language 'nl')
[2020-05-29 12:08:20] VERBOSE[28158][C-00000005] file.c: <SIP/zzz.yyy.kkk.ppp-00000004> Playing 'custom/optie2.ulaw' (language 'nl')
[2020-05-29 12:08:22] VERBOSE[28158][C-00000005] pbx.c: Executing [5@IVR-mainmenu-open:1] Goto("SIP/zzz.yyy.kkk.ppp-00000004", "1,lbl_IVR-mainmenu-open_1") in new stack
[2020-05-29 12:08:22] VERBOSE[28158][C-00000005] pbx_builtins.c: Goto (IVR-mainmenu-open,1,2)
[2020-05-29 12:08:22] VERBOSE[28158][C-00000005] pbx.c: Executing [1@IVR-mainmenu-open:2] Wait("SIP/zzz.yyy.kkk.ppp-00000004", "1.5") in new stack
[2020-05-29 12:08:24] VERBOSE[28158][C-00000005] pbx.c: Executing [1@IVR-mainmenu-open:3] Playback("SIP/zzz.yyy.kkk.ppp-00000004", "custom/uw_wordt_nu_doorgeschakeld") in new stack
[2020-05-29 12:08:24] VERBOSE[28158][C-00000005] file.c: <SIP/zzz.yyy.kkk.ppp-00000004> Playing 'custom/uw_wordt_nu_doorgeschakeld.ulaw' (language 'nl')
[2020-05-29 12:08:25] VERBOSE[28158][C-00000005] pbx.c: Executing [1@IVR-mainmenu-open:4] Set("SIP/zzz.yyy.kkk.ppp-00000004", "CHANNEL(musicclass)=kempenfm") in new stack
[2020-05-29 12:08:25] WARNING[28158][C-00000005] pbx.c: No application '' for extension (IVR-mainmenu-open, 1, 5)
[2020-05-29 12:08:25] VERBOSE[28158][C-00000005] pbx.c: Spawn extension (IVR-mainmenu-open, 1, 5) exited non-zero on 'SIP/zzz.yyy.kkk.ppp-00000004'

If the added line is removed, everything works as designed.

danielf · May 29, 2020, 10:36am

Hello @Mypbx

You should write it like that:
exten => 1,n,Gosub(sub-record-check,s,1(in,${FROM_DID},yes))

Thank you,

Daniel Friedman
Trixton LTD.

Stassen · May 30, 2020, 7:57am

Danielf’s addition did the job for me. I now see these recordings in CDR/CEL overviews with all your help. Super service to you all!

system · June 30, 2020, 7:57am

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.