No audio on COMPOSED recording of audio-only session

OpenVidu v2 Issues with deployment
1

I am trying to record an audio-only (without video) screen-sharing enabled session with OpenVidu. I tried recording the session with audio enabled and screen-sharing and video disabled using INDIVIDUAL setting, and the recording worked fine. But the recording file output is just blank (no audio, no video and no screen sharing) if I use the COMPOSED setting. I have tried with both audio enabled, screen sharing disabled and audio enabled, screen sharing enabled and the result is same i-e mp4 file without any audio or screen sharing recording.

PS: I am using ALWAYS recording mode. The version is 2.14.0, if it helps further.

2

Hi @Fawad_Khalil is this happening to you in 2.15.0? Can you share with us your OpenVidu logs and more details about your session? Is this happening for you in a production environment?

Regards,
Carlos

3

Hi @cruizba ,

Yes, this is happening in version 2.15.0 as well. Can you please specify what details about session you need? I haven’t changed configuration related to production/development environment, I guess it’s production by default. I used this link to download openvidu. Following are the logs of a session:

openvidu-server_1  | [WARN] 2020-10-03 12:15:54,950 [main] io.openvidu.server.OpenViduServer - You have set property server.port (or SERVER_PORT). This will serve OpenVidu Server on your host at port 5443. But property HTTPS_PORT (443) still configures the port that should be used to connect to OpenVidu Server from outside. Bear this in mind when configuring a proxy in front of OpenVidu Server
openvidu-server_1  | [INFO] 2020-10-03 12:15:54,950 [main] io.openvidu.server.OpenViduServer - Using /dev/urandom for secure random generation
openvidu-server_1  | [INFO] 2020-10-03 12:15:55,017 [main] io.openvidu.server.OpenViduServer - Starting OpenViduServer on terkwaz-online-classroom with PID 19 (/openvidu-server.jar started by root in /)
openvidu-server_1  | [INFO] 2020-10-03 12:15:55,019 [main] io.openvidu.server.OpenViduServer - No active profile set, falling back to default profiles: default
openvidu-server_1  | [ERROR] 2020-10-03 12:15:56,209 [main] io.openvidu.server.config.OpenviduConfig - .env file not found at /.env
openvidu-server_1  | [INFO] 2020-10-03 12:15:56,562 [main] org.springframework.boot.web.embedded.tomcat.TomcatWebServer - Tomcat initialized with port(s): 5443 (http)
openvidu-server_1  | [INFO] 2020-10-03 12:15:56,585 [main] org.apache.coyote.http11.Http11NioProtocol - Initializing ProtocolHandler ["http-nio-0.0.0.0-5443"]
openvidu-server_1  | [INFO] 2020-10-03 12:15:56,586 [main] org.apache.catalina.core.StandardService - Starting service [Tomcat]
openvidu-server_1  | [INFO] 2020-10-03 12:15:56,587 [main] org.apache.catalina.core.StandardEngine - Starting Servlet engine: [Apache Tomcat/9.0.30]
openvidu-server_1  | [INFO] 2020-10-03 12:15:56,667 [main] org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/] - Initializing Spring embedded WebApplicationContext
openvidu-server_1  | [INFO] 2020-10-03 12:15:56,668 [main] org.springframework.web.context.ContextLoader - Root WebApplicationContext: initialization completed in 1607 ms
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,062 [main] io.openvidu.server.OpenViduServer - OpenVidu CDR service is disabled (may be enable with 'OPENVIDU_CDR=true')
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,063 [main] io.openvidu.server.OpenViduServer - OpenVidu Webhook service is disabled (may be enabled with 'OPENVIDU_WEBHOOK=true')
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,076 [main] io.openvidu.server.OpenViduServer - OpenVidu Server using one KMS: ws://localhost:8888/kurento
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,097 [JsonRpcClient-hearbeatExec-e1-t0] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient]  Connecting native client
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,098 [JsonRpcClient-hearbeatExec-e1-t0] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient]  Creating new NioEventLoopGroup
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,251 [nioEventLoopGroup-2-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient]  Initiating new Netty channel. Will create new handler too!
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,370 [main] io.openvidu.server.recording.service.RecordingManager - OpenVidu recording service is enabled
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,373 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client "connected" event for KMS ws://localhost:8888/kurento [org.kurento.client.KurentoClient@7b9433f]
openvidu-server_1  | [INFO] 2020-10-03 12:15:57,580 [main] io.openvidu.server.recording.service.RecordingManager - Recording module required: Downloading openvidu/openvidu-recording:2.15.0 Docker image (350MB aprox)
openvidu-server_1  | [INFO] 2020-10-03 12:15:58,479 [main] io.openvidu.server.utils.DockerManager - Docker is installed and enabled
openvidu-server_1  | [INFO] 2020-10-03 12:15:58,479 [main] io.openvidu.server.recording.service.RecordingManager - Initializing recording paths
openvidu-server_1  | [INFO] 2020-10-03 12:15:58,483 [main] io.openvidu.server.recording.service.RecordingManager - OpenVidu Server has write permissions on recording path: /opt/openvidu/recordings/
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,071 [main] io.openvidu.server.recording.service.RecordingManager - Kurento Media Server has write permissions on recording path: /opt/openvidu/recordings/
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,079 [main] io.openvidu.server.recording.service.RecordingManager - OpenVidu Server has write permissions over files created by Kurento Media Server
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,080 [main] io.openvidu.server.recording.service.RecordingManager - OpenVidu Server has read permissions on custom layout path: /opt/openvidu/custom-layout/
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,080 [main] io.openvidu.server.recording.service.RecordingManager - Custom layouts path successfully initialized at /opt/openvidu/custom-layout/
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,080 [main] io.openvidu.server.recording.service.RecordingManager - Recording path successfully initialized at /opt/openvidu/recordings/
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,097 [main] io.openvidu.server.recording.service.RecordingManager - Docker image already exists locally
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,191 [main] io.openvidu.server.coturn.CoturnCredentialsService - COTURN IP: 157.230.26.84
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,192 [main] io.openvidu.server.coturn.CoturnCredentialsService - COTURN Redis DB accessible with string "ip=127.0.0.1 dbname=0 password=*********** connect_timeout=30"
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,192 [main] io.openvidu.server.coturn.CoturnCredentialsService - Cleaning COTURN DB...
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,193 [main] io.openvidu.server.coturn.CoturnCredentialsService - Path of COTURN log files: /var/log/
openvidu-server_1  | [ERROR] 2020-10-03 12:15:59,198 [main] io.openvidu.server.coturn.CoturnCredentialsService - COTURN DB is not empty
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,199 [main] io.openvidu.server.coturn.CoturnCredentialsService - Using COTURN credentials service for BASH environment
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,230 [main] io.openvidu.server.core.SessionManager - Garbage collector for non active sessions initialized. Running every 900 seconds and cleaning up non active Sessions more than 3600 seconds old
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,264 [main] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler - Initializing ExecutorService 'jsonrpcTaskScheduler'
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,394 [main] org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor - Initializing ExecutorService 'applicationTaskExecutor'
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,497 [main] org.springframework.boot.autoconfigure.web.servlet.WelcomePageHandlerMapping - Adding welcome page: class path resource [static/index.html]
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,734 [main] org.springframework.security.web.DefaultSecurityFilterChain - Creating filter chain: any request, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@69504ae9, org.springframework.security.web.context.SecurityContextPersistenceFilter@69c81773, org.springframework.security.web.header.HeaderWriterFilter@333d4a8c, org.springframework.web.filter.CorsFilter@6b927fb, org.springframework.security.web.authentication.logout.LogoutFilter@79207381, org.springframework.security.web.authentication.www.BasicAuthenticationFilter@47caedad, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@7e990ed7, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@4d15107f, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@387a8303, org.springframework.security.web.session.SessionManagementFilter@dc7df28, org.springframework.security.web.access.ExceptionTranslationFilter@6a8658ff, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@4f0f2942]
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,776 [main] org.apache.coyote.http11.Http11NioProtocol - Starting ProtocolHandler ["http-nio-0.0.0.0-5443"]
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,802 [main] org.springframework.boot.web.embedded.tomcat.TomcatWebServer - Tomcat started on port(s): 5443 (http) with context path ''
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,804 [main] io.openvidu.server.OpenViduServer - Started OpenViduServer in 4.842 seconds (JVM running for 7.754)
openvidu-server_1  | [INFO] 2020-10-03 12:15:59,809 [main] io.openvidu.server.OpenViduServer - 
openvidu-server_1  | 
openvidu-server_1  | ----------------------------------------------------
openvidu-server_1  | 
openvidu-server_1  |    OpenVidu is ready!
openvidu-server_1  |    ---------------------------
openvidu-server_1  | 
openvidu-server_1  |    * OpenVidu Server: https://media.classroom.terkwaz.com/
openvidu-server_1  | 
openvidu-server_1  |    * OpenVidu Dashboard: https://media.classroom.terkwaz.com/dashboard/
openvidu-server_1  | 
openvidu-server_1  | ----------------------------------------------------
openvidu-server_1  | 
openvidu-server_1  | [INFO] 2020-10-03 12:19:05,724 [http-nio-0.0.0.0-5443-exec-1] org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/] - Initializing Spring DispatcherServlet 'dispatcherServlet'
openvidu-server_1  | [INFO] 2020-10-03 12:19:05,724 [http-nio-0.0.0.0-5443-exec-1] org.springframework.web.servlet.DispatcherServlet - Initializing Servlet 'dispatcherServlet'
openvidu-server_1  | [INFO] 2020-10-03 12:19:05,733 [http-nio-0.0.0.0-5443-exec-1] org.springframework.web.servlet.DispatcherServlet - Completed initialization in 9 ms
openvidu-server_1  | [INFO] 2020-10-03 12:19:06,222 [http-nio-0.0.0.0-5443-exec-2] io.openvidu.server.rest.SessionRestController - REST API: POST /api/sessions {customSessionId=q1Srba, recordingMode=ALWAYS}
openvidu-server_1  | [INFO] 2020-10-03 12:19:06,227 [http-nio-0.0.0.0-5443-exec-2] io.openvidu.server.rest.SessionRestController - New session q1Srba initialized [q1Srba]
openvidu-server_1  | [INFO] 2020-10-03 12:19:06,698 [http-nio-0.0.0.0-5443-exec-4] io.openvidu.server.rest.SessionRestController - REST API: POST /api/tokens {session=q1Srba}
openvidu-server_1  | [INFO] 2020-10-03 12:19:06,703 [http-nio-0.0.0.0-5443-exec-4] io.openvidu.server.coturn.CoturnCredentialsService - Creating COTURN user
openvidu-server_1  | [INFO] 2020-10-03 12:19:06,727 [http-nio-0.0.0.0-5443-exec-4] io.openvidu.server.coturn.CoturnCredentialsService - COTURN user created: true
openvidu-server_1  | [INFO] 2020-10-03 12:19:06,730 [http-nio-0.0.0.0-5443-exec-4] io.openvidu.server.core.Session - Token created { Session: q1Srba | Tokens: [wss://media.classroom.terkwaz.com?sessionId=q1Srba&token=tok_NThH3FciuSVo6TVj&role=PUBLISHER&version=2.15.0&coturnIp=157.230.26.84&turnUsername=HJ0KIO&turnCredential=3atkrn] }
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,333 [http-nio-0.0.0.0-5443-exec-5] io.openvidu.server.config.HttpHandshakeInterceptor - New HttpSession 90F1E63ADD03063D2A89EB4DC4AA5109
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,557 [http-nio-0.0.0.0-5443-exec-6] io.openvidu.server.rpc.RpcHandler - After connection established for WebSocket session: k3a5vdpfqnc0406vab4dr09q7g
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,566 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.core.Session - Token consumed { Session: q1Srba | Tokens: [] }
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,568 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.core.SessionManager - Participant con_Mqa8yupwSL of session q1Srba is a final user connecting to this session for the first time
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,570 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoSessionManager - KMS less loaded is ws://localhost:8888/kurento with a load of 1.0
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,572 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoSessionManager - No session 'q1Srba' exists yet. Created one on KMS 'kms_FP9u8b2W' with ip 'localhost'
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,573 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoSession - SESSION q1Srba: Creating MediaPipeline
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,599 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoSession - SESSION q1Srba: Added participant [participantPrivateId=k3a5vdpfqnc0406vab4dr09q7g, participantPublicId=con_Mqa8yupwSL, streaming=false]
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,804 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL is calling method 'signal' in session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:07,857 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL is calling method 'publish' in session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,058 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoParticipant - PARTICIPANT con_Mqa8yupwSL: Request to publish video in room q1Srba (sdp type OFFER)
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,197 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoParticipant - PARTICIPANT con_Mqa8yupwSL: Is now publishing video in room q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,202 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL is calling method 'onIceCandidate' in session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,209 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - New candidate received from participant con_Mqa8yupwSL: {connectionId: "con_Mqa8yupwSL", sdpMid: 0, sdpMLineIndex: 0, candidate: "candidate:2901037939 1 udp 2122260223 192.168.8.100 50755 typ host generation 0 ufrag p+q7 network-id 1 network-cost 10"}
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,218 [Thread-5] io.openvidu.server.recording.service.RecordingService - New recording id (q1Srba) and final name (q1Srba)
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,228 [Thread-5] io.openvidu.server.recording.service.ComposedRecordingService - Starting composed (video + audio) recording q1Srba of session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,233 [Thread-5] io.openvidu.server.recording.service.ComposedRecordingService - {"id":"q1Srba","name":"q1Srba","outputMode":"COMPOSED","resolution":"1920x1080","recordingLayout":"BEST_FIT","sessionId":"q1Srba","createdAt":1601727548228,"size":0,"duration":0.0,"url":null,"hasAudio":true,"hasVideo":true,"status":"started"}
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,237 [Thread-5] io.openvidu.server.recording.service.ComposedRecordingService - Recorder connecting to url https://OPENVIDUAPP:**********@media.classroom.terkwaz.com/dashboard/#/layout-best-fit/q1Srba/***********/-1/false
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,232 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL is calling method 'onIceCandidate' in session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,237 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - New candidate received from participant con_Mqa8yupwSL: {connectionId: "con_Mqa8yupwSL", sdpMid: 0, sdpMLineIndex: 0, candidate: "candidate:3798577027 1 tcp 1518280447 192.168.8.100 9 typ host tcptype active generation 0 ufrag p+q7 network-id 1 network-cost 10"}
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,239 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL is calling method 'onIceCandidate' in session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,239 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - New candidate received from participant con_Mqa8yupwSL: {connectionId: "con_Mqa8yupwSL", sdpMid: 0, sdpMLineIndex: 0, candidate: "candidate:765613511 1 udp 1686052607 111.119.187.55 55423 typ srflx raddr 192.168.8.100 rport 50755 generation 0 ufrag p+q7 network-id 1 network-cost 10"}
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,266 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t5] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [IceComponentStateChange]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | state: GATHERING | componentId: 1 | streamId: 1 | timestamp: 1601727548208
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,284 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t3] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [IceComponentStateChange]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | state: CONNECTING | componentId: 1 | streamId: 1 | timestamp: 1601727548220
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,287 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t2] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [IceComponentStateChange]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | state: GATHERING | componentId: 2 | streamId: 1 | timestamp: 1601727548242
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,297 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL is calling method 'onIceCandidate' in session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,297 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - New candidate received from participant con_Mqa8yupwSL: {connectionId: "con_Mqa8yupwSL", sdpMid: 0, sdpMLineIndex: 0, candidate: "candidate:960296037 1 udp 41885695 157.230.26.84 65529 typ relay raddr 111.119.187.55 rport 55423 generation 0 ufrag p+q7 network-id 1 network-cost 10"}
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,479 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL is calling method 'onIceCandidate' in session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,479 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - New candidate received from participant con_Mqa8yupwSL: {connectionId: "con_Mqa8yupwSL", sdpMid: 0, sdpMLineIndex: 0, candidate: "candidate:2009008277 1 udp 25108223 157.230.26.84 62603 typ relay raddr 111.119.187.55 rport 21551 generation 0 ufrag p+q7 network-id 1 network-cost 10"}
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,601 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t7] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [NewCandidatePairSelected]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | local: candidate:1 1 UDP 2015363327 157.230.26.84 40569 typ host | remote: candidate:remote1 1 UDP 1853824767 111.119.187.55 31939 typ prflx | timestamp: 1601727548599
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,603 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t3] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [IceComponentStateChange]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | state: CONNECTED | componentId: 1 | streamId: 1 | timestamp: 1601727548599
openvidu-server_1  | [INFO] 2020-10-03 12:19:08,806 [Thread-5] io.openvidu.server.utils.DockerManager - Container ID: b131f5c2dec4d00d688a0b14508f33e077d2157a59868e0d8faf130c67433a38
openvidu-server_1  | [INFO] 2020-10-03 12:19:09,601 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t3] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [ConnectionStateChanged]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | oldState: DISCONNECTED | newState: CONNECTED | timestamp: 1601727549599
openvidu-server_1  | [INFO] 2020-10-03 12:19:09,667 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t3] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaFlowOutStateChange] -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | state: FLOWING | pad: default | mediaType: AUDIO | timestamp: 1601727549662
openvidu-server_1  | [INFO] 2020-10-03 12:19:09,674 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t7] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaTranscodingStateChange]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | state: NOT_TRANSCODING | mediaType: AUDIO | binName: kmsagnosticbin2-2 | timestamp: 1601727549662
openvidu-server_1  | [INFO] 2020-10-03 12:19:10,282 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t7] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [IceGatheringDone] -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | timestamp: 1601727550279
openvidu-server_1  | [INFO] 2020-10-03 12:19:10,287 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t3] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [IceComponentStateChange]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | state: READY | componentId: 1 | streamId: 1 | timestamp: 1601727550279
openvidu-server_1  | [INFO] 2020-10-03 12:19:10,358 [AbstractJsonRpcClientWebSocket-reqResEventExec-e2-t3] io.openvidu.server.kurento.core.KurentoParticipantEndpointConfig - KMS event [MediaStateChangedEvent]: -> endpoint: str_MIC_G94m_con_Mqa8yupwSL (publisher) | oldState: DISCONNECTED | newState: CONNECTED | timestamp: 1601727550356
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,476 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL is calling method 'disconnect' in session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,476 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoSessionManager - Request [LEAVE_ROOM] for participant con_Mqa8yupwSL of session q1Srba with reason disconnect
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,477 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoSession - PARTICIPANT con_Mqa8yupwSL: Leaving session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,504 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.coturn.CoturnCredentialsService - Deleting COTURN user
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,555 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.coturn.CoturnCredentialsService - COTURN user deleted: true
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,556 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.kurento.core.KurentoSessionManager - Last participant left. Starting 60 seconds countdown for stopping recording of session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,560 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcNotificationService - Closed session for participant with private id k3a5vdpfqnc0406vab4dr09q7g
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,560 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcNotificationService - <PRIVATE_ID, RPC_CONNECTION>: {}
openvidu-server_1  | [INFO] 2020-10-03 12:19:24,560 [SessionHandler-k3a5vdpfqnc0406vab4dr09q7g-e4-t0] io.openvidu.server.rpc.RpcHandler - Participant con_Mqa8yupwSL has left session q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:19:34,559 [jsonrpcTaskScheduler-1] io.openvidu.server.rpc.RpcHandler - After connection closed for WebSocket session: k3a5vdpfqnc0406vab4dr09q7g - Status: null
openvidu-server_1  | [INFO] 2020-10-03 12:20:24,557 [pool-1-thread-1] io.openvidu.server.recording.service.RecordingManager - Stopping recording q1Srba after 60 seconds wait (no publisher published before timeout)
openvidu-server_1  | [INFO] 2020-10-03 12:20:24,558 [pool-1-thread-1] io.openvidu.server.recording.service.RecordingManager - Closing session q1Srba after automatic stop of recording q1Srba
openvidu-server_1  | [INFO] 2020-10-03 12:20:24,561 [pool-1-thread-1] io.openvidu.server.recording.service.RecordingService - Sealed recording metadata file at /opt/openvidu/recordings/q1Srba/.recording.q1Srba with status [stopped]
openvidu-server_1  | [INFO] 2020-10-03 12:20:24,561 [pool-1-thread-1] io.openvidu.server.recording.service.ComposedRecordingService - Stopping composed (video + audio) recording q1Srba of session q1Srba. Reason: automaticStop
openvidu-server_1  | [INFO] 2020-10-03 12:20:25,554 [pool-1-thread-1] io.openvidu.server.recording.service.RecordingService - Sealed recording metadata file at /opt/openvidu/recordings/q1Srba/.recording.q1Srba with status [ready]
openvidu-server_1  | [INFO] 2020-10-03 12:20:25,561 [pool-1-thread-1] io.openvidu.server.core.SessionManager - Session 'q1Srba' removed and closed