OVP Fails to restart after Christmas/ New Year Shutdown

Good Morning,

Came back after Christmas/ New Year shutdown to restart OVP - running on ubuntu within Azure environment. We have 2 tagged KMS Nodes as well. Working fine before Christmas, but on restart it’s coming back with a failure - Excerpts from the log below:

[INFO] 2021-01-04 09:07:19,366 [main] io.openvidu.server.pro.OpenViduServerPro - Starting OpenViduServerPro on XXXXXXXXXXXXXXXXXXXXX with PID 222 (/opt/openvidu/openvidu-server.jar started by root in /opt/openvidu)
[INFO] 2021-01-04 09:07:19,372 [main] io.openvidu.server.pro.OpenViduServerPro - No active profile set, falling back to default profiles: default
[INFO] 2021-01-04 09:07:19,880 [main] io.openvidu.server.config.OpenviduConfig - Configuration properties read from file /opt/openvidu/.env
[INFO] 2021-01-04 09:07:20,076 [main] io.openvidu.server.pro.OpenViduServerPro - Started OpenViduServerPro in 2.017 seconds (JVM running for 2.651)
[INFO] 2021-01-04 09:07:20,085 [main] io.openvidu.server.OpenViduServer -

Configuration properties
------------------------

* CERTIFICATE_TYPE=letsencrypt
* DOMAIN_OR_PUBLIC_IP=xxxxxxxxxxxxxxx.uksouth.cloudapp.azure.com
* HTTPS_PORT=443
* KMS_URIS=["ws://172.16.4.37:8888/kurento", "ws://172.16.4.36:8888/kurento"]
* OPENVIDU_CDR=false
* OPENVIDU_CDR_PATH=/opt/openvidu/cdr
* OPENVIDU_PRO_CHECK_DIND_UPDATES=true
* OPENVIDU_PRO_CLUSTER=true
* OPENVIDU_PRO_CLUSTER_AUTOSCALING=false
* OPENVIDU_PRO_CLUSTER_AUTOSCALING_INTERVAL=10
* OPENVIDU_PRO_CLUSTER_AUTOSCALING_MAX_LOAD=70
* OPENVIDU_PRO_CLUSTER_AUTOSCALING_MAX_NODES=2
* OPENVIDU_PRO_CLUSTER_AUTOSCALING_MIN_LOAD=30
* OPENVIDU_PRO_CLUSTER_AUTOSCALING_MIN_NODES=1
* OPENVIDU_PRO_CLUSTER_ENVIRONMENT=on_premise
* OPENVIDU_PRO_CLUSTER_ID=
* OPENVIDU_PRO_CLUSTER_LOAD_INTERVAL=3
* OPENVIDU_PRO_CLUSTER_MEDIA_NODES=1
* OPENVIDU_PRO_CLUSTER_MODE=manual
* OPENVIDU_PRO_CLUSTER_PATH=/opt/openvidu/cluster
* OPENVIDU_PRO_CLUSTER_TEST=false
* OPENVIDU_PRO_ELASTICSEARCH_MAX_DAYS_DELETE=0
* OPENVIDU_PRO_LICENSE=XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXx
* OPENVIDU_PRO_PRIVATE_IP=
* OPENVIDU_PRO_STATS_MONITORING_INTERVAL=30
* OPENVIDU_PRO_STATS_WEBRTC_INTERVAL=30
* OPENVIDU_RECORDING=true
* OPENVIDU_RECORDING_AUTOSTOP_TIMEOUT=240
* OPENVIDU_RECORDING_COMPOSED_URL=
* OPENVIDU_RECORDING_CUSTOM_LAYOUT=/opt/openvidu/custom-layout
* OPENVIDU_RECORDING_DEBUG=true
* OPENVIDU_RECORDING_NOTIFICATION=publisher_moderator
* OPENVIDU_RECORDING_PATH=/opt/openvidu/recordings
* OPENVIDU_RECORDING_PUBLIC_ACCESS=true
* OPENVIDU_RECORDING_VERSION=2.15.0
* OPENVIDU_SECRET=XXXXXXXXXXXXXXXXXXXXXXXX
* OPENVIDU_SESSIONS_GARBAGE_INTERVAL=900
* OPENVIDU_SESSIONS_GARBAGE_THRESHOLD=3600
* OPENVIDU_STREAMS_VIDEO_MAX_RECV_BANDWIDTH=1000
* OPENVIDU_STREAMS_VIDEO_MAX_SEND_BANDWIDTH=1000
* OPENVIDU_STREAMS_VIDEO_MIN_RECV_BANDWIDTH=200
* OPENVIDU_STREAMS_VIDEO_MIN_SEND_BANDWIDTH=200
* OPENVIDU_WEBHOOK=true
* OPENVIDU_WEBHOOK_ENDPOINT=https://XXXXXXXXXXXXXXXXXXXXXX.uksouth.cloudapp.azure.com:8084/api/recordingwebhook
* OPENVIDU_WEBHOOK_EVENTS=["recordingStatusChanged"]
* OPENVIDU_WEBHOOK_HEADERS=["Authorization: \"Basic xxxxxxxxxxxxxxxxxxxxxxxxxxx\""]

