Consider customising default logged attributes

[ac-astuartkregor]

Hi there, thanks for taking the time to read this.

I'm looking at putting structured logging into our rails apps and Ougai seems to give me what I'm looking for. I was wondering what people think about being able to turn off certain properties/fields that are logged by default.

Consider the following example, where the name, hostname, pid, level, time and 'v' attributes are included in the log messages.

{"name":"rails","hostname":"sample-app","pid":7,"level":30,"time":1527602643707,"v":1,"foo":"bar","message":"Generated in new_model."}
{"name":"rails","hostname":"sample-app","pid":7,"level":30,"time":1527602643808,"v":1,"method":"GET","path":"/","format":"html","controller":"NewController","action":"new","status":200,"duration":123.81,"view":8.01,"params":{}}

In my use case, these fields are not useful or desirable and they end up cluttering the logs. The output I'd like is similar to this, with the aforementioned fields removed:

{"@timestamp":"2018-05-29T15:03:50.516+01:00","foo":"bar","message":"Generated in new_model."}
{"@timestamp":"2018-05-29T15:03:50.641+01:00","method":"GET","path":"/","format":"html","controller":"NewController","action":"new","status":200,"duration":147.87,"view":19.29,"params":{}}

To achieve this, I've used a custom formatter which does not pass those fields to dump. I've also combined ougai with lograge.

What I was wanting to discuss is an additional config item, something like this:

config.logger.default_fields = [:pid]

The way I envisage this working is that if the config isn't set, then the default fields would be as normal, i.e. [:name, :hostname, :pid, :level, :time, :v]. However, this setting could be overridden to exclude some of the default fields that the various formatters apply. This could perhaps be achieved by using a new formatter and possibly this setting then controlled at the point of initialization.

I'm open to ideas and suggestions and I am thinking of contributing with a PR, so would happily take suggestions for that too.

[ac-astuartkregor]

P.S. Perhaps what I would be looking for is a combination of a new ElasticSearch formatter, which has the same config option, or the preset fields configurable through the initializer. I noticed that I have the @timestamp field in as well, which isn't just a case of including or excluding default fields.

[tilfin]

Thank you for your proposal.

First of all, I think a log-output should be few processing procedures as soon as possible. If a logger has the options to output a log in itself, it's necessary to reflect the options each time log-output.

I think that it is more efficient to create a log format that matches your project than that way. I'm sorry that I have not provided the information to create cutomized formatter yet.

[ac-astuartkregor]

@tilfin Thanks for your quick reply and for your suggestions. Shall I go ahead and create a new formatter in Ougai itself? I think I can get started without needing any guidance. Once I've got a branch ready, I'll raise a PR if you'd like and we can discuss the approach there?

[tilfin]

@ac-astuartkregor No, I think it is best to create custom formatter for each project. I consider that Ougai may contain new log formatter if it corresponds to other well-known services and tools. But after all, I guess that everyone is trying to customize a formatter to be suitable for his or her project.

If you think that your formatter is convinience to others, I'm happy that you will try it as a rubygem.
There is already a custom formatter @eropple has been released.
https://github.com/eropple/ougai-formatters-inline_readable

[ac-astuartkregor]

@tilfin A fair point. I think perhaps the only formatter I could suggest would be one that's close to elasticsearch by convention, however the formatter changes I've made are certainly not specific only to elasticsearch, as you imply.

I will find or make a way of re-using the custom formatter easily across our projects instead. Thank you for your advice.

[luizcarvalho]

Ohh, I have exactly same need of the @ac-astuartkregor =(

[ac-astuartkregor]

@luizcarvalho You can override the Ougai::Formatters::Base#_call method to get the output that you want, for instance:

def _call(severity, time, progname, data)
  # Do any custom processing here
  data['rails-error'] = data.delete(:error) if data.has_key?(:error)
  data['@timestamp'] = format_datetime(time)
  data['@loglevel'] = severity || 'INFO'
  dump(data)
end

So for example, you could ignore the severity and progname parameters.

Edit: bad wording around severity and example.

[luizcarvalho]

Thank you @ac-astuartkregor <3