Commit Graph

15 Commits

Author SHA1 Message Date
Stan Hu 1136c0c8e9 Add Rugged calls and duration to API and Rails logs
This adds `rugged_duration_ms` and `rugged_calls` fields to
`api_json.log` and `production_json.log`. This will make it easier to
identify performance issues caused by excessive I/O.

Closes https://gitlab.com/gitlab-org/gitlab-ce/issues/64676
2019-07-18 06:53:39 -07:00
Heinrich Lee Yu aeb67dd489 Upgrade to Rails 5.2
Updates changed method names and fixes spec failures
2019-07-12 10:15:31 +08:00
Andrew Newdigate 4f4de36cac Migrate correlation and tracing code to LabKit
This change is a fairly straightforward refactor to extract the tracing
and correlation-id code from the gitlab rails codebase into the new
LabKit-Ruby project.

The corresponding import into LabKit-Ruby was in
https://gitlab.com/gitlab-org/labkit-ruby/merge_requests/1

The code itself remains very similar for now.

Extracting it allows us to reuse it in other projects, such as
Gitaly-Ruby. This will give us the advantages of correlation-ids and
distributed tracing in that project too.
2019-04-18 09:57:16 +02:00
Stan Hu 74ff33a3fd Log Gitaly RPC duration to api_json.log and production_json.log
This makes it easier to debug Gitaly performance issues in the field.

This commit also makes the tracking of query time thread-safe via
RequestStore.
2019-03-27 06:01:21 -05:00
Stan Hu 51ca79228b Log queue duration in production_json.log
`queue_duration` is a useful metric that is currently in api_json.log
but not in production_json.log. We should add it because it tells us how
long the request sat in Workhorse before Unicorn processed it. Having
this field enables the support team to better troubleshoot when delays
began to happen.
2019-02-12 06:58:55 -08:00
Kamil Trzciński 39c1731a53 Log and pass correlation-id between Unicorn, Sidekiq and Gitaly
The Correlation ID is taken or generated from received X-Request-ID.
Then it is being passed to all executed services (sidekiq workers
or gitaly calls).

The Correlation ID is logged in all structured logs as `correlation_id`.
2018-12-06 20:46:14 +01:00
Stan Hu 93005b4e81 Add User-Agent to production_json.log
This will help production gain more visibility which browsers may be
having issues.
2018-09-05 14:43:09 -07:00
Stan Hu 5d3abdf9a7 Log response body to production_json.log when a controller responds with a 422 status
We have a number of import errors occurring with 422 errors, and
it's hard to determine why they are happening. This change will
surface the errors in the log lines.

Relates to #47365
2018-06-06 13:16:15 -07:00
Stan Hu 69246ec8d2 Bump lograge to 0.10.0 and remove monkey patch
lograge 0.10.0 contains the `Location` query string fix in
https://github.com/roidrage/lograge/pull/241 among other minor changes:
https://github.com/roidrage/lograge/blob/master/CHANGELOG.md
2018-04-23 13:00:02 -07:00
Stan Hu 467aa65e11 Strip any query string parameters from Location headers from lograge
Port of https://github.com/roidrage/lograge/pull/241
2018-03-20 16:38:36 -07:00
Andrew Newdigate e62a6cca08 Fix for open-ended parameter's in lograge causing elastic memory issues 2018-02-28 15:45:41 +00:00
Andrew Newdigate 64d7ec0a9e Detect n+1 issues involving Gitaly 2017-09-19 10:55:37 +00:00
Stan Hu 9bc176b2c3 Add remote IP, user ID and username to JSON lograge output
This makes the logs a bit more useful to search requests by users.
2017-07-28 00:48:03 -05:00
Stan Hu 68529f4f80 Standardize on ISO8601 UTC time for lograge 2017-07-20 07:58:01 -07:00
Stan Hu e2b1c16ade Add structured logging for Rails processes
This introduces JSON logging for Rails views saved to a file called
`development_json.log`, `production_json.log`, etc.

For example, instead of this unparsable log:

```
Started GET "/" for 127.0.0.1 at 2012-03-10 14:28:14 +0100
Processing by HomeController#index as HTML
  Rendered text template within layouts/application (0.0ms)
  Rendered layouts/_assets.html.erb (2.0ms)
  Rendered layouts/_top.html.erb (2.6ms)
  Rendered layouts/_about.html.erb (0.3ms)
  Rendered layouts/_google_analytics.html.erb (0.4ms)
Completed 200 OK in 79ms (Views: 78.8ms | ActiveRecord: 0.0ms)
```

We get a single line with this:

```
{"method":"GET","path":"/,"format":"html","controller":"HomeController","action":"index","status":200,"duration":79,"view":78.8,"db":0.0,"location":"http://localhost/","time":"2017-07-18 09:35:17 -0700"}
```

Part of #20060
2017-07-18 09:49:21 -07:00