게으른 로거 메시지 문자열 평가

게으른 로거 메시지 문자열 평가

---

내 파이썬 응용 프로그램에서 표준 파이썬 로깅 모듈을 사용하고 있습니다.

가져 오기 로깅
logging.basicConfig (level = logging.INFO)
로거 = logging.getLogger ( "log")
True 동안 :
  logger.debug ( 'Stupid log message "+' '.join ([str (i) for i in range (20)]))
  # 뭔가 해

문제는 디버그 수준이 활성화되어 있지 않지만 해당 어리석은 로그 메시지가 각 루프 반복에서 평가되어 성능에 나쁜 영향을 미친다는 것입니다.

이에 대한 해결책이 있습니까?

C ++에서 우리가 log4cxx다음과 같이 매크로를 제공 패키지 :
LOG4CXX_DEBUG(logger, messasage)
그건 효율적으로 평가

if (log4cxx :: debugEnabled (logger)) {
    log4cxx.log (logger, log4cxx :: LOG4CXX_DEBUG, 메시지)
}

그러나 Python (AFAIK)에는 매크로가 없기 때문에 로깅을 수행하는 효율적인 방법이 있다면?

---

로깅 모듈은 이미 수행하려는 작업을 부분적으로 지원합니다. 이 작업을 수행:

log.debug("Some message: a=%s b=%s", a, b)

... 대신 :

log.debug("Some message: a=%s b=%s" % (a, b))

로깅 모듈은 메시지가 실제로 어딘가에 기록되지 않는 한 완전한 로그 메시지를 생성하지 않을만큼 똑똑합니다.

이 기능을 특정 요청에 적용하려면 lazyjoin 클래스를 만들 수 있습니다.

class lazyjoin:
    def __init__(self, s, items):
        self.s = s
        self.items = items
    def __str__(self):
        return self.s.join(self.items)

다음과 같이 사용하십시오 (게으름에 추가하는 생성기 표현식 사용에 유의하십시오).

logger.info('Stupid log message %s', lazyjoin(' ', (str(i) for i in range(20))))

이것이 작동하는 것을 보여주는 데모입니다.

>>> import logging
>>> logging.basicConfig(level=logging.INFO)
>>> logger = logging.getLogger("log")
>>> class DoNotStr:
...     def __str__(self):
...         raise AssertionError("the code should not have called this")
... 
>>> logger.info('Message %s', DoNotStr())
Traceback (most recent call last):
...
AssertionError: the code should not have called this
>>> logger.debug('Message %s', DoNotStr())
>>>

데모에서 logger.info () 호출은 어설 션 오류에 부딪 혔지만 logger.debug ()는 그렇게 멀리하지 않았습니다.

---

물론 다음은 매크로만큼 효율적이지 않습니다.

if logger.isEnabledFor(logging.DEBUG):
    logger.debug(
        'Stupid log message ' + ' '.join([str(i) for i in range(20)])
    )

하지만 단순, 게으른 방식으로 평가 하고있다 4 배 빠른 허용 대답보다 더 :

class lazyjoin:
    def __init__(self, s, items):
        self.s = s
        self.items = items

    def __str__(self):
        return self.s.join(self.items)

logger.debug(
    'Stupid log message %s', lazyjoin(' ', (str(i) for i in range(20)))
)

내 설정 은 benchmark-src 를 참조하십시오 .

---

import logging
import time

logging.basicConfig(level=logging.INFO)
logger = logging.getLogger("log")

class Lazy(object):
    def __init__(self,func):
        self.func=func
    def __str__(self):
        return self.func()

logger.debug(Lazy(lambda: time.sleep(20)))

logger.info(Lazy(lambda: "Stupid log message " + ' '.join([str(i) for i in range(20)])))
# INFO:log:Stupid log message 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19

If you run the script, you'll notice the first logger.debug command does not take 20 seconds to execute. This shows the argument is not evaluated when the logging level is below the set level.

---

As Shane points out, using

log.debug("Some message: a=%s b=%s", a, b)

... instead of this:

log.debug("Some message: a=%s b=%s" % (a, b))

saves some time by only performing the string formatting if the message is actually logged.

This does not completely solve the problem, though, as you may have to pre-process the values to format into the string, such as:

log.debug("Some message: a=%s b=%s", foo.get_a(), foo.get_b())

In that case, obj.get_a() and obj.get_b() will be computed even if no logging happens.

A solution to that would be to use lambda functions, but this requires some extra machinery:

class lazy_log_debug(object):
    def __init__(self, func):
        self.func = func
        logging.debug("%s", self)
    def __str__(self):
        return self.func()

... then you can log with the following:

lazy_log_debug(lambda: "Some message: a=%s b=%s" % (foo.get_a(), foo.get_b()))

In that case, the lambda function will only be called if log.debug decides to perform the formatting, hence calling the __str__ method.

Mind you: the overhead of that solution may very well exceed the benefit :-) But at least in theory, it makes it possible to do perfectly lazy logging.

---

I present, Lazyfy:

class Lazyfy(object):
    __slots__ = 'action', 'value'

    def __init__(self, action, *value):
        self.action = action
        self.value = value

    def __str__(self):
        return self.action(*self.value)

Usage:

from pprint import pformat
log.debug("big_result: %s", Lazyfy(pformat, big_result))
log.debug( "x y z: %s", Lazyfy( lambda x, y, z: ' ,'.join( [x, y, z] ), '1', '2', '3' ) )

The original example:

logger.info('Stupid log message %s', Lazyfy(lambda: ' '.join((str(i) for i in range(20)))))

As you see, this also covers the other answer which uses lambda function, but uses more memory with the value atribute and expansion. However, it saves more memory with: Usage of __slots__?

Finally, by far, the most efficient solution still being the following as suggested another answer:

if logger.isEnabledFor(logging.DEBUG): 
    logger.debug('Stupid log message ' + ' '.join([str(i) for i in range(20)]))

---

If you depend only on accessing global state attributes, you can instantiate a python class and lazify it by using the __str__ method:

class get_lazy_debug(object):
    def __repr__(self):
        return ' '.join(
                str(i) for i in range(20)
            )

# Allows to pass get_lazy_debug as a function parameter without 
# evaluating/creating its string!
get_lazy_debug = get_lazy_debug()

logger.debug( 'Stupid log message', get_lazy_debug )

Related:

1. Conditionally evaluated debug statements in Python
2. What are metaclasses in Python?

참고URL : https://stackoverflow.com/questions/4148790/lazy-logger-message-string-evaluation