Hi Team,
During a start of video conference, we can notice “erizoAgent.js” is exited abnormally.
No crash, no error logs.
we can notice the “erizoAgent.js” is down, hence we restarted licode service.
Firstly, no error information, this is a problem.
And this is not reproducible again, do you guys faced something similar like this?
Any suggestions to identify and fix this issue?
Thanks & Regards,
Hemanth
There should be some kind of message pointing that ErizoAgent has crashed. Are you getting the ErizoAgent logs anywhere?
Are you using config.erizoAgent.useIndividualLogFiles =true; in the configuration? I’d recommend setting it to false in production unless you have some mechanism to remove old log files.
Frankly, we haven’t had an ErizoAgent crash in years. Check for standard things: that rabbitmq is running, there’s enough disk space, memory, etc.
Hi Pedro,
config.erizoAgent.useIndividualLogFiles is set to false only.
Yes, we are getting ErizoAgent logs.
Please find the licode logs:
2017-08-10 14:50:13.411 - INFO: RoomController - message: addPublisher, streamId: 549910774042984100, state: erizo, audio: false, video: true, screen: false, minVideoBW: 0, attributes: [Object],
2017-08-10 14:50:13.411 - INFO: EcCloudHandler - message: createErizoJS, agentId: ErizoAgent
2017-08-10 14:50:13.414 - INFO: EcCloudHandler - message: createErizoJS success, erizoId: 1170d2da-cb40-e45b-0c39-fc6a944cba39, agentId: d5403ded-ddd4-e6ca-5685-19e3c4d8a2d6
2017-08-10 14:50:13.414 - INFO: RoomController - message: addPublisher erizoJs assigned, erizoId: 1170d2da-cb40-e45b-0c39-fc6a944cba39, streamId: 549910774042984100,
2017-08-10 14:50:13.443 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: d76a5d82-da95-2e9a-478d-3f149d0f029f
[erizo-1170d2da-cb40-e45b-0c39-fc6a944cba39] 2017-08-10 14:50:13.427 - INFO: ErizoJSController - message: Adding publisher, streamId: 549910774042984100, state: erizo, audio: false, video: true, screen: false, minVideoBW: 0, attributes: [Object],
2017-08-10 14:50:13,430 - INFO [0x7ff859dd5780] WebRtcConnection - id: 549910774042984100, message: constructor, stunserver: stun.l.google.com, stunPort: 19302, minPort: 0, maxPort: 0
2017-08-10 14:50:13.433 - INFO: ErizoJSController - message: WebRtcConnection status update, id: 549910774042984100, status: 101,
3499
3508
3545
3557
3558
Checking dir /home/ubuntu/sandbox/licode/build/libdeps/nvm
Running nvm
2017-08-10 14:50:20.199 - INFO: RPC - message: AMQP connected
2017-08-10 14:50:20.209 - INFO: RPC - message: rpcExchange open, exchangeName: rpcExchange
2017-08-10 14:50:20.212 - INFO: RPC - message: clientQueue open, queueName: amq.gen-lank6NI0NNguJ3cxaX1EpA
2017-08-10 14:50:20.217 - INFO: RPC - message: queue open, queueName: nuveQueue
Checking dir /home/ubuntu/sandbox/licode/build/libdeps/nvm
Running nvm
Found ‘/home/ubuntu/sandbox/licode/.nvmrc’ with version <6.9.2>
Now using node v6.9.2 (npm v3.10.9)
Checking dir /home/ubuntu/sandbox/licode/build/libdeps/nvm
Running nvm
(node:24160) DeprecationWarning: ‘GLOBAL’ is deprecated, use 'global’
2017-08-10 14:50:27.303 - INFO: CloudHandler - New erizocontroller ( 598c72b3e3d1a45d42ebbbe6 ) in: -EDITED-
2017-08-10 14:50:27.316 - INFO: ErizoController - message: succesfully added to cloudHandler
Found ‘/home/ubuntu/sandbox/licode/.nvmrc’ with version <6.9.2>
Now using node v6.9.2 (npm v3.10.9)
[licode] Done, run ./scripts/initBasicExample.sh
2017-08-10 14:50:29.665 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: f4f583bd-0af4-e44e-c740-e58b11490e8d
2017-08-10 14:50:29.675 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: a056bdab-1c24-806f-fac7-5f2db206d95a
2017-08-10 14:50:29.683 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: 76c29485-1a52-95f9-81d4-a5bb381daca0
2017-08-10 14:50:29.688 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: d7e2deca-c6c9-b425-8245-9a60059bc5dc
2017-08-10 14:50:29.690 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: e32f2946-7718-7ce3-7dab-093bb551c611
2017-08-10 14:50:29.695 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: 9de4fc21-fb6d-9fed-031a-442b0dc07c3b
2017-08-10 14:50:29.700 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: 8153cce6-eb15-5cb5-63fb-92ca37e574f9
2017-08-10 14:50:29.702 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: 386ff694-7459-e32d-9956-ce11d562de22
2017-08-10 14:50:29.715 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: 6d5d5514-38e0-770a-6f0c-c6d9da16db03
2017-08-10 14:50:29.717 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: 5570c7df-b54c-14d0-07c8-c6ae58322d94
No crash (or) error information.
Please note that, we are running on Amazon cloud instance.
Hi Pedro,
We added signal handlers for both erizoAgent and erizoController.
And what we can notice is “erizoController” is the one, which is exited with signal “SIGQUIT”.
2017-08-19 10:26:05.685 - INFO: ErizoAgent - message: closed, erizoId: aa18af7d-023c-777d-eccf-0a5699014297
2017-08-19 10:26:16.416 - DEBUG: RoomController - message: empty erizoJS removed, erizoId: d4bfb442-a44f-f93a-7f54-b7da01146374
2017-08-19 10:26:16.416 - INFO: EcCloudHandler - message: deleting erizoJS, erizoId: d4bfb442-a44f-f93a-7f54-b7da01146374
2017-08-19 10:26:21.418 - DEBUG: RoomController - message: empty erizoJS removed, erizoId: d6d4711c-e28b-8559-3f39-8dfdce534157
2017-08-19 10:26:21.418 - INFO: EcCloudHandler - message: deleting erizoJS, erizoId: d6d4711c-e28b-8559-3f39-8dfdce534157
2017-08-19 10:26:21.418 - DEBUG: RoomController - message: empty erizoJS removed, erizoId: aa18af7d-023c-777d-eccf-0a5699014297
2017-08-19 10:26:21.418 - INFO: EcCloudHandler - message: deleting erizoJS, erizoId: aa18af7d-023c-777d-eccf-0a5699014297
2017-08-19 10:29:59.076 - INFO: ErizoController - message: addPublisher requested, streamId: 816168115862356900, clientId: CqyjnsVOi-Dxx3bxAAAC, state: erizo, screen: true, minVideoBW: 0, attributes: [Object], name: screenShare-6, type: public
2017-08-19 10:29:59.077 - INFO: RoomController - message: addPublisher, streamId: 816168115862356900, state: erizo, screen: true, minVideoBW: 0, attributes: [Object],
2017-08-19 10:29:59.077 - INFO: EcCloudHandler - message: createErizoJS, agentId: ErizoAgent
2017-08-19 10:29:59.078 - DEBUG: ErizoAgent - message: createErizoJS returning, erizoId: 7be3f98a-4839-5a2d-3dff-ae0d525e9fda
2017-08-19 10:29:59.078 - DEBUG: ErizoAgent - message: launching ErizoJS, erizoId: 4b055166-b149-93fa-b98f-cc5e94b671a1
2017-08-19 10:29:59.078 - INFO: EcCloudHandler - message: createErizoJS success, erizoId: 7be3f98a-4839-5a2d-3dff-ae0d525e9fda, agentId: 6b6fff05-b47b-4292-9625-16e3ca105d7d
2017-08-19 10:29:59.078 - INFO: RoomController - message: addPublisher erizoJs assigned, erizoId: 7be3f98a-4839-5a2d-3dff-ae0d525e9fda, streamId: 816168115862356900,
2017-08-19 10:29:59.084 - ERROR: ErizoController - About to exit on signal: SIGQUIT
2017-08-19 10:29:59.084 - INFO: ErizoAgent - message: launched new ErizoJS, erizoId: 4b055166-b149-93fa-b98f-cc5e94b671a1
[erizo-7be3f98a-4839-5a2d-3dff-ae0d525e9fda] 2017-08-19 10:29:59.082 - INFO: ErizoJSController - message: Adding publisher, streamId: 816168115862356900, state: erizo, screen: true, minVideoBW: 0, attributes: [Object],
[erizo-7be3f98a-4839-5a2d-3dff-ae0d525e9fda] 2017-08-19 10:29:59,084 - INFO [0x7f1fc461d780] WebRtcConnection - id: 816168115862356900, message: constructor, stunserver: stun.l.google.com, stunPort: 19302, minPort: 0, maxPort: 0
[erizo-7be3f98a-4839-5a2d-3dff-ae0d525e9fda] 2017-08-19 10:29:59.085 - DEBUG: ErizoJSController - message: Init WebRtcConnection, id: 816168115862356900, state: erizo, screen: true, minVideoBW: 0, attributes: [Object]
[erizo-7be3f98a-4839-5a2d-3dff-ae0d525e9fda] 2017-08-19 10:29:59.088 - INFO: ErizoJSController - message: WebRtcConnection status update, id: 816168115862356900, status: 101,
2017-08-19 10:29:59.096 - INFO: ErizoController - message: addPublisher, state: PUBLISHER_INITIAL, clientId: CqyjnsVOi-Dxx3bxAAAC, streamId: 816168115862356900
2017-08-19 10:29:59.130 - ERROR: ErizoController - About to exit on signal: SIGQUIT
2017-08-19 10:29:59.131 - ERROR: ErizoAgent - message: killing erizoJSs on signal: SIGQUIT, numProcesses: undefined
2017-08-19 10:29:59.131 - DEBUG: ErizoAgent - message: killing process, processId: 7453
2017-08-19 10:29:59.131 - DEBUG: ErizoAgent - message: killing process, processId: 7454
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 7456
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 7482
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 3175
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 32517
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 6428
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 8493
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 14758
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 15596
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 21586
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 22333
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 31307
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 20799
2017-08-19 10:29:59.132 - DEBUG: ErizoAgent - message: killing process, processId: 26359
2017-08-19 10:29:59.133 - ERROR: ErizoAgent - About to exit with code: 0
1381
1391
Checking dir /home/ubuntu/sandbox/licode/build/libdeps/nvm
Running nvm
2017-08-19 10:30:05.099 - INFO: RPC - message: AMQP connected
2017-08-19 10:30:05.103 - INFO: RPC - message: rpcExchange open, exchangeName: rpcExchange
2017-08-19 10:30:05.105 - INFO: RPC - message: clientQueue open, queueName: amq.gen-8uDETf897uvAdluvUbIOqQ
2017-08-19 10:30:05.109 - INFO: RPC - message: queue open, queueName: nuveQueue
2017-08-19 10:30:06.968 - WARN: EcCloudHandler - message: no agents available, code: 503
Also note that, we are currently on below commit:
commit 8d84978b6425b70857d78f7f282eda5000593232
Author: Javier Cerviño jcague@gmail.com
Date: Wed Jun 28 14:49:50 2017 +0200
Use ESLint in Erizo Client. (#937)
Regards,
Hemanth
Atleast once in a day … we are noticing this issue.
It is a kind of blocker for us.
Will update you, as we get any lead/clue wrt issue.
Thanks & Regards,
Hemanth
Hi Pedro,
Check these logs, it may give a clue to us.
, readyRtp:1, readyRtcp:1
2017-08-19 10:24:07,013 - DEBUG [0x7fe2bf7fe700] WebRtcConnection - id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, transportName: video, new_state: 3
2017-08-19 10:24:07,013 - DEBUG [0x7fe2bf7fe700] LibNiceConnection - id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, message: selected pair, local_addr: 172.31.11.103, local_port: 55511, local_type: host
2017-08-19 10:24:07,013 - INFO [0x7fe2bf7fe700] LibNiceConnection - id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, message: selected pair, remote_addr: 106.51.73.73, remote_port: 3314, remote_type: host
2017-08-19 10:24:07,013 - INFO [0x7fe2bf7fe700] WebRtcConnection - id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, newGlobalState: 104
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:07.013 - INFO: ErizoJSController - message: WebRtcConnection status update, id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, status: 104,
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:07.013 - DEBUG: ErizoJSController - message: connection ready, id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, status: 104
2017-08-19 10:24:07.014 - INFO: ErizoController - message: addSubscriber, state: SUBSCRIBER_READY, streamId: 115156842243135200, clientId: kD_Y3J2QpqIkEkkzAAAB
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:30.951 - INFO: ErizoJSController - message: Process Signaling message, streamId: 115156842243135200, peerId: kD_Y3J2QpqIkEkkzAAAB
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:30.951 - DEBUG: ErizoJSController - message: setting SlideShow, id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, slideShowMode: true
2017-08-19 10:24:30,951 - DEBUG [0x7fe2daec6780] WebRtcConnection - id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, slideShowMode: 1
[erizo-d4bfb442-a44f-f93a-7f54-b7da01146374] 2017-08-19 10:24:33.770 - INFO: ErizoJSController - message: Process Signaling message, streamId: 304951780067712800, peerId: Pj5RyYXyeEO0lKnRAAAD
[erizo-d4bfb442-a44f-f93a-7f54-b7da01146374] 2017-08-19 10:24:33.771 - DEBUG: ErizoJSController - message: setting SlideShow, id: Pj5RyYXyeEO0lKnRAAAD_304951780067712800, slideShowMode: true
2017-08-19 10:24:33,771 - DEBUG [0x7f92f63ff780] WebRtcConnection - id: Pj5RyYXyeEO0lKnRAAAD_304951780067712800, slideShowMode: 1
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:33.782 - INFO: ErizoJSController - message: Process Signaling message, streamId: 115156842243135200, peerId: Pj5RyYXyeEO0lKnRAAAD
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:33.782 - DEBUG: ErizoJSController - message: setting SlideShow, id: Pj5RyYXyeEO0lKnRAAAD_115156842243135200, slideShowMode: true
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:33,782 - DEBUG [0x7fe2daec6780] WebRtcConnection - id: Pj5RyYXyeEO0lKnRAAAD_115156842243135200, slideShowMode: 1
[erizo-d6d4711c-e28b-8559-3f39-8dfdce534157] 2017-08-19 10:24:33.783 - INFO: ErizoJSController - message: Process Signaling message, streamId: 327568192614310500, peerId: Pj5RyYXyeEO0lKnRAAAD
[erizo-d6d4711c-e28b-8559-3f39-8dfdce534157] 2017-08-19 10:24:33.783 - DEBUG: ErizoJSController - message: setting SlideShow, id: Pj5RyYXyeEO0lKnRAAAD_327568192614310500, slideShowMode: false
[erizo-d6d4711c-e28b-8559-3f39-8dfdce534157] 2017-08-19 10:24:33,783 - DEBUG [0x7f40562b7780] WebRtcConnection - id: Pj5RyYXyeEO0lKnRAAAD_327568192614310500, slideShowMode: 0
[erizo-d6d4711c-e28b-8559-3f39-8dfdce534157] 2017-08-19 10:24:33,924 - WARN [0x7f403bfff700] rtp.PliPacerHandler - id: 327568192614310500, message: Timed out waiting for a keyframe
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:33.937 - INFO: ErizoJSController - message: Process Signaling message, streamId: 115156842243135200, peerId: kD_Y3J2QpqIkEkkzAAAB
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:24:33.937 - DEBUG: ErizoJSController - message: setting SlideShow, id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, slideShowMode: false
2017-08-19 10:24:33,937 - DEBUG [0x7fe2daec6780] WebRtcConnection - id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, slideShowMode: 0
[
erizo-d6d4711c-e28b-8559-3f39-8dfdce534157] 2017-08-19 10:24:36,143 - ERROR [0x7f3fcb7fe700] media.ExternalOutput - Not enough buffer. Dropping frame. Please adjust your UNPACKAGE_BUFFER_SIZE in ExternalOutput.h
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:16.297 - INFO: ErizoJSController - message: Process Signaling message, streamId: 115156842243135200, peerId: kD_Y3J2QpqIkEkkzAAAB
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:16.297 - DEBUG: ErizoJSController - message: setting SlideShow, id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, slideShowMode: true
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:16,300 - DEBUG [0x7fe2daec6780] WebRtcConnection - id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, slideShowMode: 1
2017-08-19 10:25:20.631 - DEBUG: ErizoController - message: sendMsgToRoom, clientId: kD_Y3J2QpqIkEkkzAAAB, roomId: 5997fc0614e7bf1ad2f0766f, onRemoveStream
2017-08-19 10:25:20.631 - DEBUG: ErizoController - message: sendMsgToRoom, clientId: CqyjnsVOi-Dxx3bxAAAC, roomId: 5997fc0614e7bf1ad2f0766f, onRemoveStream
2017-08-19 10:25:20.631 - DEBUG: ErizoController - message: sendMsgToRoom, clientId: Pj5RyYXyeEO0lKnRAAAD, roomId: 5997fc0614e7bf1ad2f0766f, onRemoveStream
2017-08-19 10:25:20.631 - DEBUG: ErizoController - message: sendMsgToRoom, clientId: sgR0gU6G70gj2Ni9AAAF, roomId: 5997fc0614e7bf1ad2f0766f, onRemoveStream
2017-08-19 10:25:20.631 - INFO: RoomController - message: removePublisher, publisherId: 115156842243135200, erizoId: ErizoJS_8999db7e-713d-79cc-6223-1d8fb4690134
2017-08-19 10:25:20.632 - DEBUG: RoomController - message: removedPublisher, publisherId: 115156842243135200, publishersLeft: 6
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20.633 - INFO: ErizoJSController - message: Removing publisher, id: 115156842243135200
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20.633 - INFO: ErizoJSController - message: Removing subscriber, id: sgR0gU6G70gj2Ni9AAAF_115156842243135200
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20.634 - INFO: ErizoJSController - message: WebRtcConnection status update, id: sgR0gU6G70gj2Ni9AAAF_115156842243135200, status: 105,
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20.634 - INFO: ErizoJSController - message: Removing subscriber, id: Pj5RyYXyeEO0lKnRAAAD_115156842243135200
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20.634 - INFO: ErizoJSController - message: WebRtcConnection status update, id: Pj5RyYXyeEO0lKnRAAAD_115156842243135200, status: 105,
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20.634 - INFO: ErizoJSController - message: Removing subscriber, id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20.634 - INFO: ErizoJSController - message: WebRtcConnection status update, id: kD_Y3J2QpqIkEkkzAAAB_115156842243135200, status: 105,
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20.634 - INFO: ErizoJSController - message: WebRtcConnection status update, id: 115156842243135200, status: 105,
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20,634 - DEBUG [0x7fe2cd49a700] WebRtcConnection - id: 115156842243135200, message:Close called
[erizo-8999db7e-713d-79cc-6223-1d8fb4690134] 2017-08-19 10:25:20,634 - DEBUG [0x7fe2cd49a700] DtlsTransport - id: 115156842243135200, message: closing
Anything wrong with above error log, which leads to exit?
Thanks & Regards,
Hemanth
Sorry, This issue is with our monitor script. It is false detecting.
Thanks & Regards,
Hemanth