Skip to content

WIP: Add structured logging support, but keep current access log format

username-removed-676946 requested to merge pchojnacki/gitlab-workhorse:add-logrus into master

Description

As part of solving #91 I think its worth adding better structured logging support.

Logrus is logging library that has a lot of of support for different log ETL pipelines e.g. FluentD, Logstash, and many others

This change is backwards incompatible in some ways.

Currently change most workhorse logs are simple access-log style logs that with few other log lines in case of errors etc. I've refactored access-logs to be separate log output that will only contain logs in that forma. While all other logs as well as new structured request log will be handled through logrus logger that will be controlled by new configuration flags.

New configuration flags are:

  • enableAccessLog - default: false, Enables Access Log

  • accessLogFile - access log file location if empty then output will be logged to stderr

  • logFile - log location in where logrus logs will be stored, this is the same config option that was used to control where old style logs go, while logrus has many different options for log transport currently I think its worth supporting only saving logs to local file

  • logFormat - logrus serialization format, valid values are "none", "json", "logstash, "text". none causes logs to be disabled completely

Example logs line

text

time="2017-01-25T11:49:29+01:00" level=info msg="error: GET \"/favicon.ico\": badgateway: failed after 0s: dial tcp [::1]:8080: getsockopt: connection refused" method=GET uri="/favicon.ico" 
time="2017-01-25T11:49:29+01:00" level=info msg="GET/favicon.icoHTTP/1.1" bytesWritten=24 method=GET proto="HTTP/1.1" referer="http://localhost:8181/test/test.git" requestTime=0.002163494 started=2017-01-25 11:49:29.0283811 +0100 CET status=502 ua="Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/55.0.2883.95 Safari/537.36" uri="/favicon.ico"

logstash

{"@timestamp":"2017-01-25 11:51:49.541","@version":"1","level":"info","message":"error: GET \"/favicon.ico\": badgateway: failed after 0s: dial tcp [::1]:8080: getsockopt: connection refused","method":"GET","uri":"/favicon.ico"}
{"@timestamp":"2017-01-25 11:51:49.541","@version":"1","bytesWritten":24,"level":"info","message":"GET/favicon.icoHTTP/1.1","method":"GET","proto":"HTTP/1.1","referer":"http://localhost:8181/test/test.git","requestTime":0.0014855860000000001,"started":"2017-01-25T11:51:49.539718598+01:00","status":502,"ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/55.0.2883.95 Safari/537.36","uri":"/favicon.ico"}

Whats next

After we are ok with this changes we need to be able to incorporate it into our infrastructure to get the logs properly parsed and indexed.

Knowing some companies, and our current log processing I think its worth keeping access-log for at least next few releases. Then we could phase it out and use only structured logs.

With new structured request logs we should be able to get percentile latency data directly from kibana. And based on that data we will be able setup proper prometheus histogram buckets.

Merge request reports