[python] logging: đừng format log message!

Xem đoạn code sau:

In [7]: import logging

In [8]: logging.basicConfig()

In [9]: log = logging.getLogger('familug')

In [10]: log.error('%s: %d', 'meo', 10)
ERROR:familug:meo: 10

In [11]: log.error('%s: %d' % ('meo', 10))
ERROR:familug:meo: 10

Bạn có thể giải thích xem câu lệnh log ở [10] hay [11] tốt hơn?

Nếu câu trả lời là [11] hoặc như nhau thì bạn nên đọc tiếp...

• ở [10], các argument được pass vào log.error  sẽ được logging module dùng để format theo format string '%s: %d'.
• ở [11], format '%s: %d' rồi mới pass cho log.error.

trong doc của logging module đã viết, msg là message format string chứ không phải là message string.

https://docs.python.org/2/library/logging.html#logging.Logger.debug

Logger.debug(msg, *args, **kwargs)

Logs a message with level DEBUG on this logger. The msg is the message format string, and the args are the arguments which are merged into msg using the string formatting operator.

Nếu format string trước khi log, bạn làm sai 2 việc:
1. format thừa một lần, vì logging module sẽ làm việc đó => ảnh hưởng đến performance.

In [16]: %timeit(log.debug('%s: %d', 'meo', 10))
1000000 loops, best of 3: 1.62 us per loop

In [17]: %timeit(log.debug('%s: %d' % ('meo', 10)))
100000 loops, best of 3: 2.52 us per loop 

2. không tận dụng được tính năng log aggregation, tức nếu để logging module thực hiện việc format, nó có thể phân loại các log theo message format string (các log có cùng format string nhưng khác argument sẽ được gộp chung) . Trong khi nếu format trước, mỗi log sẽ được xem là một loại riêng. Nếu đã từng sử dụng Sentry, bạn sẽ thấy điều này hữu ích thế nào.

Vậy nên đừng bao giờ format log!