Logging: Best practices

Do structured logging:

Because parsing stuctured logs are easier.
👍

{"level": "info", "timestamp": "2018-07-02T09:16:34.905626Z", "ram": {"avail": 30018531328.0, "usage_percent": 8.9, "avail_percent": 0.0, "usage": 2173394944.0, "total": 32944848896.0, "free": 24082784256.0}, "event": "system_metrics", "swap": {"usage": 0.0, "total": 0.0, "free_percent": 0.0, "free": 0.0, "usage_percent": 0.0}, "network_traffic": {"lo": {"received": 0.0, "sent": 0.0}, "eth0": {"received": 1758.0, "sent": 0.0}}, "id": "20180702T091634_9dd2f8ce7dd811e89cc40242ac110002", "disk": {"usage": 11787993088.0, "total": 241924943872.0, "free_percent": 0.0, "usage_percent": 5.1, "free": 220261687296.0}, "type": "metric", "cpu": {"avg_load_5_min": 5.875, "avg_load_15_min": 0.46, "idle_percent": 94.25, "iowait": 9170.39, "avg_load_1_min": 5.875, "usage_percent": 5.75}, "_": {"ln": 122, "file": "/usr/local/lib/python2.7/dist-packages/serverstats/serverstats.py", "name": "serverstats.serverstats", "fn": "_log_system_metrics"}}

👎

2016-04-05 22:12:32,984 [Thread-1    ] [DEBUG] [djangoproject.logger]  This is a manually logged DEBUG string.

Follow the convension of variable names in naming events in logs also be precise with the naming.

Naming events with spaces may result in more readablity but there is difficulty in filtering, storage in Storage-engines as some databases do not support storing key names with spaces.

👍

log.info("inserting_records", num_records=length(r))

👎

log.info("%s records into database", %(length(r)))

Do not write unnecesary logs especially in info mode

Writing too many logs put a lot of load on the collection pipeline, Storage also becomes an issue.

👍

log.debug("starting_function", fn=fn.__name__)

👎

log.info("starting_function")

Identify the requirement for writing metrics

Some databases/storages like influxDB work out-of-the-box for metrics, so it is useful to tag the metrics in the logs beforehand so that we can direct them to these storages with ease.

👍

log.info("inserting_records", "type"="metric", num_records=length(r), time_to_push=t)

👎

log.info("inserting_records", num_records=length(r), time_to_push=t)

Use '_' and '__' especially when logging metrics for fields that are supposed to be not indexed and supposed to be private respectively

Indexing a lot of variable stings like ids may decrease performance of databases

👍

log.info("requesting_api", "type"="metric", _request_id=id, __response=res, time_taken=t)

log.info("requesting_api", "type"="metric", request_id=id, response=res, time_taken=t)

Refer to link for more information