Improve the logging of our ALM server

[hectorj2f]

Our ALM server is quite noisy and its logs lack of a structure. We should also add different log levels depending on whether the system runs on production or in a development environment. Likewise, the format of the logs should also differ based on the prod/dev mode being either structured json or unstructured string lines.

[kwk]

See also @aslakknutsen 's #91

[kwk]

@hectorj2f I thought about this myself once and in every new PR I tell people to remove prints or log prints that aren't absolutely necessary. Most of the time "work item created 19830" messages don't add any value. I was a little bit intimidated by Dave Cheney's post on logging though: https://dave.cheney.net/2015/11/05/lets-talk-about-logging . It reads as if one is not to use leveled logging. I'd like to see computer consumable logging though (e.g. for consumption in elastic search or something).

[hectorj2f]

@kwk Yeah! The idea is generating logs that can easily feed other external tools such as (elk, riemann, or whatever we use in our infras). Another idea is to distinguish modes/levels cause you can add unnecessary logs that don't add any value if you define, e.g. INFO level..., DEBUG level.

[kwk]

@hectorj2f if the logs don't add any benefit, why add them in the first place?

[hectorj2f]

@kwk There are a couple of things related with logs:

• Logs without any value should be removed.
• Logs that add value whenever you need to DEBUG an ERROR. To track the origin of the ERROR and how it occurred. These error helps to a #dev team to detect and fix the problem.
• Logs that shows information about a running application (normally known as INFO logs).
• Logs that informs about the ERRORS, should give some information about where the error happened, when and the stacktrace. These error helps to a #ops team to detect whether the problem is in the machine or the app.

When I mean logs that don't give any value I consider logs such as Error ... or work item created 19830. Yes, those should not be added.

I talk about LEVELs but that could also be achieved using modes or even using a verbosity indicator.

[hectorj2f]

@kwk Do you mean to omit log levels and distinct modes ? Just to log the necessary info. But I am wondering if you remove the benefit of different levels of verbosity in an app.

[kwk]

I think we should have log levels. Sorry for my previous comments.

[hectorj2f]

I have researched among some golang logging packages. I found the following packages:

• https://github.com/sirupsen/logrus: 1400 Stars; 574 Forks; Last commit 4h ago
• https://github.com/go-kit/kit/tree/master/log: 5845 Starts (from the whole go-kit repo); 523 Forks; Last commit 22 days ago
• https://github.com/inconshreveable/log15= 578 Starts; 74 Forks; Last commit 19h ago
• https://github.com/golang/glog (classic one)= 1278 Starts; Forks; Last commit 25 Jan 2016; This pkg is also adapted in other known open source projects.

All of four solutions offer the possibility to define log levels + different output formats (all of the structured).

At this moment, we use log from the golang library to log stuff. Similarly goa also uses log with the creation of an adapter.

@kwk @aslakknutsen Do you think about these solutions ? I like the simplicity of go-kit/log although we could follow a similar approach others do with glog

[kwk]

@hectorj2f

• https://github.com/sirupsen/logrus looks way to verbose IMHO
• https://github.com/go-kit/kit/tree/master/log seems okay
• https://github.com/inconshreveable/log15 I like the fact that you can alias-import log15 as log and it effectively replaces all existing log.Printf calls and alike
• https://github.com/golang/glog I have used this and found it not very good. The last commit is older than half a year which either means that it is stable or outdated.

I also found these pkgs:

• https://github.com/op/go-logging
• https://github.com/juju/loggo mentioned by Dave Cheney (here https://dave.cheney.net/2015/11/05/lets-talk-about-logging)

[xcoulon]

Logrus seems to be quite popular amongst Go projects hosted on GitHub: https://medium.com/@_orcaman/most-imported-golang-packages-some-insights-fb12915a07#.r8brg75j3. It can be verbose if we use the WithFields() method for each call, but when used once to declare a local variable, it's pretty straightforward. Plus, it could be helpful to structure and categorize the logs. Just my 0.02$ ;-)

[kwk]

Found this overview of logging libs: http://libs.club/golang/developement/logging This site might also be usable for other things when finding libs.

[aslakknutsen]

LogRus doesn't look bad. I would suspect we would want to hide that complexity behind specific log adaptors anyway. Instead of:

log.WithFields(log.Fields{
    "omg":    true,
    "number": 122,
  }).Warn("The group's number increased tremendously!")

WILogger.NotFound(wi.id, wi.x, wi.z)

func (w WILogger) NotFound(id, x, z string) {
  w.log.WithFields(log.Fields{
      "id":   id,
      "x": x,
      "z": z,
    }).Info("The work item was not found")
}

[xcoulon]

actually, I was thinking about having a custom logger in each package, to categorize the logs:

var logger = log.WithFields(log.Fields{
    "category":    "workitem",
    ....
  })

and then in the code, when needing to log something:

logger.Info("The work item was not found")

[hectorj2f]

@xcoulon That isn't the right way having to declare a new logger per package. We can define an unique one that is used for all the pkgs of our application. Ofc, this logger will show information to understand in which pkg the log is prompted, etc...

[xcoulon]

@hectorj2f hum, ok. I'll check your code once you have a pull request, to improve my go skills/knowledge ;-)

[hectorj2f]

It isn't my way the way to go :), but I could only imagine your approach if you have sub-applications inside the same repo. For instance, you have a cli that uses a different logger with different characteristics than the server. But for each package, I don't see the benefits plus it might be harder to maintain if you want to change stuff.

[hectorj2f]

Thanks guys! I'll focus on coding something using logrus and probably try go-kit/log to show you how it'd look. 👍

[hectorj2f]

This has been addressed by the PR #770