Cisco Meeting Server - Recorder Setup With Windows NFS

Monday, February 27, 2017

Configure the Windows NFS Folder

After the Server for NFS role has been installed, set up the Windows NFS Folder. To do this I created a folder C:\_Recorder. Configure the folders NFS properties as follows.

Configure CMS Recorder

In this specific post, the recorder and call bridge are on the same CMS as it is a small demo/test environment. In production this should not be the case, refer to the CMS guides for up to date deployment information.

Using the MMP

recorder listen lo:8443
recorder certs recorder.key recorder.crt
recorder trust callbridge.crt
recorder nfs 1.1.1.1/_Recordings
recorder enable

For testing, I configured a spaces callProfile with the API parameter recordingMode**=automatic**, which causes the recorder to start automatically when the space is called.

After calling the space, a spaces folder is created under the NFS _Recorder folder**,** inside of which a new folder is created using the spaces ID on the first recording occurring. Subsequent recordings into the same space thus also appear under the spaces specific ID folder.

The following error was seen in the CMS Syslog when the NFS share was set to Allow anonymous access instead of Allow unmapped user Unix access (by UID/GID).

Feb 26 22:22:49 user.info acano-c-1 host:server: INFO : conference “Jason Neurohr’s Space”: unencrypted call legs now present
Feb 26 22:22:49 user.err acano-c-1 recorder[1]: Exception during session start#012Traceback (most recent call last):#012 File “/usr/bin/meredith/acano/api.py”, line 127, in handle_session_start#012 status = yield from start#012 File “/usr/bin/meredith/recorder.py”, line 43, in start#012 os.makedirs(directory, exist_ok=True)#012 File “/usr/lib/python3.4/os.py”, line 227, in makedirs#012 makedirs(head, mode, exist_ok)#012 File “/usr/lib/python3.4/os.py”, line 237, in makedirs#012 mkdir(name, mode)#012OSError: [Errno 5] Input/output error: ‘/usr/bin/meredith/recordings/spaces’

Updated 04/10/2018

When using a seperate CMS server as a dedicated recorder you find that when you attempt to start a recording the folders are created in the NFS share but the mp4 file is never written. Verify that you have correctly setup XMPP on the primary CMS and that the recorder does not show any errors in its syslog output. I recently assisted a collegue who was observing this behaviour and we found the following.

XMPP was correctly configured on the primary CMS.
The recorder service reported no errors.
When a recording was initiated, the CoSpace ID folder was created in NFS but the mp4 was not written

Upon investigation the following was observed in the recorder syslog output.

