Skip to content

Consider defaulting Sidekiq logger to JSON

Summary

The current Sidekiq chart configures its logger to use the default format which isn't very verbose. This slows down troubleshooting investigations (in GitLab Support) where looking at enriched fields such as .db_duration_s or .scheduling_latency_s becomes necessary.

On Omnibus the Sidekiq service logs to JSON format with INFO levels by default - I think the chart equivalent should do the same.

Steps to reproduce

Check Sidekiq pod logs of any GitLab Charts Helm install running with defaults for gitlab.sidekiq.* configs.

Configuration used

The documentation at https://docs.gitlab.com/charts/charts/gitlab/sidekiq/index.html notes that logging format of Sidekiq must be explicitly set to json if its desired, and that the default is default (which logs non-JSON simple forms such as this:)

2021-01-11T11:11:11.111Z 11 TID-abcd ProjectServiceWorker JID-abcd INFO: done: 0.001 sec

Current behavior

Default logging format of the Sidekiq pod does not use JSON, and carries no performance information.

Expected behavior

Default logging format of the Sidekiq pod uses JSON, and carries performance information.

Versions

  • Chart: N/A (all releases are affected, latest as of issue filing is 5.2.3)
  • Platform: N/A (applies to all platforms)
  • Kubernetes: N/A (issue is with chart config not k8s)
  • Helm: N/A (issue is with chart defaults not helm)

Relevant logs

For Sidekiq, the difference in logging format appears like this (examples):

Basic format:

2021-01-11T11:11:11.111Z 11 TID-abcd ProjectServiceWorker JID-abcd INFO: done: 0.001 sec

JSON format:

{
    "severity": "INFO",
    "time": "2021-11-11T11:11:11.111Z",
    "class": "ProjectServiceWorker",
    "args": [
        "1111",
        "[FILTERED]"
    ],
    "retry": 3,
    "queue": "project_service",
    "version": 0,
    "dead": false,
    "jid": "abcd",
    "created_at": "2021-11-11T11:11:11.111Z",
    "meta.user": "jdoe",
    "meta.project": "main/main",
    "meta.root_namespace": "main",
    "meta.caller_id": "MergeWorker",
    "meta.remote_ip": "11.11.11.11",
    "meta.feature_category": "source_code_management",
    "meta.client_id": "user/11",
    "correlation_id": "abcd",
    "enqueued_at": "2021-11-11T11:11:11.111Z",
    "pid": 1234,
    "message": "ProjectServiceWorker JID-abcd: done: 0.1 sec",
    "job_status": "done",
    "scheduling_latency_s": 1.1234,
    "job_size_bytes": 1234,
    "cpu_s": 0.01234,
    "mem_objects": 1234,
    "mem_bytes": 1234,
    "mem_mallocs": 1234,
    "redis_calls": 1234,
    "redis_duration_s": 0.01234,
    "redis_read_bytes": 1234,
    "redis_write_bytes": 1234,
    "redis_queues_calls": 1234,
    "redis_queues_duration_s": 0.01234,
    "redis_queues_read_bytes": 1234,
    "redis_queues_write_bytes": 1234,
    "db_count": 1234,
    "db_write_count": 0,
    "db_cached_count": 0,
    "duration_s": 0.01234,
    "completed_at": "2021-11-11T11:11:11.111Z",
    "db_duration_s": 0.01234
}