fix(logger): reduce CPU/memory usage

[bacongobbler]

The way we spawned and checked to ensure the weblog server was running was a bit backwards, causing the logger to run with massive CPU usage after a few hours because of the state loop. Changing the server logic to instead defer to net/http for serving requests and shutting down the connection at the net.Listener reduces CPU usage significantly.

Additionally the Redis adapter had a similar issue; creating connections, writing every second, never close the connection and re-initiate a new connection. Re-using the connection will reduce CPU cycle usage significantly.

TESTING:

• deploy this image on top of workflow-dev
• run kubectl exec -it deis-logger-asdfsf top

CPU usage should now be observed much lower than it was before.

closes #102 closes #104

[deis-bot]

@krancour, @jchauncey and @arschles are potential reviewers of this pull request based on my analysis of git blame information. Thanks @bacongobbler!

[bacongobbler]

I'm still seeing 6.7% spikes even at idle... Must be something else

[codecov-io]

Current coverage is 41.73% (diff: 39.28%)

Merging #113 into master will increase coverage by 0.24%

@@             master       #113   diff @@
==========================================
  Files            10         13     +3   
  Lines           323        381    +58   
  Methods           0          0          
  Messages          0          0          
  Branches          0          0          
==========================================
+ Hits            134        159    +25   
- Misses          169        201    +32   
- Partials         20         21     +1   

Powered by Codecov. Last update 630521d...9bd19a3

[bacongobbler]

OK, let's hope the Redis changes fixes things. @jeroenvisser101 confirmed that switching storage adapters reduced CPU usage, and since it happens even when the logger is "idling" I have to assume it's something in the control loop.

[jeroenvisser101]

@bacongobbler if you've got time, I can deploy this into production and we can do tests there? Let me know :)

[jeroenvisser101]

btw, it still shows ./main.go:36: undefined: s in s.Start in jenkins, but if it's ready to test, just ping me on slack or here, and we'll be able to test it in prod.

[bacongobbler]

I'm still testing this myself. Once it's ready for others to review I'll label it as such :)

[jeroenvisser101]

Nice, thanks!

[bacongobbler]

2016/09/13 23:59:55 Error executing pipeline: redis: client is closed

d'oh.

[bacongobbler]

Looks like everything passed except for codecov (even after test coverage being increased with this change) so this is ready for review! Testing instructions have been added to the OP.

[mboersma]

This is 💚 now, but it didn't have unit tests to cover the new code introduced. Is it reasonable to add coverage in logger_test.go or elsewhere?

[bacongobbler]

Absolutely. I'll add some logger unit tests in here as well.

[jchauncey]

@bacongobbler ive installed this on my cluster will let it run the weekend

[bacongobbler]

Hey @jchauncey any update on your cluster's state? Just about to bring one up myself as you can see CPU spikes even after 5 minutes of running.

[bacongobbler]

@jchauncey granted me access to his cluster as he's on a plane atm. This is the weekend graph from the logger with the redis adapter enabled. Not sure about the spike in memory initially, but over the weekend CPU usage was at zero and memory usage was stable.

I've also attached a report of what the old logger's CPU and memory usage looked like over a period of 8 hours for comparison, in orange. Notice that the leftmost green graph shows a weekend high of .006s of CPU usage, whereas the orange graph (the old logger, over 8 hours) shows a high of a little over 4 seconds. The memory usage graphs explain themselves, with the orange graph showing a peak of 63MiB where the new logger shows an initial unexplained peak (restoring info from redis, perhaps?), then it stays under 3MiB in usage while idling.

[felixbuenemann]

@bacongobbler Looking good here as well. I had the new build running over the weekend and it's at roughly 0% CPU and 10 MB RSS. ❤️

[bacongobbler]

@mboersma I just added a massive load of server tests, let me know if you'd like to see redis adapter tests as well and I'll re-label this as necessary.

[jeroenvisser101]

Roughly the same here!

[jchauncey]

@bacongobbler ready to merge