Skip to content

Instantly share code, notes, and snippets.

@weshouman

weshouman/gitlab_logs.md

Last active December 7, 2019 13:58
Show Gist options
  • Save weshouman/ef3c2516df5b3a181276d1c12a4c2236 to your computer and use it in GitHub Desktop.
Save weshouman/ef3c2516df5b3a181276d1c12a4c2236 to your computer and use it in GitHub Desktop.
Download ZIP
Gitlab Logs
Raw
gitlab_logs.md

A trip into the logs of gitlab.

Structure

To understand which file to check and when, following is the structure tree of the logs

.
├── gitlab
│   ├── api_json.log
│   ├── application.log  ----------- (Headline of the performed tasks by gitlab)
│   ├── audit_json.log
│   ├── gitlab-workhorse.log ------- (Similar to gitlab_access + completion time and requester's port)
│   ├── grpc.log
│   ├── production.log  ------------ (Headlined tasks perfromed by gitlab)
│   ├── production_json.log -------- (Detailed data sent to gitlab)
│   ├── sidekiq.log     ------------ (Detailed behavior of gitlab)
│   ├── unicorn.stderr.log
│   └── unicorn.stdout.log
├── gitlab-shell
│   ├── .
│   └── ..
├── nginx
│   ├── access.log
│   ├── error.log
│   ├── gitlab_access.log ---------- (Undetailed access requests + their codes)
│   └── gitlab_error.log
└── supervisor
    ├── cron.log
    ├── gitaly.log ----------------- (Health checks)
    ├── nginx.log
    └── sidekiq.log

Scenarios

In the following files I'll add scenario(s) that show(s) which files change and what gets logged into each

Sidekiq

One can also navigate to http://192.168.4.166:30000/admin/background_jobs to use the GUI for debugging directly by checking the failed jobs.
Follow https://mensfeld.pl/2016/05/synology-dms-6-gitlab-docker-gmail/

Raw
remove_and_add_user_scenario.md

Remove and Add User Description

In this scenario I'm already logged into gitlab with an admin account and try to remove and add a pre-existing account. Following are the lines that changed, I'm extracting the changes here. Note: that was in a session of debugging why the mail isn't being sent

gitlab/application.log

I consider this log to be a summary of the activities performed by gitlab.

  • December 07, 2019 05:21: User "NAME" (MAIL@DOMAIN.COM) was removed, yes, the extra space is there
  • December 07, 2019 05:21: User "NAME" (MAIL@DOMAIN.COM) was created

gitlab/gitlab-workhorse.log

This is very similar to the logs coming to nginx/gitlab-access.log, have some extra details as the RANDOM ADMIN PORT and the completion time.

  • GITLAB_IP:GITLAB_PORT ADMIN_IP:RAND_ADMIN_PORT1 - - [2019/12/07:05:21:16 +0000] "POST /admin/users/USERNAME?hard_delete=true HTTP/1.1" 302 104 "http://GITLAB_IP:GITLAB_PORT/admin/users/USERNAME" "BROWSER_INFO" 0.151
  • GITLAB_IP:GITLAB_PORT ADMIN_IP:RAND_ADMIN_PORT2 - - [2019/12/07:05:21:16 +0000] "GET /admin/users HTTP/1.1" 200 33838 "http://GITLAB_IP:GITLAB_PORT/admin/users/USERNAME" BROWSER_INFO 0.291
  • GITLAB_IP:GITLAB_PORT ADMIN_IP:RAND_ADMIN_PORT3 - - [2019/12/07:05:21:20 +0000] "GET /admin/users/new HTTP/1.1" 200 34367 "http://GITLAB_IP:GITLAB_PORT/admin/users" BROWSER_INFO 0.110
  • GITLAB_IP:GITLAB_PORT ADMIN_IP:RAND_ADMIN_PORT4 - - [2019/12/07:05:21:35 +0000] "POST /admin/users HTTP/1.1" 302 114 "http://GITLAB_IP:GITLAB_PORT/admin/users/new" BROWSER_INFO 0.375
  • GITLAB_IP:GITLAB_PORT ADMIN_IP:RAND_ADMIN_PORT5 - - [2019/12/07:05:21:36 +0000] "GET /admin/users/USERNAME HTTP/1.1" 200 34386 "http://GITLAB_IP:GITLAB_PORT/admin/users/new" BROWSER_INFO 0.173
Notes
  • I guess the number after the SUCCESS/ERROR code is the HTTP action ID
  • I guess the last number is the time for completion

gitlab/production.log

This file is the interesting one upon mail sending failure, I'm not sure though is that because I made an after_filter for the mailer or this info is their by default.

  • [ActiveJob] [ActionMailer::DeliveryJob] [JOB_ID] Performing ActionMailer::DeliveryJob (Job ID: JOB_ID) from Sidekiq(mailers) with arguments: "Notify", "new_user_email", "deliver_now", USER_ID, "SOME_HASH"
  • [ActiveJob] [ActionMailer::DeliveryJob] [JOB_ID] sent email: {"mailer":"Notify","action":"new_user_email","mailer_action":"Notify#new_user_email","to":"MAIL@DOMAIN.COM","from":"CONFIG_MAIL@DOMAIN.COM","subject":"Account was created for you"}
  • [ActiveJob] [ActionMailer::DeliveryJob] [JOB_ID] Sent mail to MAIL@DOMAIN.COM (60.0ms)
  • [ActiveJob] [ActionMailer::DeliveryJob] [JOB_ID] Error performing ActionMailer::DeliveryJob (Job ID: JOB_ID)
  • TRACE

gitlab/production_json.log

Here we can see the exact data sent to gitlab to do it's work, including the requester's IP and lots of specificities that could be combined with sidekiq.log to get more details through the correlation ID in example.
And I consider it detailing for the nginx/gitlab_access.log and gitlab/gitlab-workhorse.log.
The details here are very useful into understanding the context in case any issue occured.

  • {"method":"DELETE","path":"/admin/users/USERNAME","format":"html","controller":"Admin::UsersController","action":"destroy","status":302,"duration":140.41,"view":0.0,"db":88.8,"location":"http://GITLAB_IP:GITLAB_PORT/admin/users","time":"2019-12-07T05:21:16.429Z","params":[{"key":"_method","value":"delete"},{"key":"authenticity_token","value":"[FILTERED]"},{"key":"username","value":"USER"},{"key":"hard_delete","value":"true"},{"key":"id","value":"USERNAME"}],"remote_ip":"IP","user_id":ADMIN_ID,"username":"ADMIN_NAME","ua":"BROWSER_INFO","queue_duration":null,"correlation_id":"HASH"}
  • {"method":"GET","path":"/admin/users","format":"html","controller":"Admin::UsersController","action":"index","status":200,"duration":278.36,"view":214.66,"db":43.84,"time":"2019-12-07T05:21:16.591Z","params":[],"remote_ip":"IP","user_id":ADMIN_ID,"username":"ADMIN_NAME","ua":"BROWSER_INFO","queue_duration":null,"correlation_id":"HASH"}
  • {"method":"GET","path":"/admin/users/new","format":"html","controller":"Admin::UsersController","action":"new","status":200,"duration":97.13,"view":70.73,"db":5.1,"time":"2019-12-07T05:21:20.002Z","params":[],"remote_ip":"IP","user_id":ADMIN_ID,"username":"ADMIN_NAME","ua":"BROWSER_INFO","queue_duration":null,"correlation_id":"HASH"}
  • {"method":"POST","path":"/admin/users","format":"html","controller":"Admin::UsersController","action":"create","status":302,"duration":246.67,"view":0.0,"db":96.12,"location":"http://GITLAB_IP:GITLAB_PORT/admin/users/USERNAME","time":"2019-12-07T05:21:35.605Z","params":[{"key":"utf8","value":"✓"},{"key":"authenticity_token","value":"[FILTERED]"},{"key":"user","value":{"name":"USER","username":"USERNAME","email":"MAIL@DOMAIN.COM","projects_limit":"100","can_create_group":"1","access_level":"regular","external":"0","skype":"","linkedin":"","twitter":"","website_url":""}}],"remote_ip":"IP","user_id":ADMIN_ID,"username":"ADMIN_NAME","ua":"BROWSER_INFO","queue_duration":null,"correlation_id":"HASH"}
  • {"method":"GET","path":"/admin/users/USERNAME","format":"html","controller":"Admin::UsersController","action":"show","status":200,"duration":157.16,"view":113.52,"db":18.52,"time":"2019-12-07T05:21:35.881Z","params":[{"key":"id","value":"USERNAME"}],"remote_ip":"IP","user_id":ADMIN_ID,"username":"ADMIN_NAME","ua":"BROWSER_INFO","queue_duration":null,"correlation_id":"HASH"}
Notes
  • FILTERED is set by the application not me

gitlab/sidekiq.log

You'll find here the correlation ID and JOB ID used to identify the removal and addition and email tasks, with more info about queueing.
And a trace of the erros occured, which would be pretty helpful in figuring out the source issue.
The details here are very useful into debugging into the code itself.

  • 2019-12-07T05:21:16.567Z 608 TID-1u2gq0 DeleteUserWorker JID-REMOVE_USER_JOB_ID INFO: start
  • 2019-12-07T05:21:16.752Z 608 TID-1u2gq0 DeleteUserWorker JID-REMOVE_USER_JOB_ID INFO: done: 0.186 sec
  • 2019-12-07T05:21:35.846Z 608 TID-2qgcbw ActionMailer::DeliveryJob JID-MAIL_JOB_ID INFO: start
  • 2019-12-07T05:21:35.956Z 608 TID-2qgcbw ActionMailer::DeliveryJob JID-MAIL_JOB_ID INFO: fail: 0.111 sec
  • 2019-12-07T05:21:35.957Z 608 TID-2qgcbw WARN: {"context":"Job raised exception","job":{"class":"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper","wrapped":"ActionMailer::DeliveryJob","queue":"mailers","args":[{"job_class":"ActionMailer::DeliveryJob","job_id":"MAIL_JOB_ID","provider_job_id":null,"queue_name":"mailers","priority":null,"arguments":["Notify","new_user_email","deliver_now",14,"HASH_A"],"executions":0,"locale":"en"}],"retry":3,"jid":"MAIL_JOB_ID","created_at":1575696095.844197,"correlation_id":"ID","enqueued_at":1575696095.8447256},"jobstr":"{\"class\":\"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper\",\"wrapped\":\"ActionMailer::DeliveryJob\",\"queue\":\"mailers\",\"args\":[{\"job_class\":\"ActionMailer::DeliveryJob\",\"job_id\":\"MAIL_JOB_ID\",\"provider_job_id\":null,\"queue_name\":\"mailers\",\"priority\":null,\"arguments\":[\"Notify\",\"new_user_email\",\"deliver_now\",14,\"HASH_A\"],\"executions\":0,\"locale\":\"en\"}],\"retry\":3,\"jid\":\"JID\",\"created_at\":1575696095.844197,\"correlation_id\":\"ID\",\"enqueued_at\":1575696095.8447256}"}
  • 2019-12-07T05:21:35.957Z 608 TID-HASH WARN: SocketError: getaddrinfo: Name or service not known
  • 2019-12-07T05:21:35.957Z 608 TID-HASH WARN: /usr/lib/ruby/2.5.0/net/smtp.rb:539:in `initialize'
  • TRACE
  • 2019-12-07T05:22:21.160Z 608 TID-TID ActionMailer::DeliveryJob JID-MAIL_JOB_ID INFO: start
  • 2019-12-07T05:22:21.237Z 608 TID-TID ActionMailer::DeliveryJob JID-MAIL_JOB_ID INFO: fail: 0.077 sec
  • 2019-12-07T05:22:21.237Z 608 TID-TID WARN: {"context":"Job raised exception","job":{"class":"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper","wrapped":"ActionMailer::DeliveryJob","queue":"mailers","args":[{"job_class":"ActionMailer::DeliveryJob","job_id":"MAIL_JOB_ID","provider_job_id":null,"queue_name":"mailers","priority":null,"arguments":["Notify","new_user_email","deliver_now",14,"HASH_A"],"executions":0,"locale":"en"}],"retry":3,"jid":"MAIL_JOB_ID","created_at":1575696095.844197,"correlation_id":"ID","enqueued_at":1575696141.158343,"error_message":"getaddrinfo: Name or service not known","error_class":"SocketError","failed_at":1575696095.9560194,"retry_count":0},"jobstr":"{\"class\":\"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper\",\"wrapped\":\"ActionMailer::DeliveryJob\",\"queue\":\"mailers\",\"args\":[{\"job_class\":\"ActionMailer::DeliveryJob\",\"job_id\":\"MAIL_JOB_ID\",\"provider_job_id\":null,\"queue_name\":\"mailers\",\"priority\":null,\"arguments\":[\"Notify\",\"new_user_email\",\"deliver_now\",14,\"HASH_A\"],\"executions\":0,\"locale\":\"en\"}],\"retry\":3,\"jid\":\"JID\",\"created_at\":1575696095.844197,\"correlation_id\":\"ID\",\"enqueued_at\":1575696141.158343,\"error_message\":\"getaddrinfo: Name or service not known\",\"error_class\":\"SocketError\",\"failed_at\":1575696095.9560194,\"retry_count\":0}"}
  • 2019-12-07T05:22:21.237Z 608 TID-TID WARN: SocketError: getaddrinfo: Name or service not known
  • 2019-12-07T05:22:21.237Z 608 TID-TID WARN: /usr/lib/ruby/2.5.0/net/smtp.rb:539:in `initialize'
  • ...

nginx/gitlab_access.log

Here we can see the requests made, the ip of the request maker, the browser info and the RESPONSE code

  • ADMIN_IP - - [07/Dec/2019:05:21:16 +0000] "POST /admin/users/USERNAME?hard_delete=true HTTP/1.1" 302 104 "http://GITLAB_IP:GITLAB_PORT/admin/users/USERNAME" "BROWSER_INFO"
  • ADMIN_IP - - [07/Dec/2019:05:21:16 +0000] "GET /admin/users HTTP/1.1" 200 33912 "http://GITLAB_IP:GITLAB_PORT/admin/users/USERNAME" "BROWSER_INFO"
  • ADMIN_IP - - [07/Dec/2019:05:21:20 +0000] "GET /admin/users/new HTTP/1.1" 200 34441 "http://GITLAB_IP:GITLAB_PORT/admin/users" "BROWSER_INFO"
  • ADMIN_IP - - [07/Dec/2019:05:21:35 +0000] "POST /admin/users HTTP/1.1" 302 114 "http://GITLAB_IP:GITLAB_PORT/admin/users/new" "BROWSER_INFO"
  • ADMIN_IP - - [07/Dec/2019:05:21:36 +0000] "GET /admin/users/USERNAME HTTP/1.1" 200 34468 "http://GITLAB_IP:GITLAB_PORT/admin/users/new" "BROWSER_INFO"

Conclusions

The logs inside gitlab dir is more related to gitlab and the other logs are more into the interface, even though both cover the interfacing to gitlab but the ones inside gitlab directory are more specific.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment