Start Recording returns HTTP 500 - Java SDK

Prabu_R · May 14, 2020, 8:44am

We are using version 2.13.0. We are occasionally getting HTTP 500 error in java client using OpenVidu Java SDK 2.13.0 when we call start recording. We have to restart the server to get rid of this error. It is happening almost once daily.

e[36mcoturn_1 |e[0m 374: IPv4. tcp or tls connected to: xx.xx.xx.242:10323
e[32mnginx_1 |e[0m xx.xx.xx.1 - - [06/May/2020:09:41:45 +0000] “POST /api/recordings/start HTTP/1.1” 500 78 “-” “Apache-HttpClient/4.5.8 (Java/11.0.7)” “-”
e[33mkms_1 |e[0m a=rtcp-fb:108 ccm fir
e

micael.gallego · May 14, 2020, 9:12am

Can you share OpenVidu server logs when the problem arises

Prabu_R · May 14, 2020, 9:31am

I am not able to paste the log inline due to size limitation. Log is available in https://www.dropbox.com/s/2y0yc21xmshh2yq/error.log?dl=0

Please check the last line in the log . NGINX is returning HTTP 500

micael.gallego · May 15, 2020, 6:43pm

Thank you @Prabu_R,

The next week we will take a look to recording related bugs like this.

Prabu_R · May 18, 2020, 10:09am

Thank you.

Again we got the error. This may later help you

openvidu-server_1 | [INFO] 2020-05-18 10:02:55,741 [ntExec-e2-t3199] io.openvidu.server.recording.service.SingleStreamRecordingService - Recording started event for stream str_CAM_LbHW_con_Dj4VDOWXfX
openvidu-server_1 | [ERROR] 2020-05-18 10:03:00,162 [0.0-5443-exec-3] io.openvidu.server.recording.service.SingleStreamRecordingService - Error waiting for some recorder endpoint to start in session ses_RZvbyk77eL
openvidu-server_1 | [ERROR] 2020-05-18 10:03:00,162 [0.0-5443-exec-3] io.openvidu.server.recording.service.RecordingService - Recording start failed for session ses_RZvbyk77eL: Couldn’t initialize some RecorderEndpoint
openvidu-server_1 | [INFO] 2020-05-18 10:03:00,162 [0.0-5443-exec-3] io.openvidu.server.recording.service.RecordingService - Sealed recording metadata file at /share/ipvrecs/ses_RZvbyk77eL/.recording.ses_RZvbyk77eL with status [stopped]
openvidu-server_1 | [INFO] 2020-05-18 10:03:00,162 [0.0-5443-exec-3] io.openvidu.server.recording.service.SingleStreamRecordingService - Stopping individual (video+audio) recording ses_RZvbyk77eL of session ses_RZvbyk77eL. Reason: null
openvidu-server_1 | [INFO] 2020-05-18 10:03:00,162 [0.0-5443-exec-3] io.openvidu.server.recording.service.SingleStreamRecordingService - Stopping single stream recorder for stream str_CAM_LbHW_con_Dj4VDOWXfX in session ses_RZvbyk77eL
openvidu-server_1 | [INFO] 2020-05-18 10:03:00,164 [0.0-5443-exec-3] io.openvidu.server.recording.service.SingleStreamRecordingService - Stopping single stream recorder for stream str_CAM_LeYG_con_RYwyOh1zaH in session ses_RZvbyk77eL
openvidu-server_1 | [INFO] 2020-05-18 10:03:00,205 [ntExec-e2-t3199] io.openvidu.server.recording.service.SingleStreamRecordingService - Recording stopped event for stream str_CAM_LbHW_con_Dj4VDOWXfX
openvidu-server_1 | [ERROR] 2020-05-18 10:03:05,165 [0.0-5443-exec-3] io.openvidu.server.recording.service.SingleStreamRecordingService - Error waiting for some recorder endpoint to stop in session ses_RZvbyk77eL
openvidu-server_1 | [INFO] 2020-05-18 10:03:05,181 [0.0-5443-exec-3] io.openvidu.server.recording.service.RecordingService - KMS recording file permissions successfully updated
openvidu-server_1 | [INFO] 2020-05-18 10:03:05,181 [0.0-5443-exec-3] io.openvidu.server.recording.service.RecordingService - Sealed recording metadata file at /share/ipvrecs/ses_RZvbyk77eL/.recording.ses_RZvbyk77eL with status [ready]
openvidu-server_1 | [INFO] 2020-05-18 10:03:08,096 [ntExec-e2-t3199] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [IceComponentStateChange]: -> endpoint: con_Dj4VDOWXfX_str_CAM_LeYG_con_RYwyOh1zaH (subscriber) | state: FAILED | componentId: 2 | streamId: 1 | timestamp: 1589796188095
openvidu-server_1 | [INFO] 2020-05-18 10:03:08,378 [ntExec-e2-t3199] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [IceComponentStateChange]: -> endpoint: str_CAM_LbHW_con_Dj4VDOWXfX (publisher) | state: FAILED | componentId: 2 | streamId: 1 | timestamp: 1589796188377
openvidu-server_1 | [INFO] 2020-05-18 10:03:26,137 [ntExec-e2-t3199] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaFlowOutStateChange] -> endpoint: str_CAM_LeYG_con_RYwyOh1zaH (publisher) | state: NOT_FLOWING | pad: default | mediaType: VIDEO | timestamp: 1589796206136
openvidu-server_1 | [INFO] 2020-05-18 10:03:27,097 [ntExec-e2-t3199] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaFlowInStateChange] -> endpoint: con_Dj4VDOWXfX_str_CAM_LeYG_con_RYwyOh1zaH (subscriber) | state: NOT_FLOWING | pad: default | mediaType: VIDEO | timestamp: 1589796207097
openvidu-server_1 | [INFO] 2020-05-18 10:03:27,912 [ntExec-e2-t3181] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaFlowInStateChange] -> endpoint: con_RYwyOh1zaH_str_CAM_LbHW_con_Dj4VDOWXfX (subscriber) | state: NOT_FLOWING | pad: default | mediaType: VIDEO | timestamp: 1589796207911
openvidu-server_1 | [INFO] 2020-05-18 10:03:27,912 [ntExec-e2-t3199] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaFlowInStateChange] -> endpoint: con_RYwyOh1zaH_str_CAM_LbHW_con_Dj4VDOWXfX (subscriber) | state: NOT_FLOWING | pad: default | mediaType: AUDIO | timestamp: 1589796207911
openvidu-server_1 | [INFO] 2020-05-18 10:03:29,361 [ntExec-e2-t3199] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaFlowOutStateChange] -> endpoint: str_CAM_LbHW_con_Dj4VDOWXfX (publisher) | state: NOT_FLOWING | pad: default | mediaType: AUDIO | timestamp: 1589796209360
openvidu-server_1 | [INFO] 2020-05-18 10:03:29,394 [ntExec-e2-t3199] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaFlowOutStateChange] -> endpoint: str_CAM_LbHW_con_Dj4VDOWXfX (publisher) | state: NOT_FLOWING | pad: default | mediaType: VIDEO | timestamp: 1589796209393
openvidu-server_1 | [INFO] 2020-05-18 10:03:30,047 [ntExec-e2-t3199] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaStateChangedEvent]: -> endpoint: str_CAM_LeYG_con_RYwyOh1zaH (publisher) | oldState: CONNECTED | newState: DISCONNECTED | timestamp: 1589796210046

