Logs are truncated

[binarykitchen]

Here an example. You can see that further down where the error lines appear, the information is truncated:

$ pm2 logs
########### Starting streaming logs for [all] process
[gith.videomail.io-0 (out)] [39mDumping processes
[gith.videomail.io-0 (out)] Deploy script ended on Tue Sep 02 2014 16:56:46 GMT+1200 (NZST) with exit code 0
[gith.videomail.io-0 (out)] Gith for videomail.io repository on GitHub running at http://gith.binarykitchen.com on Tue Sep 02 2014 16:57:45 GMT+1200 (NZST)
[gith.videomail.io-0 (out)] Gith for videomail.io repository on GitHub running at http://gith.binarykitchen.com on Tue Sep 02 2014 16:58:25 GMT+1200 (NZST)
[gith.videomail.io-0 (out)] Gith for videomail.io repository on GitHub running at http://gith.binarykitchen.com on Tue Sep 02 2014 16:58:38 GMT+1200 (NZST)
[gith.videomail.io-0 (out)] Gith for videomail.io repository on GitHub running at http://gith.binarykitchen.com on Tue Sep 02 2014 16:58:48 GMT+1200 (NZST)
[gith.videomail.io-0 (out)] Gith for videomail.io repository on GitHub running at http://gith.binarykitchen.com on Tue Sep 02 2014 17:02:37 GMT+1200 (NZST)
[gith.videomail.io-0 (out)] Gith for videomail.io repository on GitHub running at http://gith.binarykitchen.com on Tue Sep 02 2014 17:04:33 GMT+1200 (NZST)
[gith.videomail.io-0 (out)] Gith for videomail.io repository on GitHub running at http://gith.binarykitchen.com on Tue Sep 02 2014 17:07:24 GMT+1200 (NZST)
[dev.videomail.io-1 (out)] 20,"msg":"Cleaned old temporary clients","time":"2014-09-02T05:04:54.601Z","v":0}
[dev.videomail.io-1 (out)] {"name":"videomail.io","hostname":"binarykitchen.com","pid":5877,"level":30,"msg":"videomail.io v1.0.0 started with node v0.10.31 on port 4442 in development and HTTPS mode","time":"2014-09-02T05:04:54.609Z","v":0}
[dev.videomail.io-1 (out)] {"name":"videomail.io","hostname":"binarykitchen.com","pid":7311,"level":20,"msg":"Booting now ...","time":"2014-09-02T05:07:31.527Z","v":0}
[dev.videomail.io-1 (out)] {"name":"videomail.io","hostname":"binarykitchen.com","pid":7311,"level":20,"msg":"LevelDB /var/www/videomail/development/var/development/level ready","time":"2014-09-02T05:07:32.694Z","v":0}
[dev.videomail.io-1 (out)] {"name":"videomail.io","hostname":"binarykitchen.com","pid":7311,"level":20,"msg":"Cleaned old temporary clients","time":"2014-09-02T05:07:32.709Z","v":0}
[dev.videomail.io-1 (out)] {"name":"videomail.io","hostname":"binarykitchen.com","pid":7311,"level":30,"msg":"videomail.io v1.0.0 started with node v0.10.31 on port 4442 in development and HTTPS mode","time":"2014-09-02T05:07:32.717Z","v":0}
[dev.videomail.io-1 (err)] 3)
[dev.videomail.io-1 (err)]     at process.<anonymous> (/var/www/videomail/development/src/middleware/shutdown.js:40:17)
[dev.videomail.io-1 (err)]     at g (events.js:180:16)
[dev.videomail.io-1 (err)]     at process.emit (events.js:92:17)
[dev.videomail.io-1 (err)]     at wrap.onsignal (node.js:761:46)
[dev.videomail.io-1 (err)] ---------------------------------------------
[dev.videomail.io-1 (err)]     at /var/www/videomail/development/src/middleware/shutdown.js:39:21
[dev.videomail.io-1 (err)]     at Array.forEach (native)
[dev.videomail.io-1 (err)]     at Server.<anonymous> (/var/www/videomail/development/src/middleware/shutdown.js:38:22)
[dev.videomail.io-1 (err)]     at Server.emit (events.js:117:20)
[dev.videomail.io-1 (err)]     at net.js:1055:10
[dev.videomail.io-1 (err)]     at process._tickCallback (node.js:419:13)
[dev.videomail.io-1 (err)] ---------------------------------------------
[dev.videomail.io-1 (err)]     at exports.listen (/var/www/videomail/development/src/middleware/shutdown.js:36:12)
[dev.videomail.io-1 (err)]     at Object.<anonymous> (/var/www/videomail/development/src/server.js:88:18)
[dev.videomail.io-1 (err)]     at Module._compile (module.js:456:26)
[dev.videomail.io-1 (err)]     at Module._extensions..js (module.js:474:10)
[dev.videomail.io-1 (err)]     at Module.load (module.js:356:32)
[dev.videomail.io-1 (err)]     at Module._load (module.js:312:12)
[dev.videomail.io-1 (err)]     at Module.require (module.js:364:17)
[dev.videomail.io-1 (err)]     at require (module.js:380:17)

this one!

[dev.videomail.io-1 (err)] 3)

How come?

[Unitech]

It's put on standby, in your logs file it should be okay

[binarykitchen]

Ok ... but what do you mean with "putting on standby"? And won't others get confused if they see truncated logs?

[soyuka]

Might this be related to #338 (comment) ?

@binarykitchen pm2 ilogs might be more accurate on this as pm2 logs doesn't listen on process events, if it has been killed pm2 logs will also break logs...

[binarykitchen]

Yep, might be related to #388 but difficult to say since it appears to be a race condition.

Uh, I wasn't fully aware about the difference between pm2 ilogs and pm2 logs ... can you explain again in different words the difference between these two log commands?

[soyuka]

ilogs comes from the https://github.com/keymetrics/pm2-logs module. It's listening to log events through pm2-interface:

ipm2.on('ready', function() {

  //your process is logging to stdout
  ipm2.bus.on('log:out', function(err, d) { })

  //and to stderr
  ipm2.bus.on('log:err', function(err, d) { })

})

See the related article on how to build a pm2 logger on your own. It's also listening on process events like restart or kill and is pm2 independent. I find it nice to real-time debug applications that are beeing restarted a lot.

[binarykitchen]

Wow, that's awesome stuff. Thanks for explaining. Looking forward to pm2.io ;)