search

Unitech / pm2

Node.js Production Process Manager with a built-in Load Balancer.
https://pm2.keymetrics.io/docs/usage/quick-start/
Other
41.36k stars 2.61k forks source link

pm2 flush prevents apps from logging #3681

Closed Fl4m3Ph03n1x closed 4 years ago

Fl4m3Ph03n1x commented 6 years ago

What's going wrong?

This morning I realized I needed to flush some logs because our machine was running out of log space. So I run pm2 flush.

Then, I left my apps untouched. A few hours later I realized my apps were not writing anything to the logs. In fact running pm2 log my-app always returned empty.

This was specially visible with our session app.

I fixed the problem by doing pm2 reaload all.

It is the second time this happens and no one really knows why.

How could we reproduce this issue?

Have a running app with a high output throughput to logs ( lets say, around 50 lines/second ). Use pm2 flush Run pm2 log

If your it shows an empty result, you have replicated the issue.

Supporting information

===============================================================================
--- PM2 REPORT (Wed May 23 2018 15:16:14 GMT+0000 (UTC)) ----------------------
===============================================================================
--- Daemon -------------------------------------------------
pm2d version         : 2.6.1
node version         : 6.11.3
node path            : /usr/bin/pm2
argv                 : /usr/bin/node,/usr/lib/node_modules/pm2/lib/Daemon.js
argv0                : node
user                 : vera
uid                  : 1000
gid                  : 1000
uptime               : 58110min
===============================================================================
--- CLI ----------------------------------------------------
local pm2            : 2.6.1
node version         : 6.11.3
node path            : /usr/bin/pm2
argv                 : /usr/bin/node,/usr/bin/pm2,report
argv0                : node
user                 : vera
uid                  : 1000
gid                  : 1000
===============================================================================
--- System info --------------------------------------------
arch                 : x64
platform             : linux
type                 : Linux
cpus                 : Intel(R) Xeon(R) CPU E5-2673 v4 @ 2.30GHz
cpus nb              : 2
freemem              : 4065140736
totalmem             : 8352788480
home                 : /home/vera
===============================================================================
--- PM2 list -----------------------------------------------
┌──────────────┬────┬─────────┬───────┬────────┬─────────┬────────┬─────┬───────────┬──────┬──────────┐
│ App name     │ id │ mode    │ pid   │ status │ restart │ uptime │ cpu │ mem       │ user │ watching │
├──────────────┼────┼─────────┼───────┼────────┼─────────┼────────┼─────┼───────────┼──────┼──────────┤
│ api          │ 1  │ cluster │ 39733 │ online │ 20      │ 17m    │ 0%  │ 78.3 MB   │ vera │ disabled │
│ bwireless    │ 17 │ cluster │ 39881 │ online │ 1       │ 17m    │ 0%  │ 53.0 MB   │ vera │ disabled │
│ condition    │ 3  │ cluster │ 39755 │ online │ 2       │ 17m    │ 1%  │ 63.9 MB   │ vera │ disabled │
│ consumer     │ 0  │ cluster │ 39727 │ online │ 1       │ 17m    │ 2%  │ 69.6 MB   │ vera │ disabled │
│ contract     │ 11 │ fork    │ 39842 │ online │ 2       │ 17m    │ 1%  │ 94.3 MB   │ vera │ disabled │
│ ian.jr       │ 14 │ cluster │ 39863 │ online │ 15      │ 17m    │ 0%  │ 61.8 MB   │ vera │ disabled │
│ iot          │ 12 │ cluster │ 39848 │ online │ 9       │ 17m    │ 3%  │ 73.6 MB   │ vera │ disabled │
│ lastcom      │ 8  │ cluster │ 39801 │ online │ 4       │ 17m    │ 0%  │ 63.3 MB   │ vera │ disabled │
│ lastcom      │ 9  │ cluster │ 39817 │ online │ 4       │ 17m    │ 0%  │ 61.4 MB   │ vera │ disabled │
│ lastcom      │ 6  │ cluster │ 39779 │ online │ 4       │ 17m    │ 0%  │ 61.1 MB   │ vera │ disabled │
│ lastcom      │ 7  │ cluster │ 39794 │ online │ 4       │ 17m    │ 0%  │ 62.0 MB   │ vera │ disabled │
│ old.events   │ 2  │ cluster │ 39749 │ online │ 1       │ 17m    │ 0%  │ 58.2 MB   │ vera │ disabled │
│ rabbit.alert │ 16 │ cluster │ 39874 │ online │ 3       │ 17m    │ 0%  │ 55.3 MB   │ vera │ disabled │
│ session      │ 10 │ cluster │ 39828 │ online │ 2       │ 17m    │ 0%  │ 60.6 MB   │ vera │ disabled │
│ sigfox       │ 25 │ fork    │ 39900 │ online │ 1       │ 16m    │ 4%  │ 65.3 MB   │ vera │ disabled │
│ stat         │ 18 │ fork    │ 39912 │ online │ 6       │ 16m    │ 2%  │ 91.1 MB   │ vera │ disabled │
│ verify       │ 5  │ cluster │ 39772 │ online │ 1       │ 17m    │ 0%  │ 52.2 MB   │ vera │ disabled │
└──────────────┴────┴─────────┴───────┴────────┴─────────┴────────┴─────┴───────────┴──────┴──────────┘
===============================================================================
--- Daemon logs --------------------------------------------
/home/vera/.pm2/pm2.log last 20 lines:
PM2        | 2018-05-23 14:59:18: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:18: pid=2184 msg=process killed
PM2        | 2018-05-23 14:59:18: Process 25 in a stopped status, starting it
PM2        | 2018-05-23 14:59:18: Stopping app:sigfox id:25
PM2        | 2018-05-23 14:59:18: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:18: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:18: App [sigfox] with id [25] and pid [75721], exited with code [0] via signal [SIGINT]
PM2        | 2018-05-23 14:59:18: pid=75721 msg=process killed
PM2        | 2018-05-23 14:59:18: Starting execution sequence in -fork mode- for app name:sigfox id:25
PM2        | 2018-05-23 14:59:18: App name:sigfox id:25 online
PM2        | 2018-05-23 14:59:18: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:18: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:18: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:18: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:19: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:19: pid=24395 msg=failed to kill - retrying in 100ms
PM2        | 2018-05-23 14:59:19: App [stat] with id [18] and pid [24395], exited with code [0] via signal [SIGINT]
PM2        | 2018-05-23 14:59:19: pid=24395 msg=process killed
PM2        | 2018-05-23 14:59:19: Starting execution sequence in -fork mode- for app name:stat id:18
PM2        | 2018-05-23 14:59:19: App name:stat id:18 online
stale[bot] commented 4 years ago

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.