Merge branch 'sh-structured-logs-docs' into 'master'
Add documentation on how to use structured logging Closes #54059 See merge request gitlab-org/gitlab-ce!23031
This commit is contained in:
Sean McGivern
commit
b44baf2edb
2 changed files with 145 additions and 0 deletions
|
|
@ -30,6 +30,7 @@ description: 'Learn how to contribute to GitLab.'
|
|||
## Backend guides
|
||||
|
||||
- [GitLab utilities](utilities.md)
|
||||
- [Logging](logging.md)
|
||||
- [API styleguide](api_styleguide.md) Use this styleguide if you are
|
||||
contributing to the API.
|
||||
- [GraphQL API styleguide](api_graphql_styleguide.md) Use this
|
||||
|
|
|
|||
144
doc/development/logging.md
Normal file
144
doc/development/logging.md
Normal file
|
|
@ -0,0 +1,144 @@
|
|||
# GitLab Developers Guide to Logging
|
||||
|
||||
[GitLab Logs](../administration/logs.md) play a critical role for both
|
||||
administrators and GitLab team members to diagnose problems in the field.
|
||||
|
||||
## Don't use `Rails.logger`
|
||||
|
||||
Currently `Rails.logger` calls all get saved into `production.log`, which contains
|
||||
a mix of Rails' logs and other calls developers have inserted in the code base.
|
||||
For example:
|
||||
|
||||
```
|
||||
Started GET "/gitlabhq/yaml_db/tree/master" for 168.111.56.1 at 2015-02-12 19:34:53 +0200
|
||||
Processing by Projects::TreeController#show as HTML
|
||||
Parameters: {"project_id"=>"gitlabhq/yaml_db", "id"=>"master"}
|
||||
|
||||
...
|
||||
|
||||
Namespaces"."created_at" DESC, "namespaces"."id" DESC LIMIT 1 [["id", 26]]
|
||||
CACHE (0.0ms) SELECT "members".* FROM "members" WHERE "members"."source_type" = 'Project' AND "members"."type" IN ('ProjectMember') AND "members"."source_id" = $1 AND "members"."source_type" = $2 AND "members"."user_id" = 1 ORDER BY "members"."created_at" DESC, "members"."id" DESC LIMIT 1 [["source_id", 18], ["source_type", "Project"]]
|
||||
CACHE (0.0ms) SELECT "members".* FROM "members" WHERE "members"."source_type" = 'Project' AND "members".
|
||||
(1.4ms) SELECT COUNT(*) FROM "merge_requests" WHERE "merge_requests"."target_project_id" = $1 AND ("merge_requests"."state" IN ('opened','reopened')) [["target_project_id", 18]]
|
||||
Rendered layouts/nav/_project.html.haml (28.0ms)
|
||||
Rendered layouts/_collapse_button.html.haml (0.2ms)
|
||||
Rendered layouts/_flash.html.haml (0.1ms)
|
||||
Rendered layouts/_page.html.haml (32.9ms)
|
||||
Completed 200 OK in 166ms (Views: 117.4ms | ActiveRecord: 27.2ms)
|
||||
```
|
||||
|
||||
These logs suffer from a number of problems:
|
||||
|
||||
1. They often lack timestamps or other contextual information (e.g. project ID, user)
|
||||
2. They may span multiple lines, which make them hard to find via Elasticsearch.
|
||||
3. They lack a common structure, which make them hard to parse by log
|
||||
forwarders, such as Logstash or Fluentd. This also makes them hard to
|
||||
search.
|
||||
|
||||
Note that currently on GitLab.com, any messages in `production.log` will
|
||||
NOT get indexed by Elasticsearch due to the sheer volume and noise. They
|
||||
do end up in Google Stackdriver, but it is still harder to search for
|
||||
logs there. See the [GitLab.com logging
|
||||
documentation](https://gitlab.com/gitlab-com/runbooks/blob/master/howto/logging.md)
|
||||
for more details.
|
||||
|
||||
## Use structured (JSON) logging
|
||||
|
||||
Structured logging solves these problems. Consider the example from an API request:
|
||||
|
||||
```json
|
||||
{"time":"2018-10-29T12:49:42.123Z","severity":"INFO","duration":709.08,"db":14.59,"view":694.49,"status":200,"method":"GET","path":"/api/v4/projects","params":[{"key":"action","value":"git-upload-pack"},{"key":"changes","value":"_any"},{"key":"key_id","value":"secret"},{"key":"secret_token","value":"[FILTERED]"}],"host":"localhost","ip":"::1","ua":"Ruby","route":"/api/:version/projects","user_id":1,"username":"root","queue_duration":100.31,"gitaly_calls":30}
|
||||
```
|
||||
|
||||
In a single line, we've included all the information that a user needs
|
||||
to understand what happened: the timestamp, HTTP method and path, user
|
||||
ID, etc.
|
||||
|
||||
### How to use JSON logging
|
||||
|
||||
Suppose you want to log the events that happen in a project
|
||||
importer. You want to log issues created, merge requests, etc. as the
|
||||
importer progresses. Here's what to do:
|
||||
|
||||
1. Look at [the list of GitLab Logs](../administration/logs.md) to see
|
||||
if your log message might belong with one of the existing log files.
|
||||
1. If there isn't a good place, consider creating a new filename, but
|
||||
check with a maintainer if it makes sense to do so. A log file should
|
||||
make it easy for people to search pertinent logs in one place. For
|
||||
example, `geo.log` contains all logs pertaining to GitLab Geo.
|
||||
To create a new file:
|
||||
1. Choose a filename (e.g. `importer_json.log`).
|
||||
1. Create a new subclass of `Gitlab::JsonLogger`:
|
||||
|
||||
```ruby
|
||||
module Gitlab
|
||||
module Import
|
||||
class Logger < ::Gitlab::JsonLogger
|
||||
def self.file_name_noext
|
||||
'importer_json'
|
||||
end
|
||||
end
|
||||
end
|
||||
end
|
||||
```
|
||||
|
||||
1. In your class where you want to log, you might initialize the logger as an instance variable:
|
||||
|
||||
```ruby
|
||||
attr_accessor :logger
|
||||
|
||||
def initialize
|
||||
@logger = Gitlab::Import::Logger.build
|
||||
end
|
||||
```
|
||||
|
||||
Note that it's useful to memoize this because creating a new logger
|
||||
each time you log will open a file, adding unnecessary overhead.
|
||||
|
||||
1. Now insert log messages into your code. When adding logs,
|
||||
make sure to include all the context as key-value pairs:
|
||||
|
||||
```ruby
|
||||
# BAD
|
||||
logger.info("Unable to create project #{project.id}")
|
||||
```
|
||||
|
||||
```ruby
|
||||
# GOOD
|
||||
logger.info("Unable to create project", project_id: project.id)
|
||||
```
|
||||
|
||||
1. Be sure to create a common base structure of your log messages. For example,
|
||||
all messages might have `current_user_id` and `project_id` to make it easier
|
||||
to search for activities by user for a given time.
|
||||
|
||||
1. Do NOT mix and match types. Elasticsearch won't be able to index your
|
||||
logs properly if you [mix integer and string
|
||||
types](https://www.elastic.co/guide/en/elasticsearch/guide/current/mapping.html#_avoiding_type_gotchas):
|
||||
|
||||
```ruby
|
||||
# BAD
|
||||
logger.info("Import error", error: 1)
|
||||
logger.info("Import error", error: "I/O failure")
|
||||
```
|
||||
|
||||
```ruby
|
||||
# GOOD
|
||||
logger.info("Import error", error_code: 1, error: "I/O failure")
|
||||
```
|
||||
|
||||
## Additional steps with new log files
|
||||
|
||||
1. Consider log retention settings. By default, Omnibus will rotate any
|
||||
logs in `/var/log/gitlab/gitlab-rails/*.log` every hour and [keep at
|
||||
most 30 compressed files](https://docs.gitlab.com/omnibus/settings/logs.html#logrotate).
|
||||
On GitLab.com, that setting is only 6 compressed files. These settings should suffice
|
||||
for most users, but you may need to tweak them in [omnibus-gitlab](https://gitlab.com/gitlab-org/omnibus-gitlab).
|
||||
|
||||
1. If you add a new file, submit an issue to the [production
|
||||
tracker](https://gitlab.com/gitlab-com/gl-infra/production/issues) or
|
||||
a merge request to the [gitlab_fluentd](https://gitlab.com/gitlab-cookbooks/gitlab_fluentd)
|
||||
project. See [this example](https://gitlab.com/gitlab-cookbooks/gitlab_fluentd/merge_requests/51/diffs).
|
||||
|
||||
1. Be sure to update the [GitLab CE/EE documentation](../administration/logs.md) and the [GitLab.com
|
||||
runbooks](https://gitlab.com/gitlab-com/runbooks/blob/master/howto/logging.md).
|
||||
Loading…
Reference in a new issue