Log field management for action and entity
Summary
In our rails logs, I see two items that could be compressed into one. Example, json.remove
will tell me what it removes. In one example this will be populated with project
. However, we have that same data in json.entity_type
, which reports Project
. So this is duplicated slightly, the difference being that we are performing a remove action. However, in other parts of our code base, we populate a field called json.action
, and in the example I'm looking at, it's reporting a value of show
. (These are completely unrelated log lines).
Example log lines:
with `json.action` populated
@timestamp: Jul 13, 2020 @ 11:53:54.872
_id: CjEGSHMBLT6_KDgjQAed
_index: pubsub-rails-inf-gstg-000117
_score: -
_type: _doc
ecs.version: 1.4.0
host.name: pubsub-rails-inf-gstg
json.action: show
json.cf_ray: 5b22ccef1e07c619-KHI
json.cf_request_id: 03e99e696a0000c6193298f200000001
json.controller: Projects::ImportsController
json.correlation_id: N6kiIukWjm7
json.cpu_s: 0.18
json.db_cached_count: 0
json.db_count: 30
json.db_duration_s: 0.032
json.db_write_count: 0
json.duration_s: 0.171
json.environment: gstg
json.extra.created_at:
json.format: html
json.fqdn: web-02-sv-gstg.c.gitlab-staging-1.internal
json.gitaly_calls: 1
json.gitaly_duration_s: 0.018
json.hostname: web-02-sv-gstg
json.meta.caller_id: Projects::ImportsController#show
json.meta.project: gitlab-qa-sandbox-group/qa-test-2020-07-13-16-36-53-57aa29437da0099d/project-using-instance-level-project-template-5580381d121e158a
json.meta.root_namespace: gitlab-qa-sandbox-group
json.meta.user: gitlab-qa-bot
json.method: GET
json.params:
{
"key": "namespace_id",
"value": "gitlab-qa-sandbox-group/qa-test-2020-07-13-16-36-53-57aa29437da0099d"
},
{
"key": "project_id",
"value": "project-using-instance-level-project-template-5580381d121e158a"
}
json.path: /gitlab-qa-sandbox-group/qa-test-2020-07-13-16-36-53-57aa29437da0099d/project-using-instance-level-project-template-5580381d121e158a/-/import
json.queue_duration_s: 0.016
json.redis_cache_calls: 44
json.redis_cache_duration_s: 0.011201
json.redis_cache_read_bytes: 9428
json.redis_cache_write_bytes: 2911
json.redis_calls: 46
json.redis_duration_s: 0.012
json.redis_read_bytes: 9612
json.redis_shared_state_calls: 2
json.redis_shared_state_duration_s: 0.000586
json.redis_shared_state_read_bytes: 184
json.redis_shared_state_write_bytes: 650
json.redis_write_bytes: 3561
json.remote_ip: 202.47.48.94
json.shard: default
json.stage: main
json.status: 200
json.tag: rails.production
json.tier: sv
json.time: Jul 13, 2020 @ 11:52:55.720
json.type: web
json.ua: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/83.0.4103.116 Safari/537.36
json.user_id: 1,675,733
json.username: gitlab-qa-bot
json.view_duration_s: 0.096
message_id: 1314557476231890
publish_time: Jul 13, 2020 @ 11:53:54.830
type: pubsub-rails-inf-gstg
with `json.remove` populated
@timestamp: Jul 14, 2020 @ 21:35:04.486
_id: arxAT3MBLT6_KDgjrd8m
_index: pubsub-rails-inf-gstg-000117
_score: -
_type: _doc
ecs.version: 1.4.0
host.name: pubsubbeat-pubsub-rails-inf-gstg-648c797bbb-pl68r
json.author_id: 1,614,863
json.author_name: QA User (Quality Team's Test Account)
json.correlation_id: 2f4a9a8294b415ee9a8bc7c0ef2a8466
json.entity_id: 4,733,218
json.entity_path: gitlab-qa-sandbox-group/qa-test-2020-07-13-16-36-53-57aa29437da0099d/project-using-instance-level-project-template-5580381d121e158a
json.entity_type: Project
json.environment: gstg
json.extra.created_at
json.fqdn: sidekiq-catchall-01-sv-gstg.c.gitlab-staging-1.internal
json.hostname: sidekiq-catchall-01-sv-gstg
json.ip_address: 35.243.143.82
json.remove: project
json.severity: INFO
json.shard: catchall
json.stage: main
json.tag: rails.audit
json.target_details: gitlab-qa-sandbox-group/qa-test-2020-07-13-16-36-53-57aa29437da0099d/project-using-instance-level-project-template-5580381d121e158a
json.target_id: gitlab-qa-sandbox-group/qa-test-2020-07-13-16-36-53-57aa29437da0099d/project-using-instance-level-project-template-5580381d121e158a
json.target_type: Project
json.tier: sv
json.time: Jul 14, 2020 @ 21:35:04.370
json.type: sidekiq
message_id: 1319483844166795
publish_time: Jul 14, 2020 @ 21:35:04.467
type: pubsubbeat-pubsub-rails-inf-gstg-648c797bbb-pl68r
Improvements
I'd like to suggest that we drop json.remove
in favor of using this as the json.action
. With json.action
more simplified, this reduces the amount of data stored in our logging system and allows for better searching and filtering on fields that are more consistent.
With this proposal, we land with only 2 objects instead of three:
+json.action: remove
json.entity: Project
-json.remove: project
json.action: show
# no entity in this log detail for X reason
Risks
Involved components
This may involve touching various places in the rails code base to ensure that all locations meet said requirement. Note that the log data from above both come from rails, but two distinct portions of code. A sidekiq worker vs a web request.