[INFO] 2021-01-04 09:07:21,017 [main] io.openvidu.server.pro.OpenViduServerPro - No active profile set, falling back to default profiles: default
[INFO] 2021-01-04 09:07:21,039 [main] io.openvidu.server.config.OpenviduConfig - Configuration properties read from file /opt/openvidu/.env
[INFO] 2021-01-04 09:07:21,043 [main] io.openvidu.server.pro.OpenViduServerPro - Started OpenViduServerPro in 0.085 seconds (JVM running for 3.618)
[INFO] 2021-01-04 09:07:21,044 [main] io.openvidu.server.pro.OpenViduServerPro - Checking KMS_URIS [ws://172.16.4.37:8888/kurento, ws://172.16.4.36:8888/kurento]
[INFO] 2021-01-04 09:07:21,044 [main] io.openvidu.server.config.OpenviduConfig - Waiting for KMS instance ws://172.16.4.37:8888/kurento to be ready for a maximum of 120 seconds (maximum 120 connection attempts with a wait interval of 1000 ms between them)
[INFO] 2021-01-04 09:07:21,072 [JsonRpcClient-hearbeatExec-e1-t0] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Connecting native client
[INFO] 2021-01-04 09:07:21,072 [JsonRpcClient-hearbeatExec-e1-t0] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Creating new NioEventLoopGroup
[INFO] 2021-01-04 09:07:21,331 [nioEventLoopGroup-2-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Initiating new Netty channel. Will create new handler too!
[INFO] 2021-01-04 09:07:21,464 [main] io.openvidu.server.config.OpenviduConfig - KMS with URI ws://172.16.4.37:8888/kurento is now ready after 1 seconds at connection attempt 1
[WARN] 2021-01-04 09:07:21,484 [JsonRpcClient-hearbeatExec-e1-t0] org.kurento.jsonrpc.client.JsonRpcClient - [KurentoClient] Error sending heartbeat to server. Exception: [KurentoClient] Interrupted while waiting for a response
[WARN] 2021-01-04 09:07:21,485 [JsonRpcClient-hearbeatExec-e1-t0] org.kurento.jsonrpc.client.JsonRpcClient - [KurentoClient] Stopping heartbeat and closing client: failure during heartbeat mechanism
[WARN] 2021-01-04 09:07:21,506 [main] org.kurento.jsonrpc.client.AbstractJsonRpcClientWebSocket - [KurentoClient] Exception sending close message. org.kurento.jsonrpc.JsonRpcErrorException:‘params’ is requiered. Code: -32602. Data: {“type”:“INVALID_PARAMS”}
[INFO] 2021-01-04 09:07:21,508 [nioEventLoopGroup-2-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] channel closed
[WARN] 2021-01-04 09:07:21,517 [main] org.kurento.jsonrpc.client.AbstractJsonRpcClientWebSocket - [KurentoClient] Exception sending close message. org.kurento.jsonrpc.JsonRpcClientClosedException:Trying to send a message in a client closed explicitly. When a client is closed, it can’t be reused. It is necessary to create another one
[WARN] 2021-01-04 09:07:21,518 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Trying to close a JsonRpcClientNettyWebSocket with channel == null
[WARN] 2021-01-04 09:07:21,518 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Trying to close a JsonRpcClientNettyWebSocket with group == null
[INFO] 2021-01-04 09:07:21,519 [main] io.openvidu.server.config.OpenviduConfig - Waiting for KMS instance ws://172.16.4.36:8888/kurento to be ready for a maximum of 120 seconds (maximum 120 connection attempts with a wait interval of 1000 ms between them)
[INFO] 2021-01-04 09:07:21,521 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Connecting native client
[INFO] 2021-01-04 09:07:21,522 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Creating new NioEventLoopGroup
[INFO] 2021-01-04 09:07:21,528 [nioEventLoopGroup-3-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Initiating new Netty channel. Will create new handler too!
[INFO] 2021-01-04 09:07:21,541 [main] io.openvidu.server.config.OpenviduConfig - KMS with URI ws://172.16.4.36:8888/kurento is now ready after 1 seconds at connection attempt 1
[WARN] 2021-01-04 09:07:21,545 [JsonRpcClient-hearbeatExec-e2-t0] org.kurento.jsonrpc.client.JsonRpcClient - [KurentoClient] Error sending heartbeat to server. Exception: [KurentoClient] Interrupted while waiting for a response
[WARN] 2021-01-04 09:07:21,545 [JsonRpcClient-hearbeatExec-e2-t0] org.kurento.jsonrpc.client.JsonRpcClient - [KurentoClient] Stopping heartbeat and closing client: failure during heartbeat mechanism
[WARN] 2021-01-04 09:07:21,548 [main] org.kurento.jsonrpc.client.AbstractJsonRpcClientWebSocket - [KurentoClient] Exception sending close message. org.kurento.jsonrpc.JsonRpcErrorException:‘params’ is requiered. Code: -32602. Data: {“type”:“INVALID_PARAMS”}
[INFO] 2021-01-04 09:07:21,548 [nioEventLoopGroup-3-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] channel closed
[WARN] 2021-01-04 09:07:21,555 [main] org.kurento.jsonrpc.client.AbstractJsonRpcClientWebSocket - [KurentoClient] Exception sending close message. org.kurento.jsonrpc.JsonRpcClientClosedException:Trying to send a message in a client closed explicitly. When a client is closed, it can’t be reused. It is necessary to create another one
[WARN] 2021-01-04 09:07:21,555 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Trying to close a JsonRpcClientNettyWebSocket with channel == null
[WARN] 2021-01-04 09:07:21,555 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Trying to close a JsonRpcClientNettyWebSocket with group == null
[WARN] 2021-01-04 09:07:21,556 [main] io.openvidu.server.pro.OpenViduServerPro - You have set property server.port (or SERVER_PORT). This will serve OpenVidu Server Pro 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
[INFO] 2021-01-04 09:07:21,764 [main] io.openvidu.server.pro.OpenViduServerPro - Starting OpenViduServerPro on XXXXXXXXXXXXXXXXXXXXX with PID 222 (/opt/openvidu/openvidu-server.jar started by root in /opt/openvidu)
[INFO] 2021-01-04 09:07:21,767 [main] io.openvidu.server.pro.OpenViduServerPro - No active profile set, falling back to default profiles: default
[INFO] 2021-01-04 09:07:23,437 [main] io.openvidu.server.config.OpenviduConfig - Configuration properties read from file /opt/openvidu/.env
[INFO] 2021-01-04 09:07:23,839 [main] org.springframework.boot.web.embedded.tomcat.TomcatWebServer - Tomcat initialized with port(s): 5443 (http)
[INFO] 2021-01-04 09:07:23,849 [main] org.apache.catalina.core.StandardService - Starting service [Tomcat]
[INFO] 2021-01-04 09:07:23,849 [main] org.apache.catalina.core.StandardEngine - Starting Servlet engine: [Apache Tomcat/9.0.30]
[INFO] 2021-01-04 09:07:23,905 [main] org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/] - Initializing Spring embedded WebApplicationContext
[INFO] 2021-01-04 09:07:23,906 [main] org.springframework.web.context.ContextLoader - Root WebApplicationContext: initialization completed in 2115 ms
[INFO] 2021-01-04 09:07:24,254 [main] io.openvidu.server.config.OpenviduConfig - Configuration properties read from file /opt/openvidu/.env
[INFO] 2021-01-04 09:07:24,354 [main] io.openvidu.server.pro.OpenViduServerPro - OpenVidu Pro is deployed in ‘on_premise’ environment
[WARN] 2021-01-04 09:07:24,355 [main] io.openvidu.server.pro.OpenViduServerPro - OpenVidu Pro cluster mode is ‘manual’. There will be no automatic instances management
[INFO] 2021-01-04 09:07:24,377 [main] io.openvidu.server.pro.OpenViduServerPro - OpenVidu Pro cluster mode enabled
[INFO] 2021-01-04 09:07:24,379 [main] io.openvidu.server.pro.OpenViduServerPro - Cluster identifier got from disk: clu_EVqEXlyW
[INFO] 2021-01-04 09:07:24,389 [main] io.openvidu.server.pro.OpenViduServerPro - OpenVidu Pro Elasticsearch service is enabled
[INFO] 2021-01-04 09:07:24,733 [main] io.openvidu.server.pro.cdr.CDRLoggerElasticSearch - Elasticsearch is accessible at 127.0.0.1:9200
[INFO] 2021-01-04 09:07:24,759 [main] io.openvidu.server.pro.cdr.CDRLoggerElasticSearch - Elasticsearch version is 7.8.0
[INFO] 2021-01-04 09:07:24,787 [main] io.openvidu.server.pro.cdr.CDRLoggerElasticSearch - Elasticsearch index “openvidu” already exists
[INFO] 2021-01-04 09:07:24,787 [main] io.openvidu.server.pro.OpenViduServerPro - OpenVidu Pro CDR service is disabled (may be enable with ‘OPENVIDU_CDR=true’)
[INFO] 2021-01-04 09:07:24,787 [main] io.openvidu.server.pro.OpenViduServerPro - OpenVidu Pro Webhook service is enabled
[INFO] 2021-01-04 09:07:24,797 [main] io.openvidu.server.kurento.kms.KmsManager - OpenVidu Server Pro is deployed with ‘OPENVIDU_PRO_CLUSTER_MODE’ set to ‘manual’. Initializing Media Nodes defined in parameter ‘KMS_URIS’: [ws://172.16.4.37:8888/kurento, ws://172.16.4.36:8888/kurento]
[INFO] 2021-01-04 09:07:24,836 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Connecting native client
[INFO] 2021-01-04 09:07:24,836 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Creating new NioEventLoopGroup
[INFO] 2021-01-04 09:07:24,851 [nioEventLoopGroup-4-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Initiating new Netty channel. Will create new handler too!
[INFO] 2021-01-04 09:07:24,867 [I/O dispatcher 1] io.openvidu.server.pro.cdr.CDRLoggerElasticSearch - New event of type “cdr” sent to Elasticsearch: {“timestamp”:1609751244803,“id”:“kms_HAr7w80f”,“environmentId”:null,“ip”:“172.16.4.37”,“uri”:“ws://172.16.4.37:8888/kurento”,“newStatus”:“launching”,“oldStatus”:null,“clusterId”:“clu_EVqEXlyW”,“event”:“mediaNodeStatusChanged”,“elastic_type”:“cdr”}
[INFO] 2021-01-04 09:07:24,875 [AbstractJsonRpcClientWebSocket-reqResEventExec-e4-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client “connected” event for KMS ws://172.16.4.37:8888/kurento [org.kurento.client.KurentoClient@1ad34100]
[INFO] 2021-01-04 09:07:24,883 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Connecting native client
[INFO] 2021-01-04 09:07:24,883 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Creating new NioEventLoopGroup
[INFO] 2021-01-04 09:07:24,899 [nioEventLoopGroup-5-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Initiating new Netty channel. Will create new handler too!
[INFO] 2021-01-04 09:07:24,926 [AbstractJsonRpcClientWebSocket-reqResEventExec-e7-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client “connected” event for KMS ws://172.16.4.36:8888/kurento [org.kurento.client.KurentoClient@fbd9d61]
[INFO] 2021-01-04 09:07:24,927 [main] io.openvidu.server.kurento.kms.KmsManager - All KMSs in [ws://172.16.4.37:8888/kurento, ws://172.16.4.36:8888/kurento] are within reach of OpenVidu Server
[INFO] 2021-01-04 09:07:25,065 [main] io.openvidu.server.pro.account.ClusterUsageService - Media Node kms_HAr7w80f registered into usage service
[INFO] 2021-01-04 09:07:25,085 [main] io.openvidu.server.pro.account.ClusterUsageService - Media Node kms_VAflFMF4 registered into usage service
[INFO] 2021-01-04 09:07:25,163 [main] io.openvidu.server.recording.service.RecordingManager - OpenVidu recording service is enabled
[ERROR] 2021-01-04 09:07:25,192 [I/O dispatcher 1] io.openvidu.server.pro.cdr.CDRLoggerElasticSearch - Sending event of type “cdr” to Elasticsearch failure: Elasticsearch exception [type=circuit_breaking_exception, reason=[parent] Data too large, data for [<http_request>] would be [1024647832/977.1mb], which is larger than the limit of [1020054732/972.7mb], real usage: [1024647328/977.1mb], new bytes reserved: [504/504b], usages [request=0/0b, fielddata=0/0b, in_flight_requests=7986/7.7kb, accounting=43187564/41.1mb]]
[ERROR] 2021-01-04 09:07:25,193 [I/O dispatcher 2] io.openvidu.server.pro.cdr.CDRLoggerElasticSearch - Sending event of type “cdr” to Elasticsearch failure: Elasticsearch exception [type=circuit_breaking_exception, reason=[parent] Data too large, data for [<http_request>] would be [1021848870/974.5mb], which is larger than the limit of [1020054732/972.7mb], real usage: [1021848376/974.5mb], new bytes reserved: [494/494b], usages [request=0/0b, fielddata=0/0b, in_flight_requests=494/494b, accounting=43187564/41.1mb]]
[INFO] 2021-01-04 09:07:25,209 [I/O dispatcher 2] io.openvidu.server.pro.cdr.CDRLoggerElasticSearch - New event of type “cdr” sent to Elasticsearch: {“timestamp”:1609751244929,“id”:“kms_HAr7w80f”,“environmentId”:null,“ip”:“172.16.4.37”,“uri”:“ws://172.16.4.37:8888/kurento”,“newStatus”:“running”,“oldStatus”:“launching”,“clusterId”:“clu_EVqEXlyW”,“event”:“mediaNodeStatusChanged”,“elastic_type”:“cdr”}
[INFO] 2021-01-04 09:07:25,504 [main] io.openvidu.server.recording.service.RecordingManager - Recording module required: Downloading openvidu/openvidu-recording:2.15.0 Docker image (350MB aprox)
[INFO] 2021-01-04 09:07:25,896 [Thread-3] io.openvidu.server.pro.account.LambdaService - License GET HTTP status: HTTP/1.1 200 OK
[INFO] 2021-01-04 09:07:26,164 [main] io.openvidu.server.utils.DockerManager - Docker is installed and enabled
[INFO] 2021-01-04 09:07:26,164 [main] io.openvidu.server.recording.service.RecordingManager - Initializing recording paths
[INFO] 2021-01-04 09:07:26,167 [main] io.openvidu.server.recording.service.RecordingManager - OpenVidu Server has write permissions on recording path: /opt/openvidu/recordings/
[INFO] 2021-01-04 09:07:26,733 [main] io.openvidu.server.recording.service.RecordingManager - Kurento Media Server has write permissions on recording path: /opt/openvidu/recordings/
[INFO] 2021-01-04 09:07:26,743 [main] io.openvidu.server.recording.service.RecordingManager - OpenVidu Server has write permissions over files created by Kurento Media Server
[INFO] 2021-01-04 09:07:26,743 [main] io.openvidu.server.recording.service.RecordingManager - OpenVidu Server has read permissions on custom layout path: /opt/openvidu/custom-layout/
[INFO] 2021-01-04 09:07:26,743 [main] io.openvidu.server.recording.service.RecordingManager - Custom layouts path successfully initialized at /opt/openvidu/custom-layout/
[INFO] 2021-01-04 09:07:26,743 [main] io.openvidu.server.recording.service.RecordingManager - Recording path successfully initialized at /opt/openvidu/recordings/
[INFO] 2021-01-04 09:07:27,077 [main] io.openvidu.server.recording.service.RecordingManager - Docker image already exists locally
[INFO] 2021-01-04 09:07:27,146 [main] io.openvidu.server.coturn.CoturnCredentialsService - COTURN IP: 51.11.176.85
[INFO] 2021-01-04 09:07:27,146 [main] io.openvidu.server.coturn.CoturnCredentialsService - COTURN Redis DB accessible with string “ip=127.0.0.1 dbname=0 password=XXXXXXXXXXXXXXXXXXXXX connect_timeout=30”
[INFO] 2021-01-04 09:07:27,146 [main] io.openvidu.server.coturn.CoturnCredentialsService - Cleaning COTURN DB…
[INFO] 2021-01-04 09:07:27,146 [main] io.openvidu.server.coturn.CoturnCredentialsService - Path of COTURN log files: /var/log/
[INFO] 2021-01-04 09:07:27,163 [main] io.openvidu.server.coturn.CoturnCredentialsService - COTURN DB is now empty
[INFO] 2021-01-04 09:07:27,163 [main] io.openvidu.server.coturn.CoturnCredentialsService - Using COTURN credentials service for BASH environment
[INFO] 2021-01-04 09:07:27,169 [main] io.openvidu.server.pro.utils.GeoLocationByIpPro - Trying to load user location database…
[INFO] 2021-01-04 09:07:27,659 [main] io.openvidu.server.pro.utils.GeoLocationByIpPro - Database was loaded successfully
[INFO] 2021-01-04 09:07:27,665 [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
[INFO] 2021-01-04 09:07:27,709 [main] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler - Initializing ExecutorService ‘jsonrpcTaskScheduler’
[INFO] 2021-01-04 09:07:27,740 [main] io.openvidu.server.pro.OpenViduServerPro - OpenVidu Pro autoscaling service is disabled
[INFO] 2021-01-04 09:07:27,746 [main] io.openvidu.server.pro.infrastructure.metrics.MetricBeatsServer - Listen at 5044 Beats Port
[INFO] 2021-01-04 09:07:27,800 [main] io.openvidu.server.pro.config.KibanaConfig - Kibana is accessible at http://127.0.0.1/kibana
[INFO] 2021-01-04 09:07:27,800 [main] io.openvidu.server.pro.config.KibanaConfig - Kibana version is 7.8.0
[INFO] 2021-01-04 09:07:27,841 [main] io.openvidu.server.pro.config.KibanaConfig - Kibana already has default dashboards imported [OpenVidu Recordings, OpenVidu Sessions, OpenVidu Clustering]
[INFO] 2021-01-04 09:07:27,853 [main] io.openvidu.server.pro.config.ElasticSearchConfig - Creating Elasticsearch index “filebeat-openvidu-2021.01.04”
[WARN] 2021-01-04 09:07:27,935 [main] org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext - Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name ‘elasticSearchConfig’: Invocation of init method failed; nested exception is ElasticsearchStatusException[Elasticsearch exception [type=validation_exception, reason=Validation Failed: 1: this action would add [2] total shards, but this cluster currently has [1000]/[1000] maximum shards open;]]
[INFO] 2021-01-04 09:07:27,935 [main] io.openvidu.server.pro.infrastructure.metrics.MetricBeatsServer - Shuting down Beats server gracefully…
[INFO] 2021-01-04 09:07:33,968 [main] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler - Shutting down ExecutorService ‘jsonrpcTaskScheduler’
[INFO] 2021-01-04 09:07:33,968 [main] org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler - Shutting down ExecutorService ‘jsonrpcTaskScheduler’
[INFO] 2021-01-04 09:07:33,969 [main] io.openvidu.server.kurento.kms.KmsManager - Closing all KurentoClients
[INFO] 2021-01-04 09:07:33,972 [AbstractJsonRpcClientWebSocket-reqResEventExec-e4-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client “disconnected” event for KMS ws://172.16.4.37:8888/kurento [org.kurento.client.KurentoClient@1ad34100]. Closed explicitly
[INFO] 2021-01-04 09:07:33,972 [nioEventLoopGroup-4-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] channel closed
[INFO] 2021-01-04 09:07:33,972 [AbstractJsonRpcClientWebSocket-reqResEventExec-e4-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client “disconnected” event for KMS ws://172.16.4.37:8888/kurento [org.kurento.client.KurentoClient@1ad34100]. Closed explicitly
[WARN] 2021-01-04 09:07:33,975 [main] org.kurento.jsonrpc.client.AbstractJsonRpcClientWebSocket - [KurentoClient] Exception sending close message. org.kurento.jsonrpc.JsonRpcClientClosedException:Trying to send a message in a client closed explicitly. When a client is closed, it can’t be reused. It is necessary to create another one
[WARN] 2021-01-04 09:07:33,975 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Trying to close a JsonRpcClientNettyWebSocket with channel == null
[WARN] 2021-01-04 09:07:33,975 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Trying to close a JsonRpcClientNettyWebSocket with group == null
[INFO] 2021-01-04 09:07:33,979 [AbstractJsonRpcClientWebSocket-reqResEventExec-e9-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client “disconnected” event for KMS ws://172.16.4.37:8888/kurento [org.kurento.client.KurentoClient@1ad34100]. Closed explicitly
[INFO] 2021-01-04 09:07:33,981 [AbstractJsonRpcClientWebSocket-reqResEventExec-e7-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client “disconnected” event for KMS ws://172.16.4.36:8888/kurento [org.kurento.client.KurentoClient@fbd9d61]. Closed explicitly
[INFO] 2021-01-04 09:07:33,981 [nioEventLoopGroup-5-1] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] channel closed
[INFO] 2021-01-04 09:07:33,981 [AbstractJsonRpcClientWebSocket-reqResEventExec-e7-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client “disconnected” event for KMS ws://172.16.4.36:8888/kurento [org.kurento.client.KurentoClient@fbd9d61]. Closed explicitly
[WARN] 2021-01-04 09:07:33,984 [main] org.kurento.jsonrpc.client.AbstractJsonRpcClientWebSocket - [KurentoClient] Exception sending close message. org.kurento.jsonrpc.JsonRpcClientClosedException:Trying to send a message in a client closed explicitly. When a client is closed, it can’t be reused. It is necessary to create another one
[WARN] 2021-01-04 09:07:33,988 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Trying to close a JsonRpcClientNettyWebSocket with channel == null
[WARN] 2021-01-04 09:07:33,988 [main] org.kurento.jsonrpc.client.JsonRpcClientNettyWebSocket - [KurentoClient] Trying to close a JsonRpcClientNettyWebSocket with group == null
[INFO] 2021-01-04 09:07:33,989 [main] io.openvidu.server.core.SessionManager - Closing all sessions
[INFO] 2021-01-04 09:07:33,990 [main] org.apache.catalina.core.StandardService - Stopping service [Tomcat]
[INFO] 2021-01-04 09:07:33,993 [AbstractJsonRpcClientWebSocket-reqResEventExec-e11-t0] io.openvidu.server.kurento.kms.KmsManager - Kurento Client “disconnected” event for KMS ws://172.16.4.36:8888/kurento [org.kurento.client.KurentoClient@fbd9d61]. Closed explicitly
[INFO] 2021-01-04 09:07:34,004 [main] org.springframework.boot.autoconfigure.logging.ConditionEvaluationReportLoggingListener -

Error starting ApplicationContext. To display the conditions report re-run your application with ‘debug’ enabled.
[ERROR] 2021-01-04 09:07:34,009 [main] org.springframework.boot.SpringApplication - Application run failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name ‘elasticSearchConfig’: Invocation of init method failed; nested exception is ElasticsearchStatusException[Elasticsearch exception [type=validation_exception, reason=Validation Failed: 1: this action would add [2] total shards, but this cluster currently has [1000]/[1000] maximum shards open;]]
at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:160)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:416)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1788)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:595)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:879)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:878)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:550)
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:141)
at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:747)
at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:315)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226)
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1215)
at io.openvidu.server.pro.OpenViduServerPro.main(OpenViduServerPro.java:296)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)
at org.springframework.boot.loader.Launcher.launch(Launcher.java:87)
at org.springframework.boot.loader.Launcher.launch(Launcher.java:51)
at org.springframework.boot.loader.PropertiesLauncher.main(PropertiesLauncher.java:597)
Caused by: org.elasticsearch.ElasticsearchStatusException: Elasticsearch exception [type=validation_exception, reason=Validation Failed: 1: this action would add [2] total shards, but this cluster currently has [1000]/[1000] maximum shards open;]
at org.elasticsearch.rest.BytesRestResponse.errorFromXContent(BytesRestResponse.java:177)
at org.elasticsearch.client.RestHighLevelClient.parseEntity(RestHighLevelClient.java:1897)
at org.elasticsearch.client.RestHighLevelClient.parseResponseException(RestHighLevelClient.java:1867)
at org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:1624)
at org.elasticsearch.client.RestHighLevelClient.performRequest(RestHighLevelClient.java:1596)
at org.elasticsearch.client.RestHighLevelClient.performRequestAndParseEntity(RestHighLevelClient.java:1563)
at org.elasticsearch.client.IndicesClient.create(IndicesClient.java:139)
at io.openvidu.server.pro.config.ElasticSearchConfig.createIndex(ElasticSearchConfig.java:115)
at io.openvidu.server.pro.config.ElasticSearchConfig.init(ElasticSearchConfig.java:92)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleElement.invoke(InitDestroyAnnotationBeanPostProcessor.java:389)
at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleMetadata.invokeInitMethods(InitDestroyAnnotationBeanPostProcessor.java:333)
at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:157)
… 26 common frames omitted
Suppressed: org.elasticsearch.client.ResponseException: method [PUT], host [http://127.0.0.1:9200], URI [/filebeat-openvidu-2021.01.04?master_timeout=30s&timeout=30s], status line [HTTP/1.1 400 Bad Request]
{“error”:{“root_cause”:[{“type”:“validation_exception”,“reason”:“Validation Failed: 1: this action would add [2] total shards, but this cluster currently has [1000]/[1000] maximum shards open;”}],“type”:“validation_exception”,“reason”:“Validation Failed: 1: this action would add [2] total shards, but this cluster currently has [1000]/[1000] maximum shards open;”},“status”:400}
at org.elasticsearch.client.RestClient.convertResponse(RestClient.java:283)
at org.elasticsearch.client.RestClient.performRequest(RestClient.java:261)
at org.elasticsearch.client.RestClient.performRequest(RestClient.java:235)
at org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:1611)
… 38 common frames omitted
[INFO] 2021-01-04 09:10:26,079 [Thread-3] io.openvidu.server.pro.account.LambdaService - License GET HTTP status: HTTP/1.1 200 OK
[INFO] 2021-01-04 09:13:26,261 [Thread-3] io.openvidu.server.pro.account.LambdaService - License GET HTTP status: HTTP/1.1 200 OK
[INFO] 2021-01-04 09:16:26,585 [Thread-3] io.openvidu.server.pro.account.LambdaService - License GET HTTP status: HTTP/1.1 200 OK
[INFO] 2021-01-04 09:19:26,768 [Thread-3] io.openvidu.server.pro.account.LambdaService - License GET HTTP status: HTTP/1.1 200 OK

Any ideas/ suggestions?

Thanks

I think you’re experiencing some kind of error with your Elasticsearch.

  1. What version do you have deployed?
  2. what is the output of df -h (How much free space do you have)
  3. How much RAM do you have?

Regards,
Carlos