Sep 28 13:08:28 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:28 TRACE (ALL):r = &{GET /recorderStatus HTTP/1.1 1 1 map[User-Agent:[Acano server] Connection:[close] Accept:[/]] {} <nil> 0 [] true CmsRecorder.domain.com:8443 map[] map[] <nil> map[] 10.100.15.100:38002 /recorderStatus 0xc420355340 <nil> <nil> 0xc420219d00} upgrade not found
Sep 28 13:08:28 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:28 TRACE (ALL):set path to /recorderStatus from /recorderStatus: websocket: false, protected: true
Sep 28 13:08:28 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:28 INFO (ALL):peer presented certificate in whitelist with serial number 646721613590206963452377183439427694747451937
Sep 28 13:08:28 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:28 INFO (ALL):Adding auth header
Sep 28 13:08:28 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:28 TRACE (ALL):read 0 bytes: <nil>
Sep 28 13:08:28 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:28 TRACE (ALL):read 336 bytes: <nil>
Sep 28 13:08:38 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:38 TRACE (ALL):r = &{GET /recorderStatus HTTP/1.1 1 1 map[Accept:[/] User-Agent:[Acano server] Connection:[close]] {} <nil> 0 [] true CmsRecorder.domain.com:8443 map[] map[] <nil> map[] 10.100.15.100:41910 /recorderStatus 0xc4200a1ad0 <nil> <nil> 0xc420219f40} upgrade not found
Sep 28 13:08:38 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:38 TRACE (ALL):set path to /recorderStatus from /recorderStatus: websocket: false, protected: true
Sep 28 13:08:38 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:38 INFO (ALL):peer presented certificate in whitelist with serial number 646721613590206963452377183439427694747451937
Sep 28 13:08:38 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:38 INFO (ALL):Adding auth header
Sep 28 13:08:38 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:38 TRACE (ALL):read 0 bytes: <nil>
Sep 28 13:08:38 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:38 TRACE (ALL):read 336 bytes: read tcp 203.0.113.1:60456->203.0.113.3:9000: use of closed network connection
Sep 28 13:08:48 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:48 TRACE (ALL):r = &{GET /recorderStatus HTTP/1.1 1 1 map[Accept:[/] User-Agent:[Acano server] Connection:[close]] {} <nil> 0 [] true CmsRecorder.domain.com:8443 map[] map[] <nil> map[] 10.100.15.100:45656 /recorderStatus 0xc4201fe210 <nil> <nil> 0xc42037ab80} upgrade not found
Sep 28 13:08:48 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:48 TRACE (ALL):set path to /recorderStatus from /recorderStatus: websocket: false, protected: true
Sep 28 13:08:48 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:48 INFO (ALL):peer presented certificate in whitelist with serial number 646721613590206963452377183439427694747451937
Sep 28 13:08:48 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:48 INFO (ALL):Adding auth header
Sep 28 13:08:48 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:48 TRACE (ALL):read 0 bytes: <nil>
Sep 28 13:08:48 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:48 TRACE (ALL):read 336 bytes: <nil>
Sep 28 13:08:55 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:55 TRACE (ALL):r = &{POST /recordings HTTP/1.1 1 1 map[Content-Type:[application/x-www-form-urlencoded] Content-Length:[174] User-Agent:[Acano server] Connection:[close]] 0xc4204aad80 <nil> 174 [] true acano.callbridge.authenticator map[] map[] <nil> map[] 10.100.15.100:34129 /recordings 0xc420355a20 <nil> <nil> 0xc4204aadc0} upgrade not found
Sep 28 13:08:55 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:55 TRACE (ALL):set path to /recordings from /recordings: websocket: false, protected: true
Sep 28 13:08:55 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:55 INFO (ALL):peer presented certificate in whitelist with serial number 646721613590206963452377183439427694747451937
Sep 28 13:08:55 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:55 INFO (ALL):Adding auth header
Sep 28 13:08:55 user.info CmsRecorder recorder[1]: Start session 3ff6dfee-2320-4a7b-bc54-d313dd3a93ed
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Start send
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Start Keepalives
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Bot started
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Media Framework listening on /acano-socket-3ff6dfee-2320-4a7b-bc54-d313dd3a93ed
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Media Framework connected
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Media Framework is up.
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Create meeting.mf.Object(1, sync_pipe)
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Create meeting.mf.Object(2, audio_decoder)
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Create meeting.mf.Object(3, video_decoder)
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Create meeting.mf.Object(4, video_compose)
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Connect meeting.mf.Object(3, video_decoder), 0 to meeting.mf.Object(4, video_compose), 0
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Connect meeting.mf.Object(4, video_compose), 0 to meeting.mf.Object(1, sync_pipe), 0
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Connect meeting.mf.Object(2, audio_decoder), 0 to meeting.mf.Object(1, sync_pipe), 0
Sep 28 13:08:55 user.err CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Client connect failed dns_error
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: End send
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: End Keepalives
Sep 28 13:08:55 user.info CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Bot finished without error
Sep 28 13:08:55 user.err CmsRecorder recorder[1]: Bot 3ff6dfee-2320-4a7b-bc54-d313dd3a93ed failed: CLIENT_CONNECT_FAILED
Sep 28 13:08:56 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:56 TRACE (ALL):read 0 bytes: <nil>
Sep 28 13:08:56 daemon.info CmsRecorder recorder-proxy[1]: 2018/09/28 03:08:56 TRACE (ALL):read 185 bytes: read tcp 203.0.113.1:60460->203.0.113.3:9000: use of closed network connection
Sep 28 13:08:56 user.info CmsRecorder recorder[1]: Process 163 exited with status 13
Sep 28 13:08:57 user.info CmsRecorder recorder[1]: Process 164 exited with status 256

Towards the end of the above exert, a hint points to the problem Sep 28 13:08:55 user.err CmsRecorder recorder.3ff6dfee-2320-4a7b-bc54-d313dd3a93ed[161]: Client connect failed dns_error.

Upon investigation we identified that the CMS recorder was unable to resolve the XMPP SRV DNS record. Once this was resolved, the recorder could successfully write the recordings to disk.