Log the current time when Puma shuts down.

[bsnape]

Hi,

My team occasionally observe Puma shutting down in our CI environment. We can't see any strange behaviour in the logs so we think that the process is being killed somehow.

We think that logging when Puma shuts down will help us investigate further.

Currently, Puma logs the time when it starts:

=== puma startup: 2014-06-27 13:13:48 +0100 ===

but not when it shuts down:

- Gracefully stopping, waiting for requests to finish
- Goodbye!

This simple patch fixes that (tested locally), and looks like this:

- Gracefully stopping, waiting for requests to finish
- Puma shutdown: 2014-07-01 14:13:10 +0100
- Goodbye!

Many thanks,
Ben

[seuros]

👍

[seuros]

What about having it === puma shutdown: 2014-07-01 14:13:10 +0100 === ?

[bsnape]

Sure! Whatever works for you.

Just pushed the change. 👍

[bsnape]

@seuros please can this be merged in now?

[seuros]

cc @evanphx

[evanphx]

The message should go the same place as the start message, which is not via #log, as that goes to stdout.

[nateless]

@bsnape, did you find the problem? I think our issue #554, can be related.

[bsnape]

Hey @nateless, sorry I got sidetracked by other things at work but I'm happy to get this moving again.

I was a little confused by @evanphx 's reply as it looks like there is a single startup message:

puma/lib/puma/runner.rb

Line 95 in b90fc4f

STDOUT.puts "=== puma startup: #{Time.now} ==="

But two different shutdown messages (both STDOUT and log):

https://github.com/puma/puma/search?q=goodbye&type=Code

Should those be reconciled or am I barking up the wrong tree?

As I said, happy to get this moving again as it will be useful for myself and others.