Prabu_R · December 19, 2020, 10:40am

Environment OpenVidu Pro 2.15.1

Today we got more than 40 times we received io.openvidu.java.client.OpenViduHttpException: 500
error.

What could be the reason for this error. In general, we have noticed around 30 error in production environment for average recording request of 500 conference sessions.

Need support from OpenVidu team.

Thanks
Prabu R

pabloFuente · December 21, 2020, 10:14am

Something went wrong in OpenVidu Server. Post openvidu-server logs to see what happened.

Prabu_R · December 23, 2020, 6:23am

It is a large file and contains client IP address. client is not giving us permission to share the log with IP details

pabloFuente · December 23, 2020, 10:50am

Without it we will not be able to find out what happened. If you can’t post the logs here, then search for the error log in openvidu-server yourself.

Topic		Replies	Views
Unable to start recording Issues developing apps v2	0	596	February 9, 2021
OpenViduPro 2.15.1: Error during single session recording Issues with deployment v2	4	419	September 4, 2020
Getting 500 error code while recording Issues developing apps v2	7	1314	June 5, 2020
Recording Issue - 2.15.1 Issues developing apps v2	18	1457	February 12, 2021
Recording is not working with Openvidu 2.15.0 Issues developing apps v2	7	1757	February 10, 2021

Start Recording returns HTTP 500 - Java SDK

Related topics