Pm2: Cron broken since 3.2.3 ? "PM ID unknown"
Not sure if we're doing something wrong, but PR #3944 broke cron_restart for us :
- the 1st cron run following the initial
pm2 startsuccessfully restarts the app, - but all the subsequent runs fail with error
PM ID unknown
In more details on a sample setup :
ecosystem.json :
{
"apps" : [{
"name" : "my_app",
"script" : "main.js",
"exec_mode" : "cluster",
"autorestart": true,
"cron_restart" : "* * * * *",
"log_date_format": "YYYY-MM-DD HH:mm:ss"
}]
}
main.js :
// Logs on startup
console.log('my_app started');
// Pings every 10s
setInterval(() => console.log('my_app is running'), 10 * 1000);
// Dies after 1m20s (shouldn't happen since pm2 is supposed to restart us every minute)
setTimeout(() => { console.log('my_app will die'); process.exit(0); }, 80 * 1000);
Output of pm2 log :
(can't seem to have PM2 daemon logs include timestamps for some reason ?)
PM2 | App [my_app:0] starting in -cluster mode- <-- "pm2 start ecosystem.json"
PM2 | App [my_app:0] online
0|my_app | 2019-06-05 13:34:04: my_app started
0|my_app | 2019-06-05 13:34:14: my_app is running
PM2 | [PM2][WORKER] Registering a cron job on: 0
0|my_app | 2019-06-05 13:34:24: my_app is running
0|my_app | 2019-06-05 13:34:34: my_app is running
0|my_app | 2019-06-05 13:34:44: my_app is running
0|my_app | 2019-06-05 13:34:54: my_app is running
PM2 | App [my_app:0] starting in -cluster mode- <-- 1st cron restart at 13:35:00, works
PM2 | App [my_app:0] online
0|my_app | 2019-06-05 13:35:00: my_app started
_old_0|my_app | 2019-06-05 13:35:04: my_app is running <-- apparently the initial process (synced at second 4) keeps running for some time ?
0|my_app | 2019-06-05 13:35:10: my_app is running
PM2 | Stopping app:my_app id:_old_0 <-- the initial process is being stopped
PM2 | App name:my_app id:_old_0 disconnected
PM2 | App [my_app:_old_0] exited with code [0] via signal [SIGINT]
PM2 | pid=8462 msg=process killed
0|my_app | 2019-06-05 13:35:20: my_app is running
0|my_app | 2019-06-05 13:35:30: my_app is running
0|my_app | 2019-06-05 13:35:40: my_app is running
0|my_app | 2019-06-05 13:35:50: my_app is running
PM2 | Error: PM ID unknown <-- 2nd cron restart at 13:36:00, fails
PM2 | at Object.God.softReloadProcessId ([...]/pm2/lib/God/Reload.js:185:17)
PM2 | at CronJob.onTick ([...]//pm2/lib/Worker.js:40:13)
PM2 | at CronJob.fireOnTick ([...]//pm2/node_modules/cron/lib/cron.js:562:23)
PM2 | at Timeout.callbackWrapper [as _onTimeout] ([...]//pm2/node_modules/cron/lib/cron.js:629:10)
PM2 | at ontimeout (timers.js:436:11)
PM2 | at tryOnTimeout (timers.js:300:5)
PM2 | at listOnTimeout (timers.js:263:5)
PM2 | at Timer.processTimers (timers.js:223:10)
0|my_app | 2019-06-05 13:36:00: my_app is running <-- still running
0|my_app | 2019-06-05 13:36:10: my_app is running
0|my_app | 2019-06-05 13:36:20: my_app will die <-- dies after 80s (= 1min20s after the cron that worked)
PM2 | App name:my_app id:0 disconnected
PM2 | App [my_app:0] exited with code [0] via signal [SIGINT]
PM2 | App [my_app:0] starting in -cluster mode-
PM2 | App [my_app:0] online
0|my_app | 2019-06-05 13:36:20: my_app started <-- restarted by autorestart
0|my_app | 2019-06-05 13:36:30: my_app is running
etc...
- at every round clock minute, cron fails with Error: PM ID unknown
- process naturally dies every 100s, and gets restarted
yched
👍10
👀4
All 18 comments
Same setup (main.js / ecosystem.js) with pm2 3.2.2 :
works as expected : app restarts every minute, and never reaches "die after 1m20"
PM2 | App [my_app:0] starting in -cluster mode-
PM2 | App [my_app:0] online
0|my_app | 2019-06-05 14:47:42: my_app started
0|my_app | 2019-06-05 14:47:52: my_app is running
PM2 | Stopping app:my_app id:0 <-- 1st cron restart
PM2 | App name:my_app id:0 disconnected
PM2 | App [my_app:0] exited with code [0] via signal [SIGINT]
PM2 | pid=16476 msg=process killed
PM2 | App [my_app:0] starting in -cluster mode-
PM2 | App [my_app:0] online
PM2 | Application my_app has been restarted via CRON
0|my_app | 2019-06-05 14:48:00: my_app started
0|my_app | 2019-06-05 14:48:10: my_app is running
0|my_app | 2019-06-05 14:48:20: my_app is running
0|my_app | 2019-06-05 14:48:30: my_app is running
0|my_app | 2019-06-05 14:48:40: my_app is running
0|my_app | 2019-06-05 14:48:50: my_app is running
PM2 | Stopping app:my_app id:0 <-- 2nd cron restart
PM2 | App name:my_app id:0 disconnected
PM2 | App [my_app:0] exited with code [0] via signal [SIGINT]
PM2 | pid=16496 msg=process killed
PM2 | App [my_app:0] starting in -cluster mode-
PM2 | App [my_app:0] online
PM2 | Application my_app has been restarted via CRON
0|my_app | 2019-06-05 14:49:00: my_app started
0|my_app | 2019-06-05 14:49:10: my_app is running
etc...
Similar problem here
18601673727
on 26 Jun 2019
👍2
+1
krunalshah68
on 10 Jul 2019
same here
wong2
on 12 Jul 2019
same here.
Im rolling back to 3.2.2
ejames17
on 22 Jul 2019
👍1
same here
gnehs
on 2 Nov 2019
same here
The same problem occurs with version 3.5.1.
yahao87
on 11 Dec 2019
Same problem here,
Does anyone fix it?
mirajehossain
on 14 Jan 2020
Same problem. I deleted cron job with "pm2 delete {name}", after that it looks like pm2 is still trying to start that process.
rcupic
on 4 Feb 2020
Any solution to this? I am having this issue in a production server
kelleghan1
on 17 May 2020
Same problem here
Allain55
on 20 May 2020
This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.
![stale[bot] picture](https://avatars3.githubusercontent.com/in/1724?v=4&s=40)
stale[bot]
on 19 Jun 2020
That is still an issue
yched
on 19 Jun 2020
This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.
stale[bot]
on 19 Jul 2020
seriously ?
yched
on 19 Jul 2020
👍1
Facing same issue,
--- PM2 report ----------------------------------------------------------------
Date : Sat Aug 15 2020 20:24:46 GMT+0000 (Coordinated Universal Time)
===============================================================================
--- Daemon -------------------------------------------------
pm2d version : 4.4.0
node version : 12.18.3
node path : /usr/bin/pm2
argv : /usr/bin/node,/usr/lib/node_modules/pm2/lib/Daemon.js
argv0 : node
user : ubuntu
uid : 1000
gid : 1000
uptime : 40min
===============================================================================
--- CLI ----------------------------------------------------
local pm2 : 4.4.0
node version : 12.18.3
node path : /usr/bin/pm2
argv : /usr/bin/node,/usr/bin/pm2,report
argv0 : node
user : ubuntu
uid : 1000
gid : 1000
===============================================================================
--- System info --------------------------------------------
arch : x64
platform : linux
type : Linux
cpus : Intel(R) Xeon(R) CPU E5-2676 v3 @ 2.40GHz
cpus nb : 1
freemem : 114925568
totalmem : 1026158592
home : /home/ubuntu
===============================================================================
--- PM2 list -----------------------------------------------
┌─────┬─────────────────────────┬─────────────┬─────────┬─────────┬──────────┬────────┬──────┬───────────┬──────────┬──────────┬──────────┬──────────┐
│ id │ name │ namespace │ version │ mode │ pid │ uptime │ ↺ │ status │ cpu │ mem │ user │ watching │
├─────┼─────────────────────────┼─────────────┼─────────┼─────────┼──────────┼────────┼──────┼───────────┼──────────┼──────────┼──────────┼──────────┤
│ 0 │ Project2-SchedulerMS │ default │ 1.0.0 │ cluster │ 5068 │ 9m │ 1 │ online │ 0% │ 76.8mb │ ubuntu │ disabled │
└─────┴─────────────────────────┴─────────────┴─────────┴─────────┴──────────┴────────┴──────┴───────────┴──────────┴──────────┴──────────┴──────────┘
===============================================================================
--- Daemon logs --------------------------------------------
/home/ubuntu/.pm2/pm2.log last 20 lines:
PM2 | 2020-08-15T20:12:41: PM2 log: Stopping app:Project2-SchedulerMS id:0
PM2 | 2020-08-15T20:12:41: PM2 log: App name:Project2-SchedulerMS id:0 disconnected
PM2 | 2020-08-15T20:12:41: PM2 log: App [Project2-SchedulerMS:0] exited with code [0] via signal [SIGINT]
PM2 | 2020-08-15T20:12:41: PM2 log: pid=4934 msg=process killed
PM2 | 2020-08-15T20:13:09: PM2 log: [PM2][WORKER] Registering a cron job on: 0
PM2 | 2020-08-15T20:13:09: PM2 log: App [Project2-SchedulerMS:0] starting in -cluster mode-
PM2 | 2020-08-15T20:13:09: PM2 log: App [Project2-SchedulerMS:0] online
PM2 | 2020-08-15T20:15:00: PM2 log: App [Project2-SchedulerMS:0] starting in -cluster mode-
PM2 | 2020-08-15T20:15:00: PM2 log: App [Project2-SchedulerMS:0] online
PM2 | 2020-08-15T20:15:11: PM2 log: Stopping app:Project2-SchedulerMS id:_old_0
PM2 | 2020-08-15T20:15:11: PM2 log: App name:Project2-SchedulerMS id:_old_0 disconnected
PM2 | 2020-08-15T20:15:11: PM2 log: App [Project2-SchedulerMS:_old_0] exited with code [0] via signal [SIGINT]
PM2 | 2020-08-15T20:15:11: PM2 log: pid=5033 msg=process killed
PM2 | 2020-08-15T20:20:00: PM2 error: Error: pm_id _old_0 not available in _old_0
PM2 | at Object.God.softReloadProcessId (/usr/lib/node_modules/pm2/lib/God/Reload.js:194:17)
PM2 | at CronJob.onTick (/usr/lib/node_modules/pm2/lib/Worker.js:38:13)
PM2 | at CronJob.fireOnTick (/usr/lib/node_modules/pm2/node_modules/cron/lib/cron.js:600:23)
PM2 | at Timeout.callbackWrapper [as _onTimeout] (/usr/lib/node_modules/pm2/node_modules/cron/lib/cron.js:667:10)
PM2 | at listOnTimeout (internal/timers.js:549:17)
PM2 | at processTimers (internal/timers.js:492:7)
goodwillsandy
on 15 Aug 2020
This issue exists here when exec_mode: cluster. If you change to exec_mode: fork it will work.
Keep me posted.
goodwillsandy
on 15 Aug 2020
👍1
fixed in [email protected]:
npm install pm2@latest -g
pm2 update
Unitech
on 16 Dec 2020
Was this page helpful?
0 / 5 - 0 ratings
Related issues
getvega
·
3Comments
liujb
·
3Comments
psparago
·
3Comments
cchan
·
3Comments
lefam
·
3Comments
Most helpful comment
Similar problem here