Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Error: channel closed after Reloading logs #2977

Closed
onlinemad opened this issue Jun 28, 2017 · 3 comments
Closed

Error: channel closed after Reloading logs #2977

onlinemad opened this issue Jun 28, 2017 · 3 comments
Labels
S: Pending Release

Comments

@onlinemad
Copy link

What's going wrong?

pm2 daemon log shows Error: channel closed after Reloading logs

this is error log

2017-06-28 07:35:39: Reloading logs...
2017-06-28 07:35:39: Reloading logs for process id 0
2017-06-28 07:35:39: Reloading logs for process id 1
2017-06-28 07:35:39: Reloading logs for process id 2
2017-06-28 07:35:39: Reloading logs for process id 3
2017-06-28 07:35:39: Reloading logs for process id 4
2017-06-28 07:35:39: Reloading logs for process id 5
2017-06-28 07:35:39: Reloading logs for process id 6
2017-06-28 07:35:39: Reloading logs for process id 7
2017-06-28 07:35:39: Reloading logs for process id 8
2017-06-28 07:35:39: Reloading logs for process id 9
2017-06-28 07:35:39: Error: channel closed
    at ChildProcess.target.send (internal/child_process.js:535:16)
    at Worker.options.process.on.process.on.Worker.send (cluster.js:51:21)
    at /usr/lib/node_modules/pm2/lib/God/ActionMethods.js:577:19
    at Array.forEach (native)
    at God.reloadLogs (/usr/lib/node_modules/pm2/lib/God/ActionMethods.js:568:16)
    at Server.onmessage (/usr/lib/node_modules/pm2/node_modules/pm2-axon-rpc/lib/server.js:105:6)
    at emitTwo (events.js:87:13)
    at RepSocket.emit (events.js:172:7)
    at Parser.<anonymous> (/usr/lib/node_modules/pm2/node_modules/pm2-axon/lib/sockets/rep.js:51:15)
    at emitOne (events.js:77:13)
    at Parser.emit (events.js:169:7)
2017-06-28 07:35:40: Reloading logs...
2017-06-28 07:35:40: Reloading logs for process id 0
2017-06-28 07:35:40: Reloading logs for process id 1
2017-06-28 07:35:40: Reloading logs for process id 2
2017-06-28 07:35:40: Reloading logs for process id 3
2017-06-28 07:35:40: Reloading logs for process id 4
2017-06-28 07:35:40: Reloading logs for process id 5
2017-06-28 07:35:40: Reloading logs for process id 6
2017-06-28 07:35:40: Reloading logs for process id 7
2017-06-28 07:35:40: Reloading logs for process id 8
2017-06-28 07:35:40: Reloading logs for process id 9
2017-06-28 07:35:40: ===============================================================================
2017-06-28 07:35:40: --- PM2 global error caught ---------------------------------------------------
2017-06-28 07:35:40: Time                 : Wed Jun 28 2017 07:35:40 GMT+0800 (CST)
2017-06-28 07:35:40: channel closed
2017-06-28 07:35:40: Error: channel closed
    at ChildProcess.target.send (internal/child_process.js:535:16)
    at Worker.options.process.on.process.on.Worker.send (cluster.js:51:21)
    at /usr/lib/node_modules/pm2/lib/God/ActionMethods.js:577:19
    at Array.forEach (native)
    at God.reloadLogs (/usr/lib/node_modules/pm2/lib/God/ActionMethods.js:568:16)
    at Server.onmessage (/usr/lib/node_modules/pm2/node_modules/pm2-axon-rpc/lib/server.js:105:6)
    at emitTwo (events.js:87:13)
    at RepSocket.emit (events.js:172:7)
    at Parser.<anonymous> (/usr/lib/node_modules/pm2/node_modules/pm2-axon/lib/sockets/rep.js:51:15)
    at emitOne (events.js:77:13)
2017-06-28 07:35:40: ===============================================================================

I use logrotate.d to reloading logs

this is config file of logrotate.d

/home/user/.pm2/logs/*.log {
  daily
  rotate 14
  missingok
  notifempty
  sharedscripts
  dateext
  dateformat -%Y-%m-%d
  postrotate
    su - user -c "pm2 flush; pm2 reloadLogs"
  endscript
}

How could we reproduce this issue?

I run logrotate.d manually but can't reproduce this issue

Supporting information

PM2 version: `2.4.3`
Node version: `v4.8.3`
Linux: `Debian 8.8`

Additional

After Error: channel closed pm2 try to resurrect process. But resurrecting failed and pm2 stop completely.

2017-06-28 07:35:40: Reloading logs...
2017-06-28 07:35:40: Reloading logs for process id 0
2017-06-28 07:35:40: Reloading logs for process id 1
2017-06-28 07:35:40: Reloading logs for process id 2
2017-06-28 07:35:40: Reloading logs for process id 3
2017-06-28 07:35:40: Reloading logs for process id 4
2017-06-28 07:35:40: Reloading logs for process id 5
2017-06-28 07:35:40: Reloading logs for process id 6
2017-06-28 07:35:40: Reloading logs for process id 7
2017-06-28 07:35:40: Reloading logs for process id 8
2017-06-28 07:35:40: Reloading logs for process id 9
2017-06-28 07:35:40: ===============================================================================
2017-06-28 07:35:40: --- PM2 global error caught ---------------------------------------------------
2017-06-28 07:35:40: Time                 : Wed Jun 28 2017 07:35:40 GMT+0800 (CST)
2017-06-28 07:35:40: channel closed
2017-06-28 07:35:40: Error: channel closed
    at ChildProcess.target.send (internal/child_process.js:535:16)
    at Worker.options.process.on.process.on.Worker.send (cluster.js:51:21)
    at /usr/lib/node_modules/pm2/lib/God/ActionMethods.js:577:19
    at Array.forEach (native)
    at God.reloadLogs (/usr/lib/node_modules/pm2/lib/God/ActionMethods.js:568:16)
    at Server.onmessage (/usr/lib/node_modules/pm2/node_modules/pm2-axon-rpc/lib/server.js:105:6)
    at emitTwo (events.js:87:13)
    at RepSocket.emit (events.js:172:7)
    at Parser.<anonymous> (/usr/lib/node_modules/pm2/node_modules/pm2-axon/lib/sockets/rep.js:51:15)
    at emitOne (events.js:77:13)
2017-06-28 07:35:40: ===============================================================================
2017-06-28 07:35:40: [PM2] Resurrecting PM2
Be sure to have the latest version by doing `npm install pm2@latest -g` before doing this procedure.
[PM2] Saving current process list...
[PM2] Stopping PM2...
[PM2] Applying action deleteProcessId on app [all](ids: 0,1,2,3,4,5,6,7,8,9)
2017-06-28 07:35:40: Stopping app:myapp id:0
2017-06-28 07:35:40: Stopping app:myapp id:1
2017-06-28 07:35:40: Stopping app:myapp id:2
2017-06-28 07:35:40: Stopping app:myapp-api-v4 id:3
2017-06-28 07:35:40: Stopping app:myapp-api-v4 id:4
2017-06-28 07:35:40: Stopping app:myapp-api-v4 id:5
2017-06-28 07:35:40: Stopping app:myapp-tracer id:6
2017-06-28 07:35:40: Stopping app:myapp-tracer id:7
2017-06-28 07:35:40: Stopping app:myapp-admin id:8
2017-06-28 07:35:40: Stopping app:operator.sleepnova.org id:9
2017-06-28 07:35:40: app=operator.sleepnova.org id=9 does not have a pid
[PM2] [all](9) ✓
2017-06-28 07:35:41: App name:myapp-tracer id:6 disconnected
2017-06-28 07:35:41: App name:myapp-tracer id:7 disconnected
2017-06-28 07:35:41: App name:myapp-api-v4 id:3 disconnected
2017-06-28 07:35:41: App [myapp-tracer] with id [6] and pid [21184], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: App [myapp-tracer] with id [7] and pid [21190], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: App [myapp-api-v4] with id [3] and pid [32621], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: App name:myapp-api-v4 id:5 disconnected
2017-06-28 07:35:41: App name:myapp-api-v4 id:4 disconnected
2017-06-28 07:35:41: App name:myapp id:0 disconnected
2017-06-28 07:35:41: App [myapp-api-v4] with id [4] and pid [32627], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: App [myapp-api-v4] with id [5] and pid [32674], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: App [myapp] with id [0] and pid [3930], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: App name:myapp id:1 disconnected
2017-06-28 07:35:41: App [myapp] with id [1] and pid [1040], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: pid=32674 msg=process killed
2017-06-28 07:35:41: pid=32627 msg=process killed
2017-06-28 07:35:41: pid=32621 msg=process killed
[PM2] [myapp-api-v4](5) ✓
2017-06-28 07:35:41: pid=10916 msg=failed to kill - retrying in 100ms
2017-06-28 07:35:41: pid=1040 msg=process killed
[PM2] [myapp-api-v4](4) ✓
[PM2] [myapp-api-v4](3) ✓
2017-06-28 07:35:41: pid=3930 msg=process killed
[PM2] [myapp](1) ✓
2017-06-28 07:35:41: pid=21184 msg=process killed
[PM2] [myapp](0) ✓
2017-06-28 07:35:41: pid=21190 msg=process killed
[PM2] [myapp-tracer](6) ✓
[PM2] [myapp-tracer](7) ✓
2017-06-28 07:35:41: App name:myapp id:2 disconnected
2017-06-28 07:35:41: App [myapp] with id [2] and pid [10916], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: App name:myapp-admin id:8 disconnected
2017-06-28 07:35:41: App [myapp-admin] with id [8] and pid [22437], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:41: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:41: pid=22437 msg=process killed
[PM2] [myapp-admin](8) ✓
2017-06-28 07:35:41: pid=10916 msg=process killed
[PM2] [myapp](2) ✓
[PM2] All processes have been stopped and deleted
2017-06-28 07:35:41: ===============================================================================
2017-06-28 07:35:41: --- Stopping PM2 --------------------------------------------------------------
2017-06-28 07:35:41: Time                 : Wed Jun 28 2017 07:35:41 GMT+0800 (CST)
2017-06-28 07:35:41: ===============================================================================
2017-06-28 07:35:41: RPC closed
2017-06-28 07:35:41: PUB closed
2017-06-28 07:35:41: PM2 successfully stopped
[PM2] PM2 stopped
[PM2] Spawning PM2 daemon with pm2_home=/home/noderunner/.pm2
[PM2] Restoring processes located in /home/noderunner/.pm2/dump.pm2
[PM2] Process /home/noderunner/calltaxi_prd/app.js restored
[PM2] Process /home/noderunner/calltaxi_prd/app.js restored
[PM2] Process /home/noderunner/calltaxi_prd/app.js restored
[PM2] Process /home/noderunner/myapp/findtaxi-server-api-v4/app.js restored
[PM2] Process /home/noderunner/myapp/findtaxi-server-api-v4/app.js restored
2017-06-28 07:35:41: ===============================================================================
2017-06-28 07:35:41: --- New PM2 Daemon started ----------------------------------------------------
2017-06-28 07:35:41: Time                 : Wed Jun 28 2017 07:35:41 GMT+0800 (CST)
2017-06-28 07:35:41: PM2 version          : 2.4.3
2017-06-28 07:35:41: Node.js version      : 4.8.3
2017-06-28 07:35:41: Current arch         : x64
2017-06-28 07:35:41: PM2 home             : /home/noderunner/.pm2
2017-06-28 07:35:41: PM2 PID file         : /home/noderunner/.pm2/pm2.pid
2017-06-28 07:35:41: RPC socket file      : /home/noderunner/.pm2/rpc.sock
2017-06-28 07:35:41: BUS socket file      : /home/noderunner/.pm2/pub.sock
2017-06-28 07:35:41: Application log path : /home/noderunner/.pm2/logs
2017-06-28 07:35:41: Process dump file    : /home/noderunner/.pm2/dump.pm2
2017-06-28 07:35:41: Concurrent actions   : 2
2017-06-28 07:35:41: SIGTERM timeout      : 1600
2017-06-28 07:35:41: ===============================================================================
2017-06-28 07:35:41: Starting execution sequence in -cluster mode- for app name:myapp id:0
2017-06-28 07:35:41: Starting execution sequence in -cluster mode- for app name:myapp id:1
2017-06-28 07:35:41: App name:myapp id:0 online
2017-06-28 07:35:41: Starting execution sequence in -cluster mode- for app name:myapp id:2
2017-06-28 07:35:41: App name:myapp id:1 online
2017-06-28 07:35:41: App name:myapp id:2 online
2017-06-28 07:35:41: Starting execution sequence in -cluster mode- for app name:myapp-api-v4 id:3
2017-06-28 07:35:41: Starting execution sequence in -cluster mode- for app name:myapp-api-v4 id:4
2017-06-28 07:35:42: Stopping app:myapp id:0
2017-06-28 07:35:42: Stopping app:myapp id:1
2017-06-28 07:35:42: App name:myapp id:1 disconnected
2017-06-28 07:35:42: App name:myapp id:0 disconnected
2017-06-28 07:35:42: App [myapp] with id [0] and pid [4062], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:42: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:42: App [myapp] with id [1] and pid [4074], exited with code [0] via signal [SIGINT]
2017-06-28 07:35:42: [HandleExit] PM2 is being killed, stopping restart procedure...
2017-06-28 07:35:42: App name:myapp-api-v4 id:3 online
2017-06-28 07:35:42: App name:myapp-api-v4 id:4 online
2017-06-28 07:35:42: Proc is not defined anymore or is being killed
2017-06-28 07:35:42: Starting execution sequence in -cluster mode- for app name:myapp-api-v4 id:5
2017-06-28 07:35:42: Starting execution sequence in -cluster mode- for app name:myapp-tracer id:6
2017-06-28 07:35:42: pid=4074 msg=process killed
2017-06-28 07:35:42: pid=4062 msg=process killed
2017-06-28 07:35:42: ===============================================================================
2017-06-28 07:35:42: --- Stopping PM2 --------------------------------------------------------------
2017-06-28 07:35:42: Time                 : Wed Jun 28 2017 07:35:42 GMT+0800 (CST)
2017-06-28 07:35:42: ===============================================================================
2017-06-28 07:35:42: RPC closed
2017-06-28 07:35:42: PUB closed
2017-06-28 07:35:42: PM2 successfully stopped
Unitech added a commit that referenced this issue Jun 28, 2017
@Unitech
#2977 reload log try/catch
8a5a102
@Unitech
Copy link
Owner

Unitech commented Jun 28, 2017 

$ npm install Unitech/pm2#development -g
$ pm2 update

@onlinemad
Copy link
Author

@Unitech Thank you for your response. I will upgrade pm2 to development version.

@Unitech
Copy link
Owner

Unitech commented Jul 20, 2017

Published on PM2 2.6.0:

$ npm install pm2@latest -g
$ pm2 update

@Unitech Unitech closed this as completed Jul 20, 2017
inerc pushed a commit to inerc/pm2 that referenced this issue Feb 11, 2020
@Unitech
Unitech#2977 reload log try/catch
65b0c33
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
S: Pending Release
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Unitech @onlinemad