Add detailed logs of each Redis instance usage (!34110) · Merge requests · GitLab.org / GitLab

What does this MR do?

It introduces detailed logs of each Redis instance usage.

Before this change, we used to have just the following Redis logs for API, Sidekiq and Web requests:

redis_calls
redis_duration_s
redis_read_bytes
redis_write_bytes

Here we introduce the following (when usage is > 0):

redis_action_cable_calls
redis_action_cable_duration_s
redis_action_cable_read_bytes
redis_action_cable_write_bytes
redis_cache_calls
redis_cache_duration_s
redis_cache_read_bytes
redis_cache_write_bytes
redis_queues_calls
redis_queues_duration_s
redis_queues_read_bytes
redis_queues_write_bytes
redis_shared_state_calls
redis_shared_state_duration_s
redis_shared_state_read_bytes
redis_shared_state_write_bytes

That's valuable information about how GitLab use Redis instances.

Examples

Sidekiq job execution

{  "severity":"INFO",
   "time":"2020-06-10T23:12:18.744Z",
   "queue":"cronjob:update_all_mirrors",
   "args":[
],
   "class":"UpdateAllMirrorsWorker",
   "retry":0,
   "backtrace":true,
   "queue_namespace":"cronjob",
   "jid":"3052e97eb8ef26ec0fb795cd",
   "created_at":"2020-06-10T23:12:17.474Z",
   "meta.caller_id":"Cronjob",
   "correlation_id":"e74b264e5e254df7d7556ee0b86dc1bc",
   "uber-trace-id":"1c8f80ebff271fca:1c8f80ebff271fca:0:1",
   "enqueued_at":"2020-06-10T23:12:17.659Z",
   "pid":96447,
   "message":"UpdateAllMirrorsWorker JID-3052e97eb8ef26ec0fb795cd: done: 1.083595 sec",
   "job_status":"done",
   "scheduling_latency_s":0.001548,
   "redis_calls":6,
   "redis_duration_s":0.013662,
   "redis_read_bytes":123,
   "redis_write_bytes":543,
   "redis_cache_calls":1,
   "redis_cache_duration_s":0.001294,
   "redis_cache_read_bytes":118,
   "redis_cache_write_bytes":51,
   "redis_queues_calls":2,
   "redis_queues_duration_s":0.004314,
   "redis_queues_read_bytes":2,
   "redis_queues_write_bytes":195,
   "redis_shared_state_calls":3,
   "redis_shared_state_duration_s":0.008054,
   "redis_shared_state_read_bytes":3,
   "redis_shared_state_write_bytes":297,
   "db_count":19,
   "db_write_count":0,
   "db_cached_count":0,
   "duration_s":1.083595,
   "cpu_s":0.429214,
   "completed_at":"2020-06-10T23:12:18.744Z",
   "db_duration_s":0.075797
}

Rails requests

{  "method":"GET",
   "path":"/",
   "format":"html",
   "controller":"RootController",
   "action":"index",
   "status":200,
   "time":"2020-06-10T23:17:01.104Z",
   "params":[],
   "remote_ip":"127.0.0.1",
   "user_id":1,
   "username":"root",
   "ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10.14; rv:77.0) Gecko/20100101 Firefox/77.0",
   "db_count":37,
   "db_write_count":0,
   "db_cached_count":0,
   "correlation_id":"CmYGQLTM3Y8",
   "meta.user":"root",
   "meta.caller_id":"RootController#index",
   "gitaly_calls":16,
   "gitaly_duration_s":0.128101,
   "redis_calls":111,
   "redis_duration_s":0.122335,
   "redis_read_bytes":11518,
   "redis_write_bytes":452303,
   "redis_cache_calls":109,
   "redis_cache_duration_s":0.121491,
   "redis_cache_read_bytes":11337,
   "redis_cache_write_bytes":451709,
   "redis_shared_state_calls":2,
   "redis_shared_state_duration_s":0.000844,
   "redis_shared_state_read_bytes":181,
   "redis_shared_state_write_bytes":594,
   "queue_duration_s":0.146951,
   "cpu_s":2.46,
   "db_duration_s":0.06425,
   "view_duration_s":2.11956,
   "duration_s":2.73541
}

API (grape) requests

{
   "time":"2020-06-10T23:18:50.111Z",
   "severity":"INFO",
   "duration_s":0.06137,
   "db_duration_s":0.00596,
   "view_duration_s":0.05541,
   "status":200,
   "method":"GET",
   "path":"/api/v4/users",
   "params":[],
   "host":"localhost",
   "remote_ip":"127.0.0.1",
   "ua":"PostmanRuntime/7.6.0",
   "route":"/api/:version/users",
   "user_id":46,
   "username":"asdf",
   "queue_duration_s":0.17117,
   "redis_calls":1,
   "redis_duration_s":0.000723,
   "redis_write_bytes":49,
   "redis_shared_state_calls":1,
   "redis_shared_state_duration_s":0.000723,
   "redis_shared_state_write_bytes":49,
   "correlation_id":"B6ECRePaqX1",
   "meta.user":"asdf",
   "meta.caller_id":"/api/:version/users"
}

gitlab-com/gl-infra/scalability#313 (closed)

Screenshots

Does this MR meet the acceptance criteria?

Conformity

Availability and Testing

Review and add/update tests for this feature/bug. Consider all test levels. See the Test Planning Process.
Tested in all supported browsers
Informed Infrastructure department of a default or new setting change, if applicable per definition of done

Security

If this MR contains changes to processing or storing of credentials or tokens, authorization and authentication methods and other items described in the security review guidelines:

Label as security and @ mention @gitlab-com/gl-security/appsec
The MR includes necessary changes to maintain consistency between UI, API, email, or other methods
Security reports checked/validated by a reviewer from the AppSec team

Add detailed logs of each Redis instance usage