When individual recording couldn't be written startTimeOffset and endTimeOffset in recordings have negative timestamp

[perk11]

Describe the bug Had a permission issue during recording:

[ERROR] 2020-03-16 21:56:55,257 [entExec-e2-t448] io.openvidu.server.recording.service.SingleStreamRecordingService - 6 Could not open file "/home/openvidu/recordings/session-210/str_CUS_KneB_con_KkazLGRG1r.webm" for writing. (gstfilesink.c(438): gst_file_sink_open_file (): /GstPipeline:pipeline75/GstFileSink:filesink53:
system error: Permission denied)
[WARN] 2020-03-16 21:56:55,257 [entExec-e2-t448] io.openvidu.server.core.Session - SESSION live-interview-210: Pipeline error encountered: UNEXPECTED_PIPELINE_ERROR: GStreamer error: state change failed and some element failed to post a proper error message with the reason for the failure. (gstbasesink.c(5244): gst_base_sink_change_state (): /GstPipeline:pipeline75/GstFileSink:filesink53:
Failed to start)(errCode=4)
[ERROR] 2020-03-16 21:56:55,258 [entExec-e2-t448] io.openvidu.server.recording.service.SingleStreamRecordingService - 4 GStreamer error: state change failed and some element failed to post a proper error message with the reason for the failure. (gstbasesink.c(5244): gst_base_sink_change_state (): /GstPipeline:pipeline75/GstFileSink:filesink53:
Failed to start)

After recording, downloaded the recording ZIP file.

Expected behavior Recording isn't contained in the manifest or is contained with something clearly indicating an error.

Wrong current behavior Recordings exist in JSON manifest with negative timestamp in starTimeOffset and endTimeOffset equal to session start time, e.g. -1584394410796 for a session that started on March 16 at 21:33 GMT.

OpenVidu deployment info Running Openvidu 2.12.0 set up using https://openvidu.io/docs/deployment/deploying-ubuntu/ tutorial, with the only difference being openvidu Public URL changed to port 443.

[micaelgallego]

Please check that kurento user has write permissions in folder /home/openvidu/recordings/

[perk11]

Yes, that is the issue. My suggestion is that OpenVidu should report this better when the recording file doesn't exist. Would be a very minor improvement.

[micaelgallego]

Yes, we will take a look.

Thanks for reporting.

[pjuhasz]

I've ran into a similar issue that startTimeOffset and endTimeOffset are negative, except in my case the issue is intermittent (affects only a small percentage of recordings) and appears to be related to some kind of connection problem. The file for the offending stream exists in the zip, but it is 0 bytes long.

[BritoMatheus]

Same problem with a lot of recordings.

https://openvidu.discourse.group/t/individual-recording-duration/1336/2

[pjuhasz]

Was there any progress on this issue?

We now frequently encounter sessions where one of the streams (out of two) could not be recorded. The final zip (in INDIVIDUAL recording mode) contains either one stream, or two streams where one is 0 sized. In the latter case the startTimeOffset and endTimeOffset are negative for the offending stream, and also the duration is calculated incorrectly.

Usually there is a Kurento error and null pointer exceptions and stack traces in the log for the affected sessions. I tried to decipher the logs, but there appears to be no additional information in the Kurento part, except that there was an error. I can send an example on request.

(The issue persists with Openvidu 2.15 and 2.16.)

[pjuhasz]

Sometimes, but not always, there is this message in the log: [ERROR] 2021-02-04 14:34:35,239 [https-jsse-nio-0.0.0.0-443-exec-3] io.openvidu.server.rpc.RpcHandler - Transport exception for WebSocket session: kal5e75e7v8f2vs313r0tnda4i - Exception: Unable to unwrap data, invalid status [CLOSED]

[mayander30]

Same problem with OpenVidu 2.17 PRO.

We can replicate it when we use a emulator in a session, when we try start the recording it return error, I think openvidu should start the recordings of the videos that are ok, and leave the others, but if someone have issue in the session recording wont start..

[micaelgallego]

As you know we have implemented a new feature in OpenVidu just "ignoring streams with issues" when recording is started. In that way, recording of healthy streams is performed.

Have you tested the alpha version OpenVidu team sent to you? Have you seen improvements in recording errors?

[mayander30]

Yes, it worked fine.

[DiStefano8472]

Hi Micael,

currently I am using OpenVidu version 2.21.0 and I have nearly the same problem you said it is already fixed?

I have a recorded session with one user, couldn't start his stream:

{
  "createdAt": 1650364607914,
  "id": "session_224",
  "name": "session_224",
  "sessionId": "session_224",
  "files": [
    {
      "name": "str_CAM_GhZb_con_Yvfpr2rDP3.webm",
      "connectionId": "con_Yvfpr2rDP3",
      "streamId": "str_CAM_GhZb_con_Yvfpr2rDP3",
      "size": 888403,
      "clientData": "{\"clientData\":\"lf1\"}",
      "serverData": "{\"serverData\":\"lf1\"}",
      "hasAudio": true,
      "hasVideo": true,
      "typeOfVideo": "CAMERA",
      "startTimeOffset": 126043,
      "endTimeOffset": 136658
    },
    {
      "name": "str_CAM_ZirN_con_WCi1cahGIG.webm",
      "connectionId": "con_WCi1cahGIG",
      "streamId": "str_CAM_ZirN_con_WCi1cahGIG",
      "size": 0,
      "clientData": "{\"clientData\":{\"userid\":6,\"name\":\"John Smith\",\"company\":\"A-Team\",\"role\":20}}",
      "serverData": "",
      "hasAudio": true,
      "hasVideo": true,
      "typeOfVideo": "CAMERA",
      "startTimeOffset": -1650364607914,
      "endTimeOffset": -1650364607914
    }
  ]
}

When I call the OpenVidu API endpoint openvidu/api/recordings, I get a wrong duration value for this recording. Ignoring files with negative time offsets would be a nice solution.

Best regards

Stefan