Лог ошибок python

I am printing Python exception messages to a log file with logging.error:

import logging
try:
    1/0
except ZeroDivisionError as e:
    logging.error(e)  # ERROR:root:division by zero

Is it possible to print more detailed information about the exception and the code that generated it than just the exception string? Things like line numbers or stack traces would be great.

vvvvv

24k19 gold badges48 silver badges76 bronze badges

asked Mar 4, 2011 at 9:21

logger.exception will output a stack trace alongside the error message.

For example:

import logging
try:
    1/0
except ZeroDivisionError:
    logging.exception("message")

Output:

ERROR:root:message
Traceback (most recent call last):
  File "<stdin>", line 2, in <module>
ZeroDivisionError: integer division or modulo by zero

@Paulo Cheque notes, «be aware that in Python 3 you must call the logging.exception method just inside the except part. If you call this method in an arbitrary place you may get a bizarre exception. The docs alert about that.»

GG.

20.8k13 gold badges82 silver badges130 bronze badges

answered Mar 4, 2011 at 9:25

Using exc_info options may be better, to allow you to choose the error level (if you use exception, it will always be at the error level):

try:
    # do something here
except Exception as e:
    logging.critical(e, exc_info=True)  # log exception info at CRITICAL log level

ti7

15.7k6 gold badges39 silver badges67 bronze badges

answered Apr 10, 2015 at 8:01

flyceeflycee

11.8k3 gold badges19 silver badges14 bronze badges

One nice thing about logging.exception that SiggyF’s answer doesn’t show is that you can pass in an arbitrary message, and logging will still show the full traceback with all the exception details:

import logging
try:
    1/0
except ZeroDivisionError:
    logging.exception("Deliberate divide by zero traceback")

With the default (in recent versions) logging behaviour of just printing errors to sys.stderr, it looks like this:

>>> import logging
>>> try:
...     1/0
... except ZeroDivisionError:
...     logging.exception("Deliberate divide by zero traceback")
... 
ERROR:root:Deliberate divide by zero traceback
Traceback (most recent call last):
  File "<stdin>", line 2, in <module>
ZeroDivisionError: integer division or modulo by zero

Stevoisiak

23.2k27 gold badges120 silver badges222 bronze badges

answered Jul 1, 2013 at 4:34

ncoghlanncoghlan

39.8k10 gold badges71 silver badges79 bronze badges

Quoting

What if your application does logging some other way – not using the logging module?

Now, traceback could be used here.

import traceback

def log_traceback(ex, ex_traceback=None):
    if ex_traceback is None:
        ex_traceback = ex.__traceback__
    tb_lines = [ line.rstrip('n') for line in
                 traceback.format_exception(ex.__class__, ex, ex_traceback)]
    exception_logger.log(tb_lines)

Use it in Python 2:

try:
    # your function call is here
except Exception as ex:
    _, _, ex_traceback = sys.exc_info()
    log_traceback(ex, ex_traceback)

Use it in Python 3:

try:
    x = get_number()
except Exception as ex:
    log_traceback(ex)

answered Oct 19, 2015 at 10:21

zangwzangw

42.8k19 gold badges172 silver badges207 bronze badges

You can log the stack trace without an exception.

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

The second optional keyword argument is stack_info, which defaults to False. If true, stack information is added to the logging message, including the actual logging call. Note that this is not the same stack information as that displayed through specifying exc_info: The former is stack frames from the bottom of the stack up to the logging call in the current thread, whereas the latter is information about stack frames which have been unwound, following an exception, while searching for exception handlers.

Example:

>>> import logging
>>> logging.basicConfig(level=logging.DEBUG)
>>> logging.getLogger().info('This prints the stack', stack_info=True)
INFO:root:This prints the stack
Stack (most recent call last):
  File "<stdin>", line 1, in <module>
>>>

answered Dec 3, 2019 at 10:01

BaczekBaczek

1,1691 gold badge13 silver badges23 bronze badges

If you use plain logs — all your log records should correspond this rule: one record = one line. Following this rule you can use grep and other tools to process your log files.

But traceback information is multi-line. So my answer is an extended version of solution proposed by zangw above in this thread. The problem is that traceback lines could have n inside, so we need to do an extra work to get rid of this line endings:

import logging


logger = logging.getLogger('your_logger_here')

def log_app_error(e: BaseException, level=logging.ERROR) -> None:
    e_traceback = traceback.format_exception(e.__class__, e, e.__traceback__)
    traceback_lines = []
    for line in [line.rstrip('n') for line in e_traceback]:
        traceback_lines.extend(line.splitlines())
    logger.log(level, traceback_lines.__str__())

After that (when you’ll be analyzing your logs) you could copy / paste required traceback lines from your log file and do this:

ex_traceback = ['line 1', 'line 2', ...]
for line in ex_traceback:
    print(line)

Profit!

answered Nov 4, 2016 at 17:32

doomateldoomatel

5971 gold badge5 silver badges8 bronze badges

This answer builds up from the above excellent ones.

In most applications, you won’t be calling logging.exception(e) directly. Most likely you have defined a custom logger specific for your application or module like this:

# Set the name of the app or module
my_logger = logging.getLogger('NEM Sequencer')
# Set the log level
my_logger.setLevel(logging.INFO)

# Let's say we want to be fancy and log to a graylog2 log server
graylog_handler = graypy.GELFHandler('some_server_ip', 12201)
graylog_handler.setLevel(logging.INFO)
my_logger.addHandler(graylog_handler)

In this case, just use the logger to call the exception(e) like this:

try:
    1/0
except ZeroDivisionError, e:
    my_logger.exception(e)

Stevoisiak

23.2k27 gold badges120 silver badges222 bronze badges

answered Apr 16, 2015 at 13:38

WillWill

1,96920 silver badges19 bronze badges

If «debugging information» means the values present when exception was raised, then logging.exception(...) won’t help. So you’ll need a tool that logs all variable values along with the traceback lines automatically.

Out of the box you’ll get log like

2020-03-30 18:24:31 main ERROR   File "./temp.py", line 13, in get_ratio
2020-03-30 18:24:31 main ERROR     return height / width
2020-03-30 18:24:31 main ERROR       height = 300
2020-03-30 18:24:31 main ERROR       width = 0
2020-03-30 18:24:31 main ERROR builtins.ZeroDivisionError: division by zero

Have a look at some pypi tools, I’d name:

tbvaccine
traceback-with-variables
better-exceptions

Some of them give you pretty crash messages:

But you might find some more on pypi

answered Nov 4, 2020 at 22:22

A little bit of decorator treatment (very loosely inspired by the Maybe monad and lifting). You can safely remove Python 3.6 type annotations and use an older message formatting style.

fallible.py

from functools import wraps
from typing import Callable, TypeVar, Optional
import logging


A = TypeVar('A')


def fallible(*exceptions, logger=None) 
        -> Callable[[Callable[..., A]], Callable[..., Optional[A]]]:
    """
    :param exceptions: a list of exceptions to catch
    :param logger: pass a custom logger; None means the default logger, 
                   False disables logging altogether.
    """
    def fwrap(f: Callable[..., A]) -> Callable[..., Optional[A]]:

        @wraps(f)
        def wrapped(*args, **kwargs):
            try:
                return f(*args, **kwargs)
            except exceptions:
                message = f'called {f} with *args={args} and **kwargs={kwargs}'
                if logger:
                    logger.exception(message)
                if logger is None:
                    logging.exception(message)
                return None

        return wrapped

    return fwrap

Demo:

In [1] from fallible import fallible

In [2]: @fallible(ArithmeticError)
    ...: def div(a, b):
    ...:     return a / b
    ...: 
    ...: 

In [3]: div(1, 2)
Out[3]: 0.5

In [4]: res = div(1, 0)
ERROR:root:called <function div at 0x10d3c6ae8> with *args=(1, 0) and **kwargs={}
Traceback (most recent call last):
  File "/Users/user/fallible.py", line 17, in wrapped
    return f(*args, **kwargs)
  File "<ipython-input-17-e056bd886b5c>", line 3, in div
    return a / b

In [5]: repr(res)
'None'

You can also modify this solution to return something a bit more meaningful than None from the except part (or even make the solution generic, by specifying this return value in fallible‘s arguments).

answered Jul 12, 2018 at 16:55

Eli KorvigoEli Korvigo

10.2k6 gold badges46 silver badges73 bronze badges

In your logging module(if custom module) just enable stack_info.

api_logger.exceptionLog("*Input your Custom error message*",stack_info=True)

answered May 20, 2020 at 10:40

DunggeonDunggeon

921 gold badge1 silver badge11 bronze badges

If you look at the this code example (which works for Python 2 and 3) you’ll see the function definition below which can extract

method
line number
code context
file path

for an entire stack trace, whether or not there has been an exception:

def sentry_friendly_trace(get_last_exception=True):
    try:
        current_call = list(map(frame_trans, traceback.extract_stack()))
        alert_frame = current_call[-4]
        before_call = current_call[:-4]

        err_type, err, tb = sys.exc_info() if get_last_exception else (None, None, None)
        after_call = [alert_frame] if err_type is None else extract_all_sentry_frames_from_exception(tb)

        return before_call + after_call, err, alert_frame
    except:
        return None, None, None

Of course, this function depends on the entire gist linked above, and in particular extract_all_sentry_frames_from_exception() and frame_trans() but the exception info extraction totals less than around 60 lines.

Hope that helps!

answered Jun 28, 2020 at 3:26

I wrap all functions around my custom designed logger:

import json
import timeit
import traceback
import sys
import unidecode

def main_writer(f,argument):
  try:
    f.write(str(argument))
  except UnicodeEncodeError:
    f.write(unidecode.unidecode(argument))


def logger(*argv,logfile="log.txt",singleLine = False):
  """
  Writes Logs to LogFile
  """
  with open(logfile, 'a+') as f:
    for arg in argv:
      if arg == "{}":
        continue
      if type(arg) == dict and len(arg)!=0:
        json_object = json.dumps(arg, indent=4, default=str)
        f.write(str(json_object))
        f.flush()
        """
        for key,val in arg.items():
          f.write(str(key) + " : "+ str(val))
          f.flush()
        """
      elif type(arg) == list and len(arg)!=0:
        for each in arg:
          main_writer(f,each)
          f.write("n")
          f.flush()
      else:
        main_writer(f,arg)
        f.flush()
      if singleLine==False:
        f.write("n")
    if singleLine==True:
      f.write("n")

def tryFunc(func, func_name=None, *args, **kwargs):
  """
  Time for Successfull Runs
  Exception Traceback for Unsuccessful Runs
  """
  stack = traceback.extract_stack()
  filename, codeline, funcName, text = stack[-2]
  func_name = func.__name__ if func_name is None else func_name # sys._getframe().f_code.co_name # func.__name__
  start = timeit.default_timer()
  x = None
  try:
    x = func(*args, **kwargs)
    stop = timeit.default_timer()
    # logger("Time to Run {} : {}".format(func_name, stop - start))
  except Exception as e:
    logger("Exception Occurred for {} :".format(func_name))
    logger("Basic Error Info :",e)
    logger("Full Error TraceBack :")
    # logger(e.message, e.args)
    logger(traceback.format_exc())
  return x

def bad_func():
  return 'a'+ 7

if __name__ == '__main__':
    logger(234)
    logger([1,2,3])
    logger(['a','b','c'])
    logger({'a':7,'b':8,'c':9})
    tryFunc(bad_func)

answered Oct 13, 2021 at 9:17

My approach was to create a context manager, to log and raise Exceptions:

import logging
from contextlib import AbstractContextManager


class LogError(AbstractContextManager):

    def __init__(self, logger=None):
        self.logger = logger.name if isinstance(logger, logging.Logger) else logger

    def __exit__(self, exc_type, exc_value, traceback):
        if exc_value is not None:
            logging.getLogger(self.logger).exception(exc_value)


with LogError():
    1/0

You can either pass a logger name or a logger instance to LogError(). By default it will use the base logger (by passing None to logging.getLogger).
One could also simply add a switch for raising the error or just logging it.

answered Aug 23, 2022 at 12:01

MuellerSebMuellerSeb

7816 silver badges11 bronze badges

If you can cope with the extra dependency then use twisted.log, you don’t have to explicitly log errors and also it returns the entire traceback and time to the file or stream.

Wim Coenen

65.9k13 gold badges156 silver badges249 bronze badges

answered Mar 4, 2011 at 9:26

Jakob BowyerJakob Bowyer

33.7k8 gold badges75 silver badges91 bronze badges

A clean way to do it is using format_exc() and then parse the output to get the relevant part:

from traceback import format_exc

try:
    1/0
except Exception:
    print 'the relevant part is: '+format_exc().split('n')[-2]

Regards

Rohan

52.1k12 gold badges89 silver badges86 bronze badges

answered Feb 20, 2013 at 16:32

Источник

Python предлагает весьма сильную библиотеку логирования в стандартной библиотеке. Многие программисты используют оператор print для лечения багов (в том числе и я), но вы можете использовать логирование для этих целей. Использование лога также более чистый метод, если вы не хотите просматривать весь свой код, чтобы удалить все операторы print. В данном разделе мы рассмотрим следующее:

Создание простого логгера;
Использование нескольких модулей для логирования;
Форматирование лога;
Настройки лога

К концу данного раздела вы сможете уверенно создавать логи для своих приложений. Приступим!

Создаем простой логгер

Создание лога при помощи модуля logging это очень просто. Для начала, будет проще взглянуть на часть кода и объяснить его:

import logging

# add filemode=»w» to overwrite

logging.basicConfig(filename=«sample.log», level=logging.INFO)

logging.debug(«This is a debug message»)

logging.info(«Informational message»)

logging.error(«An error has happened!»)

Как и ожидалось, чтобы получит доступ к модулю logging, для начала нужно импортировать модуль. Простейший способ создания лога – это использовать функцию basicConfig модуля logging и передать ей несколько ключевых аргументов. Функция принимает следующее: filename, filemode, format, datefmt, level и stream. В нашем примере, мы передадим её названию файла и уровню логирования, что мы и настроим в INFO.

Существует пять уровней логирования (в порядке возрастания): DEBUG, INFO, WARNING, ERROR и CRITICAL. По умолчанию, если вы запустите этот код несколько раз, он добавится в лог, если он существует. Если вы хотите, чтобы ваш логгер перезаписывал лог, передайте его filemode=”w”, как было указано в комментарии к коду. Говоря о запуске кода, вы должны получить следующий результат, после запуска:

INFO:root:Informational message

ERROR:root:An error has happened!

Обратите внимание на то, что сообщение о дебаггинге находится не на выходе. Это связанно с тем, что мы установили уровень в INFO, так что наш логгер будет записывать только сообщения INFO, WARNING, ERROR или CRITICAL. Часть root означает, что данное сообщение пришло либо от корневого логгера, либо от основного. Мы взглянем на то, как это можно изменить, что бы следующая часть была более понятной. Если вы не используете basicConfig, тогда модуль протоколирования выведет на консоль / stdout. Модуль logging также может учитывать некоторые исключения в файле, или там, где вы указали. Взглянем на пример:

import logging

logging.basicConfig(filename=«sample.log», level=logging.INFO)

log = logging.getLogger(«ex»)

try:

raise RuntimeError

except RuntimeError:

log.exception(«Error!»)

Давайте немного притормозим. Здесь мы использовали метод getLogger модуля logging, чтобы вернуть объект логгера под названием ex. Это удобно, если у вас есть несколько логгеров в одном приложении, так как это позволяет вам узнать, какие сообщения приходят с каждого логгера. Этот пример провоцирует возникновение ошибки RuntimeError, затем это регистрируется в файле, что может быть очень удобно при лечении багов.

Есть вопросы по Python?

На нашем форуме вы можете задать любой вопрос и получить ответ от всего нашего сообщества!

Telegram Чат & Канал

Вступите в наш дружный чат по Python и начните общение с единомышленниками! Станьте частью большого сообщества!

Паблик VK

Одно из самых больших сообществ по Python в социальной сети ВК. Видео уроки и книги для вас!

Логирование из нескольких модулей (а также форматирование)

Чем больше вы кодите, тем чаще вам нужно создавать набор настраиваемых модулей, которые должны работать вместе. Если вы хотите, чтобы запись велась в одном месте, значит, вы обратились по адресу. Мы рассмотрим простой пример, затем взглянем на более сложный метод, который также и более настраиваемый. Вот простой способ сделать это:

import logging

import otherMod

def main():

«»»

The main entry point of the application

«»»

logging.basicConfig(filename=«mySnake.log», level=logging.INFO)

logging.info(«Program started»)

result = otherMod.add(7, 8)

logging.info(«Done!»)

if __name__ == «__main__»:

main()

Здесь мы импортируем logging и модуль нашего творения (“otherMod”). После чего мы создаем лог-файл, как мы делали это раньше. Другой модуль выглядит следующим образом:

# otherMod.py

import logging

def add(x, y):

«»»»»»

logging.info(«added %s and %s to get %s» % (x, y, x+y))

return x+y

Если вы запустите основной код, вы получите лог со следующим содержимым:

INFO:root:Program started

INFO:root:added 7 and 8 to get 15

INFO:root:Done!

Заметили проблему в этом? Вы не можете однозначно сказать, откуда приходят сообщения. При этом, чем больше модулей пишут в лог, тем сложнее становится картина. Так что нам нужно это исправить. Таким образом, мы приходим к более сложному способу создание логгера. Давайте взглянем на другой способ создания:

import logging

import otherMod2

def main():

«»»

The main entry point of the application

«»»

logger = logging.getLogger(«exampleApp»)

logger.setLevel(logging.INFO)

# create the logging file handler

fh = logging.FileHandler(«new_snake.log»)

formatter = logging.Formatter(‘%(asctime)s — %(name)s — %(levelname)s — %(message)s’)

fh.setFormatter(formatter)

# add handler to logger object

logger.addHandler(fh)

logger.info(«Program started»)

result = otherMod2.add(7, 8)

logger.info(«Done!»)

if __name__ == «__main__»:

main()

Здесь мы создали экземпляр логгера под названием “exampleApp”. Мы установили его уровень ведения журнала, создали объект обработчика лог-файла, и объект форматирование. Обработчик файла должен установить объект форматирование в качестве своего форматтера, после чего обработчик файла должен быть добавлен в регистратор логгера. Остальная часть кода по большому счету остается неизменной. Только обратите внимание на то, что вместо logging.info мы используем logger.info, или любое другое название переменной вашего логгера. Давайте рассмотрим обновленный код otherMod2:

# otherMod2.py

import logging

module_logger = logging.getLogger(«exampleApp.otherMod2»)

def add(x, y):

«»»»»»

logger = logging.getLogger(«exampleApp.otherMod2.add»)

logger.info(«added %s and %s to get %s» % (x, y, x+y))

return x+y

Обратите внимание на то, что здесь у нас два определенных логгера. Мы ничего не делаем с module_logger в данном случае, но мы используем другой модуль. Если вы запустите основной скрипт, вы увидите следующий результат в своем файле:

2012—08—02 15:37:40,592 — exampleApp — INFO — Program started

2012—08—02 15:37:40,592 — exampleApp.otherMod2.add — INFO — added 7 and 8 to get 15

2012—08—02 15:37:40,592 — exampleApp — INFO — Done!

Вы заметите ,что все ссылки на root были удалены. Вместо этого, мы используем наш объект Formatter, который говорит нам, что нам нужно получить читаемое время, имя логгера, уровень логирования и сообщение. Все это в комплексе также известно как атрибуты LogRecord. Для полного списка атрибутов LogRecord обратитесь к документации Python, так как объем информации достаточно велик.

Конфигурация логов для работы

Модуль logging может быть сконфигурирован тремя различными способами. Вы можете настроить данный модуль при помощи методов (логгеров, форматтеров, обработчиков, как мы делали это ранее в данном разделе. Вы можете использовать файл конфигурации и передать его fileConfig(). Или же вы можете создать словарь информацией о конфигурации и передать его функции fileConfig(). Давайте создадим файл конфигурации для начала, а затем взглянем на то, как выполнить его в Python. Вот пример файла config:

[loggers]

keys=root,exampleApp

[handlers]

keys=fileHandler, consoleHandler

[formatters]

keys=myFormatter

[logger_root]

level=CRITICAL

handlers=consoleHandler

[logger_exampleApp]

level=INFO

handlers=fileHandler

qualname=exampleApp

[handler_consoleHandler]

class=StreamHandler

level=DEBUG

formatter=myFormatter

args=(sys.stdout,)

[handler_fileHandler]

class=FileHandler

formatter=myFormatter

args=(«config.log»,)

[formatter_myFormatter]

format=%(asctime)s — %(name)s — %(levelname)s — %(message)s

datefmt=

Обратите внимание на то, что у нас есть два определенных логгера: root и exampleApp. По какой-то причине, необходим именно root. Так что если вы его не включите в код, возникнет ошибка ValueError функции config.py _install_loggers, которая является частью модуля logging. Если вы установите обработчик root на fileHandler, то это приведет к дублированию выхода журнала, так что во избежание этого, мы отправляем его на консоль. Внимательно изучите данный пример. Вам нужна секция для каждого ключа в первых трех секциях. Давайте взглянем на то, как загрузить это в код:

# log_with_config.py

import logging

import logging.config

import otherMod2

def main():

«»»

Based on http://docs.python.org/howto/logging.html#configuring-logging

«»»

logging.config.fileConfig(‘logging.conf’)

logger = logging.getLogger(«exampleApp»)

logger.info(«Program started»)

result = otherMod2.add(7, 8)

logger.info(«Done!»)

if __name__ == «__main__»:

main()

Как вы видите, все, что вам нужно это передать путь файла config нашему logging.config.fileConfig. Обратите внимание на то, что нам больше не нужен установочный код, для этого у нас есть файл config. Также мы можем просто импортировать модуль otherMod2 без каких либо изменений. В любом случае, если вы запустите указанный выше код, вы получите следующий результат в своем лог файле:

2012—08—02 18:23:33,338 — exampleApp — INFO — Program started

2012—08—02 18:23:33,338 — exampleApp.otherMod2.add — INFO — added 7 and 8 to get15

2012—08—02 18:23:33,338 — exampleApp — INFO — Done!

Как вы могли догадаться, это очень похоже на другой пример. Теперь мы готовы перейти к следующему методу config. Метода словаря конфигураций dictConfig не существовало в Python до версии 2.7. Так что убедитесь в том, что вы работаете в последней версии, иначе вы не сможете приступить к следующей части. В документации не сказано прямо, как это работает. В действительности, примеры в документации, по какой-то причине показывают YAML. В любом случае, давайте рассмотрим один рабочий код:

# log_with_config.py

import logging

import logging.config

import otherMod2

def main():

«»»

Based on http://docs.python.org/howto/logging.html#configuring-logging

«»»

dictLogConfig = {

«version»:1,

«handlers»:{

«fileHandler»:{

«class»:«logging.FileHandler»,

«formatter»:«myFormatter»,

«filename»:«config2.log»

}

«loggers»:{

«exampleApp»:{

«handlers»:[«fileHandler»],

«level»:«INFO»,

}

«formatters»:{

«myFormatter»:{

«format»:«%(asctime)s — %(name)s — %(levelname)s — %(message)s»

}

logging.config.dictConfig(dictLogConfig)

logger = logging.getLogger(«exampleApp»)

logger.info(«Program started»)

result = otherMod2.add(7, 8)

logger.info(«Done!»)

if __name__ == «__main__»:

main()

Если вы запустите этот код, вы получите такой же результат, как в предыдущем методе. Обратите внимание на то, что вам больше не нужен логгер root, когда вы используете словарь конфигурации.

Подведем итоги

С этого момента вы должны уметь пользовать логгерами и выполнять их конфигурацию несколькими различными методами. Вы также получили все необходимые знания для модификации выдачу при помощи объекта Formatter. Модуль logging очень полезен в решении возникших проблем в работе вашего приложения. Постарайтесь провести больше времени за практической работой с данным модулем перед написанием большого приложения.

Являюсь администратором нескольких порталов по обучению языков программирования Python, Golang и Kotlin. В составе небольшой команды единомышленников, мы занимаемся популяризацией языков программирования на русскоязычную аудиторию. Большая часть статей была адаптирована нами на русский язык и распространяется бесплатно.

E-mail: vasile.buldumac@ati.utm.md

Образование
Universitatea Tehnică a Moldovei (utm.md)

2014 — 2018 Технический Университет Молдовы, ИТ-Инженер. Тема дипломной работы «Автоматизация покупки и продажи криптовалюты используя технический анализ»
2018 — 2020 Технический Университет Молдовы, Магистр, Магистерская диссертация «Идентификация человека в киберпространстве по фотографии лица»

Источник

В стандартной библиотеке Python есть замечательный пакет для логирования — logging. В сети бытует мнение, что он сложный и настраивать его сплошная боль. В этой статье я попробую убедить вас в обратном. Мы разберём что из себя представляет этот пакет, изучим основные компоненты и закрепим материал практическим примером.

Зачем нужны логи?

Логи это рентген снимок выполнения вашей программы. Чем детальнее лог, тем проще разобраться в нестандартных ситуациях, которые могут приключиться с вашим скриптом. Наиболее популярным примером логов служат access логи веб-сервера, например, Apache httpd или nginx. Пример куска access лога моего блога:

92.63.107.227 - - [04/Nov/2020:06:30:48 +0000] "GET /ru/hosted-open-vpn-server/ HTTP/1.1" 301 169 "-" "python-requests/2.11.1" "-"
92.63.107.227 - - [04/Nov/2020:06:30:49 +0000] "GET /ru/data-engineering-course/ HTTP/1.1" 301 169 "-" "python-requests/2.11.1" "-"
213.180.203.50 - - [04/Nov/2020:06:36:07 +0000] "GET / HTTP/1.1" 301 169 "-" "Mozilla/5.0 (compatible; YandexMetrika/2.0; +http://yandex.com/bots yabs01)" "-"
114.119.160.75 - - [04/Nov/2020:06:36:41 +0000] "GET /robots.txt HTTP/1.1" 301 169 "-" "(compatible;PetalBot;+https://aspiegel.com/petalbot)" "10.179.80.67"
90.180.35.207 - - [04/Nov/2020:06:47:11 +0000] "GET / HTTP/1.0" 301 169 "-" "-" "-"
46.246.122.77 - - [04/Nov/2020:06:53:22 +0000] "GET / HTTP/1.1" 301 169 "<http://khashtamov.com>" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/66.0.3359.181 Safari/537.36" "-"
66.249.76.16 - - [04/Nov/2020:06:53:30 +0000] "GET / HTTP/1.1" 301 169 "-" "Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" "-"
66.102.9.118 - - [04/Nov/2020:07:11:19 +0000] "GET / HTTP/1.1" 301 169 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/49.0.2623.75 Safari/537.36 Google Favicon" "46.159.204.234"
71.6.167.142 - - [04/Nov/2020:07:11:55 +0000] "GET / HTTP/1.1" 301 169 "-" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2228.0 Safari/537.36" "-"

Помимо access логов веб-сервер также пишет error лог, там хранится информация обо всех ошибках при обработке HTTP запросов. Также и в ваших скриптах, логи могут делиться на информационные — вывод текущего состояния выполнения, отладочной информации, и на логи с ошибками — вывод исключений, ошибок с дополнительной информацией для отладки, содержащей контекст).

logging и Python

Точкой входа в работу с логированием в Python является библиотека logging. На первый взгляд может показаться, что библиотека сложная и запутанная, но потратив некоторое время на её изучение, можно убедиться в обратном. Для меня logging это классический пример дизайна ООП, где композиция преобладает над наследованием, поэтому в исходном коде библиотеки можно встретить множество функциональных классов. Цель этого туториала разобрать по косточкам каждый класс и воссоединить их в единый механизм логирования в Python. Начнём-с.

Logger

Чтобы начать работу с logging необходимо в импортировать библиотеку logging и вызвать функцию getLogger, передав ей имя будущего логера. Функция вернёт инстанс объекта Logger. Логер это рычаг за который мы дёргаем каждый раз, когда нам нужно записать информацию в лог.

import logging

logger = logging.getLogger('logger')

Заметьте, что функция getLogger принимает на вход параметр — имя логера. Можно назначать любое имя или __name__. Вызов getLogger с одинаковым названием вернёт один и тот же инстанс логера.

Я рекомендую использовать в качестве аргумента __name__, в этом случае не нужно беспокоиться, что разные модули могут ссылаться на один и тот же логер.

Класс Logger предоставляет наружу несколько методов для записи сообщений разного уровня. Уровни необходимы для понимания контекста сообщения/лога, который мы пишем. В logging существует несколько уровней:

DEBUG — уровень отладочной информации, зачастую помогает при разработке приложения на машине программиста.
INFO — уровень вспомогательной информации о ходе работы приложения/скрипта.
WARNING — уровень предупреждения. Например, мы можем предупреждать о том, что та или иная функция будет удалена в будущих версиях вашего приложения.
ERROR — с таким уровнем разработчики пишут логи с ошибками, например, о том, что внешний сервис недоступен.
CRITICAL — уровень сообщений после которых работа приложения продолжаться не может.

По умолчанию в logging задан уровень WARNING, это означает, что сообщения уровня DEBUG и INFOбудут игнорироваться при записи в лог. Разработчик может самостоятельно задать необходимый ему уровень логирования через метод setLevel у инстанса Logger:

logger.setLevel(logging.DEBUG)

Методы для записи сообщений с разными уровнями именуются по тому же принципу:

logger.debug('debug info')
logger.info('info')
logger.warning('warning')
logger.error('debug info')
logger.critical('debug info')

Также есть ещё один метод — exception. Его желательно вызывать в блоке except при обработке исключения. В это случае он сможет уловить контекст исключения и записать его в лог:

try:
    1/0
except :
    logger.exception('exception')

Handler

Задача класса Handler и его потомков обрабатывать запись сообщений/логов. Т.е. Handler отвечает за то куда будут записаны сообщения. В базовом наборе logging предоставляет ряд готовых классов-обработчиков:

SteamHandler — запись в поток, например, stdout или stderr.
FileHandler — запись в файл, класс имеет множество производных классов с различной функциональностью (ротация файлов логов по размеру, времени и т.д.)
SocketHandler — запись сообщений в сокет по TCP
DatagramHandler — запись сообщений в сокет по UDP
SysLogHandler — запись в syslog
HTTPHandler — запись по HTTP

Это далеко не полный список. Чтобы посмотреть все, перейдите по ссылке выше. Для указания Handler, необходимо у инстанса Logger вызвать метод addHandler и передать туда инстанс класса Handler. У одного Logger инстанса может быть множество обработчиков.

Пример записи лога в stdout:

import sys
import logging
from logging import StreamHandler

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
handler = StreamHandler(stream=sys.stdout)
logger.addHandler(handler)

logger.debug('debug information')

Если запустить этот скрипт, то можно увидеть сообщение:

debug information

Мы видим сообщение уровня DEBUG потому что задачи этот уровень в настройках. Если поменять его на INFO, то сообщение пропадёт:

logger.setLevel(logging.INFO)

Наверняка вы обратили внимание, что лог содержит всего лишь переданную строку. Как сделать так, чтобы в логе была информация об уровне лога, времени записи?

Formatter

Formatter это ёщё один класс в семействе logging, отвечающий за отображение лога. Если класс Handler ответственный за то куда будет происходить запись, то класс Formatter отвечает на вопрос как будет записано сообщение. По умолчанию в лог пишется голая строка, которую мы передаём через методы debug, info и т.д. Давайте обогатим наш лог дополнительной метаинформация, например, о времени записи и уровне сообщения. Formatter передаётся инстансу Handler через метод .setFormatter

import sys
import logging
from logging import StreamHandler, Formatter

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

handler = StreamHandler(stream=sys.stdout)
handler.setFormatter(Formatter(fmt='[%(asctime)s: %(levelname)s] %(message)s'))
logger.addHandler(handler)

logger.debug('debug information')

Запуск скрипта выведет на экран следующее сообщение:

[2020-11-22 13:00:08,751: DEBUG] debug information

Обратите внимание на строку, которую я передал при инициализации инстанса Formatter:

[%(asctime)s: %(levelname)s] %(message)s

Это шаблон, который будет заполнен при записи сообщения в лог. Набор таких готовых шаблонов можно посмотреть в разделе LogRecord attributes.

Filter

Задача класса фильтровать сообщения по заданной разработчиком логике. Предположим, что я хочу записывать в лог сообщения, содержащие слово python. Чтобы задать фильтр необходимо вызвать метод addFilter у инстанса Logger. Передать можно либо инстанс класса, реализующий метод filter либо callable объект (например, функцию). На вход прилетит инстанс класса LogRecord, это и есть 1 сообщение лога:

import sys
import logging
from logging import StreamHandler, Formatter, LogRecord

def filter_python(record: LogRecord) -> bool:
    return record.getMessage().find('python') != -1

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

handler = StreamHandler(stream=sys.stdout)
handler.setFormatter(Formatter(fmt='[%(asctime)s: %(levelname)s] %(message)s'))
logger.addHandler(handler)
logger.addFilter(filter_python)

logger.debug('python debug information')

Наглядно и понятно, разве logging может быть сложным? 😎

LoggerAdapter

Адаптер нужен для передачи дополнительной контекстной информации при каждой записи лога через Logger. Например, вы написали веб-приложение и вам необходимо в логи дополнительно передавать username пользователя:

class CustomLoggerAdapter(LoggerAdapter):
    def process(self, msg, kwargs):
        return f'{msg} from {self.extra["username"]}', kwargs

logger2 = logging.getLogger('adapter')
logger2.setLevel(logging.DEBUG)

handler = StreamHandler(stream=sys.stdout)
handler.setFormatter(Formatter(fmt='[%(asctime)s: %(levelname)s] %(message)s'))

adapter = CustomLoggerAdapter(logger2, {'username': 'adilkhash'})

logger2.addHandler(handler)
adapter.error('failed to save')

extra и не только

Строки в логах это хорошо, а что если я хочу помимо строки дополнительно передавать ответ от веб-сервера? Для этого можно использовать аргумент extra при вызове методов debug, info и т.д. Давайте напишем пример вывода

logger.debug('debug info', extra={"response": response.text})

Теперь вывод значения ключа response можно указать через Formatter (при условии, что response передаётся всегда):

Formatter(fmt='[%(asctime)s: %(levelname)s] %(message)s, response: %(response)s')

Аргумент extra удобен при написании своих кастомных обработчиков логов (например, отсылка логов в телеграм). Далее я покажу пример кастомного Handler класса для отправки логов в Telegram через бота.

Конфигурация logging

Официальная документация рекомендует конфигурировать logging через python-словарь. Для этого необходимо вызвать функцию logging.config.dictConfig и передать ей специальный словарь. Схема словаря описана здесь. Я лишь вкратце пробегусь по основным ключам:

version — ключ указывает версию конфига, рекомендуется наличие этого ключа со значением 1, нужно для обратной совместимости в случае, если в будущем появятся новые версии конфигов.
disable_existing_loggers — запрещает или разрешает настройки для существующих логеров (на момент запуска), по умолчанию равен True
formatters — настройки форматов логов
handlers — настройки для обработчиков логов
loggers — настройки существующих логеров

Ранее все настройки я задавал кодом через вызов методов. Это может быть удобно, если у вас 1 модуль, но когда таких модулей становится множество, то в каждом из них задавать общие настройки кажется излишним занятием. Давайте попробуем все настройки задать в одном месте:

import logging.config

LOGGING_CONFIG = {
    'version': 1,
    'disable_existing_loggers': False,

    'formatters': {
        'default_formatter': {
            'format': '[%(levelname)s:%(asctime)s] %(message)s'
        },
    },

    'handlers': {
        'stream_handler': {
            'class': 'logging.StreamHandler',
            'formatter': 'default_formatter',
        },
    },

    'loggers': {
        'my_logger': {
            'handlers': ['stream_handler'],
            'level': 'DEBUG',
            'propagate': True
        }
    }
}

logging.config.dictConfig(LOGGING_CONFIG)
logger = logging.getLogger('my_logger')
logger.debug('debug log')

Неправда ли удобно? В реальных приложениях настройки выносят в отдельный модуль, который обязательно импортируется на старте, например, модуль в settings.py как в Django. Именно в нём задаются глобальные настройки для всех логеров приложения.

Наследование в logging

Ещё одним удобным механизмом в logging является «наследование» настроек корневого логера его потомками. Наследование задаётся через символ . в названии логера. То есть логер с названием my_package.logger1 унаследует все настройки, заданные для my_package. Давайте обновим пример выше, добавив в LOGGING_CONFIG настройку для my_package

LOGGING_CONFIG['loggers'].update({
    'my_package': {
        'handlers': ['stream_handler'],
        'level': 'DEBUG',
        'propagate': False
    }
})

Если у вас есть настройка для конкретного логера и вы не хотите, чтобы он был дополнительно обработан родительскими Handler классами, то ключу propagate нужно присвоить значение False. В этом случае передача управления «вверх» до родителя будет запрещена.

Отправляем логи в Telegram

А теперь давайте напишем свой кастомный Handler для отправки логов через бота в телеграм. Если вы никогда не работали с телеграм-ботами, то почитайте мою статью про создание телеграм-ботов. Я предполагаю, что вы уже создали бота, получили его токен и знаете свой user-id/chat-id, чтобы бот смог посылать сообщения лично вам. Для работы с телеграмом я использую библиотеку pyTelegramBotAPI.

Чтобы создать свой обработчик, необходимо наследоваться от класса Handler и перезаписать метод emit:

import telebot
from logging import Handler, LogRecord

class TelegramBotHandler(Handler):
    def __init__(self, token: str, chat_id: str):
        super().__init__()
        self.token = token
        self.chat_id = chat_id

    def emit(self, record: LogRecord):
        bot = telebot.TeleBot(self.token)
        bot.send_message(
            self.chat_id,
            self.format(record)
        )

При инициализации инстанса класса TelegramBotHandler ему необходимо будет передать токен бота и chat_id. Замечу, что эти настройки можно задать через конфигурирование:

'handlers': {
        'telegram_handler': {
            'class': 'handlers.TelegramBotHandler',
            'chat_id': '<CHAT_ID>',
            'token': '<BOT_TOKEN>',
            'formatter': 'default_formatter',
        }
    },

Чтобы обработчик начал свою работу, достаточно в настройках вашего логера прописать новый обработчик:

LOGGING_CONFIG['loggers'].update({
    'my_package': {
        'handlers': ['stream_handler', 'telegram_handler'],
        'level': 'DEBUG',
        'propagate': False
    }
})

Всё готово! 😎

Заключение

В этой статье я постарался вкратце рассказать и показать основные сущности библиотеки logging, а также продемонстрировать гибкий механизм логирования в python. Надеюсь мне это удалось, и статья оказалась для вас полезной.

💌 Присоединяйтесь к рассылке

Понравился контент? Пожалуйста, подпишись на рассылку.

Источник

По мере того, как приложения меняются и усложняются, наличие лог-журнала будет полезным при отладке и для понимания проблем, анализа производительности приложений.

Стандартная библиотека логгирования в Python поставляется модулем logging , который предлагает большинство главных функций для ведения лога. При правильной настройке сообщения лога, мы получим много полезной информации. О том, когда и где запускается логгирование, о контексте лог-журнала, например: запущенном процессе или потоке.

Несмотря на преимущества, модуль logging часто упускается из виду, так как для правильной настройки требуется некоторое время. На мой взгляд, полная официальная документация logging на самом деле не показывает лучших методов ведения лог-журнала и не выделяет некоторые сюрпризы ведения лог-журнала.

Обратите внимание, что фрагменты кода в статье предполагают, что вы уже импортировали модуль logging:

import logging

Концепции Python Logging

В этом разделе представлен обзор некоторых концепций, которые часто встречаются в модуле logging.

Уровни Python Logging

Уровень лога соответствует его важности: лог ERROR важнее, чем WARNING. Тогда как лог DEBUG следует использовать только при отладке приложения.
Python предлагает шесть уровней лога; каждый уровень связан с числом, которое указывает на важность лога: NOTSET=0, DEBUG=10, INFO=20, WARNING=30, ERROR=40 и CRITICAL=50.
Иерархия уровней интуитивно понятна: DEBUG < INFO < WARNING. Кроме NOTSET, со спецификой которого, ознакомимся позднее.

Форматирование лога в Python

Форматирование лога дополняет сообщение, добавляя к нему контекстную информацию. Полезно знать, когда отправляется лог, где (файл Python, номер строки, метод и т. д.), а так же дополнительный контекст, такой как поток и процесс. Чрезвычайно полезные данные при отладке многопоточного приложения.

"%(time)s — %(log_name)s — %(level)s — %(func_name)s:%(line_no)d — %(message)s"

Он превращается в:

2019-01-16 10:35:12,468 - keyboards - ERROR - <module>:1 - привет мир

Обработчик ведения лога в Python

Обработчик лога — компонент, который записывает и отображает данные лога. Он отображает лог в консоли (через StreamHandler), в файле (через FileHandler), с помощью отправки электронного письма (через SMTPHandler) и других методов.
В каждом обработчике лога 2 важных поля:

Форматировщик, который добавляет контекстную информацию в лог.
Уровень важности лога, который отфильтровывает логи, уровни которых ниже. Поэтому обработчик лога с уровнем INFO не будет обрабатывать логи DEBUG.

Стандартная библиотека содержит несколько обработчиков, которых достаточно для большинства случаев: https://docs.python.org/3/library/logging.handlers.html#module-logging.handlers. Наиболее распространенные — StreamHandler и FileHandler:

console_handler = logging.StreamHandler()
file_handler = logging.FileHandler("MyLogFile.txt")

Python Logger

Логгер будет использоваться чаще всего в коде и будет самым сложным. Новый Logger получим следующим образом:

toto_logger = logging.getLogger("Privacy")

У логгера три основных поля:

Propagate: определяет, должен ли лог распространяться на родителя журнала. По умолчанию равен True.
Level: как и уровень обработчика лога, уровень логгера используется для фильтрации “менее важных” логов. Кроме того, в отличие от обработчика лога, уровень проверяется только на “детях” логгера; и после того, как лог распространился среди его родителей, уровень не будет проверятся. Это скорее не интуитивное поведение.
Handlers: список обработчиков, на которые отправит лог, когда поступит в логгер. Это делает обработку логов гибкой, например, вы создадите обработчик лога для записи в файл, который регистрирует логи DEBUG и обработчик лога для отправки электронной почты, который будет использоваться только для логов CRITICAL. Таким образом, отношение обработчика-логгера становится похожим на издатель-потребитель: где лог будет передаваться всем обработчикам после проверки уровня лога.

Logger определяется по имени, это означает, что если создан лог с именем foo, последующие вызовы logging.getLogger (" foo") будут возвращать один и тот же объект:

assert id(logging.getLogger("foo")) == id(logging.getLogger("foo"))

Как вы могли догадаться, у логгеров есть иерархия. В верхней части иерархии корневой лог, к которому можно получить доступ через logging.root. Этот лог вызывается, когда используются такие методы, как logging.debug(). По умолчанию, уровень корневого лога — WARNING, поэтому каждый лог с уровнем ниже игнорируется (например, через logging.info("info")).
Другая особенность корневого логгера заключается в том, что его обработчик, по умолчанию, создается при первом входе в лог с уровнем, выше WARNING.
Использование корневого логгера с помощью таких методов, как logging.debug(), не рекомендуется

lab = logging.getLogger("f.r")
assert lab.parent == logging.root # lab.parent действительно корневой логгер

Тем не менее логгер использует “точечную запись”, значит логгер с именем f.r будет потомком логгерра f. Однако это справедливо только в том случае, когда создан лог f, иначе родитель fr по прежнему будет корнем.

la = logging.getLogger("f")
assert lab.parent == la # родитель lab теперь la вместо корня

Эффективный уровень логгера

Когда логгер решает, должен ли лог выводится в соответствии с уровнем важности (например, если уровень лога ниже уровня логгера, сообщение будет проигнорировано), он использует свой “эффективный уровень” вместо фактического уровня.
Эффективный уровень совпадает с уровнем логгера, если уровень не равен NOTSET. Однако, если уровень логгера равен NOTSET, эффективным уровнем будет первый уровень родителя, у которого уровень не NOTSET.
По умолчанию, новый логгер имеет уровень NOTSET. Поскольку корневой логгер с уровнем WARNING, эффективный уровень логгера будет WARNING.
Поэтому, даже если новый логгер подключен к некоторым обработчикам, эти обработчики не будут вызываться, если уровень лога не превысит WARNING:

foo_logger = logging.getLogger("foo")
assert foo_logger.level == logging.NOTSET # у нового логгера уровень NOTSET
assert foo_logger.getEffectiveLevel() == logging.WARNING # и его эффективный уровень не является уровнем корневого логгера
# прикрепите консольный обработчик к foo_logger
console_handler = logging.StreamHandler()
foo_logger.addHandler(console_handler)
foo_logger.debug("debug level") # ничего не отображается, так как уровень лога DEBUG меньше чем эффективный уровень foo 
foo_logger.setLevel(logging.DEBUG)
foo_logger.debug("debug message") # теперь вы увидите на экране "debug message"

По умолчанию, уровень логгера будет использоваться для решения о выводе лога. Если уровень лога ниже уровня логгера, лог не будет брать во внимание.

Модуль Logging

Модуль logging в Python – это готовый к использованию, мощный модуль, предназначенный для удовлетворения потребностей как начинающих, так и корпоративных команд. Он используется большинством сторонних библиотек Python, поэтому вы можете интегрировать ваши логи с сообщениями из этих библиотек для создания единого журнала логов в вашего приложении.

Добавить logging в вашу программу на Python так же просто, как написать эту строчку:

import logging

С импортированным модулем logging вы можете использовать то, что называется «logger», для логирования сообщений, которые вы хотите видеть. По умолчанию существует 5 стандартных уровней severity, указывающих на важность событий. У каждого есть соответствующий метод, который можно использовать для логирования событий на выбранном уровне severity. Список уровней в порядке увеличения важности:

DEBUG
INFO
WARNING
ERROR
CRITICAL

Модуль logging предоставляет вам логер по умолчанию, который позволяет вам начать работу без дополнительных настроек. Соответствующие методы для каждого уровня можно вызвать, как показано в следующем примере:

import logging

logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

Вывод вышеупомянутой программы будет выглядеть так:

WARNING:root:This is a warning message
ERROR:root:This is an error message
CRITICAL:root:This is a critical message

Вывод показывают уровень важности перед каждым сообщением вместе с root, который является именем, которое модуль logging дает своему логеру по умолчанию. Этот формат, который показывает уровень, имя и сообщение, разделенные двоеточием (:), является форматом вывода по умолчанию, и его можно изменить для включения таких вещей, как отметка времени, номер строки и других деталей.

Обратите внимание, что сообщения debug() и info() не были отображены. Это связано с тем, что по умолчанию модуль ведения журнала регистрирует сообщения только с уровнем WARNING или выше. Вы можете изменить это, сконфигурировав модуль logging для регистрации событий всех уровней. Вы также можете определить свои собственные уровни, изменив конфигурации, но, как правило, это не рекомендуется, так как это может привести к путанице с журналами некоторых сторонних библиотек, которые вы можете использовать.

Базовая конфигурация

Вы можете использовать метод basicConfig (**kwargs) для настройки ведения логов:

«Вы можете заметить, что модуль logging нарушает руководство по стилю PEP8 и использует соглашения camelCase в именнование переменных. Это потому, что он был адоптирован из пакета Log4j (утилиты ведения логов в Java). Это известная проблема в пакете, но к тому времени, когда было решено добавить ее в стандартную библиотеку, она уже была принята пользователями, и изменение ее в соответствии с требованиями PEP8 вызовет проблемы обратной совместимости ». (Источник)

Вот некоторые из часто используемых параметров для basicConfig():

level: Корневой логер с установленным указанным уровнем важности (severity).
filename: Указание файла логов
filemode: Режим открытия файла. По умолчанию это a, что означает добавление.
format: Формат сообщений.

Используя параметр level, вы можете установить, какой уровень сообщений журнала вы хотите записать. Это можно сделать, передав одну из констант, доступных в классе, и это позволило бы регистрировать все вызовы logging на этом уровне или выше. Вот пример:

import logging

logging.basicConfig(level=logging.DEBUG)
logging.debug('This will get logged')

DEBUG:root:This will get logged

Теперь будут регистрироваться все события на уровне DEBUG или выше.

Аналогично, для записи логов в файл, а не в консоль, можно использовать filename и filemode, и вы можете выбрать формат сообщения, используя format. В следующем примере показано использование всех трех переменных:

import logging

logging.basicConfig(filename='app.log', filemode='w', format='%(name)s - %(levelname)s - %(message)s')
logging.warning('This will get logged to a file')

root - ERROR - This will get logged to a file

Сообщение будет записано в файл с именем app.log вместо вывода в консоль. Для filemode значение w означает, что файл журнала открывается в «режиме записи» каждый раз, когда вызывается basicConfig(), и при каждом запуске программы файл перезаписывается. Конфигурацией по умолчанию для filemode является a, которое является добавлением.

Вы можете настроить корневой logger еще больше, используя дополнительные параметры для basicConfig(), которые можно найти здесь.

Следует отметить, что вызов basicConfig() для настройки корневого logger работает, только если корневой logger не был настроен ранее. По сути, эта функция может быть вызвана только один раз.

debug(), info(), warning(), error() и crit() также автоматически вызывают basicConfig() без аргументов, если он ранее не вызывался. Это означает, что после первого вызова одной из вышеперечисленных функций вы больше не сможете изменить настройки корневого logger.

Формат вывода

Хотя вы можете передавать любую переменную, которая может быть представлена в виде строки из вашей программы в виде сообщения в ваши журналы, есть некоторые базовые элементы, которые уже являются частью LogRecord и могут быть легко добавлены в выходной формат. Если вы хотите записать идентификатор процесса ID вместе с уровнем и сообщением, вы можете сделать что-то вроде этого:

import logging

logging.basicConfig(format='%(process)d-%(levelname)s-%(message)s')
logging.warning('This is a Warning')

18472-WARNING-This is a Warning

format может принимать строку с атрибутами LogRecord в любом порядке. Весь список доступных атрибутов можно найти здесь.

Вот еще один пример, где вы можете добавить информацию о дате и времени:

import logging

logging.basicConfig(format='%(asctime)s - %(message)s', level=logging.INFO)
logging.info('Admin logged in')

2018-07-11 20:12:06,288 - Admin logged in

%(asctime)s добавляет время создания LogRecord. Формат можно изменить с помощью атрибута datefmt, который использует тот же язык форматирования, что и функции форматирования в модуле datetime, например time.strftime():

import logging

logging.basicConfig(format='%(asctime)s - %(message)s', datefmt='%d-%b-%y %H:%M:%S')
logging.warning('Admin logged out')

12-Jul-18 20:53:19 - Admin logged out

Вы можете найти больше информации о формате datetime в этом руководстве.

Логирование переменных

В большинстве случаев вам нужно будет включать динамическую информацию из вашего приложения в журналы. Вы видели, что методы ведения журнала принимают строку в качестве аргумента, и может показаться естественным отформатировать строку с переменными в отдельной строке и передать ее методу log. Но на самом деле это можно сделать напрямую, используя строку формата для сообщения и добавляя переменные в качестве аргументов. Вот пример:

import logging

name = 'John'

logging.error('%s raised an error', name)

ERROR:root:John raised an error

Аргументы, передаваемые методу, будут включены в сообщение в качестве переменных.

Хотя вы можете использовать любой стиль форматирования, f-строки, представленные в Python 3.6, являются лучшим способом форматирования строк, поскольку они могут помочь сделать форматирование коротким и легким для чтения:

import logging

name = 'John'

logging.error(f'{name} raised an error')

ERROR:root:John raised an error

Вывод стека

Модуль регистрации также позволяет вам захватывать стек выполнения в приложении. Информация об исключении может быть получена, если параметр exc_info передан как True, а функции ведения журнала вызываются таким образом:

import logging

a = 5
b = 0

try:
  c = a / b
except Exception as e:
  logging.error("Exception occurred", exc_info=True)

ERROR:root:Exception occurred
Traceback (most recent call last):
  File "exceptions.py", line 6, in <module>
    c = a / b
ZeroDivisionError: division by zero
[Finished in 0.2s]

Если для exc_info не задано значение True, выходные данные вышеприведенной программы не сообщат нам ничего об исключении, которое в реальном сценарии может быть не таким простым, как ZeroDivisionError. Представьте, что вы пытаетесь отладить ошибку в сложной кодовой базе с помощью журнала, который показывает только это:

ERROR:root:Exception occurred

Совет: если вы логируете в обработчике исключений (try..except…), используйте метод logging.exception(), который регистрирует сообщение с уровнем ERROR и добавляет в сообщение информацию об исключении. Проще говоря, вызов logging.exception() похож на вызов logging.error (exc_info = True). Но поскольку этот метод всегда выводит информацию об исключении, его следует вызывать только в обработчике исключений. Взгляните на этот пример:

import logging

a = 5
b = 0
try:
  c = a / b
except Exception as e:
  logging.exception("Exception occurred")

ERROR:root:Exception occurred
Traceback (most recent call last):
  File "exceptions.py", line 6, in <module>
    c = a / b
ZeroDivisionError: division by zero
[Finished in 0.2s]

Использование logging.exception() покажет лог на уровне ERROR. Если вы не хотите этого, вы можете вызвать любой из других методов ведения журнала от debug() до critical() и передать параметр exc_info как True.

Классы и функции

До сих пор мы видели logger по умолчанию с именем root, который используется модулем logging всякий раз, когда его функции вызываются непосредственно таким образом: logging.debug(). Вы можете (и должны) определить свой собственный logger, создав объект класса Logger, особенно если ваше приложение имеет несколько модулей. Давайте посмотрим на некоторые классы и функции в модуле.

Наиболее часто используемые классы, определенные в модуле logging, следующие:

Logger: Это класс, чьи объекты будут использоваться в коде приложения напрямую для вызова функций.
LogRecord: Logger автоматически создает объект LogRecord, в котором находиться вся информация, относящаяся к регистрируемому событию, например, имя логера, функции, номер строки, сообщение и т. д.
Handler: Обработчики отправляют LogRecord в требуемое место назначения вывода, такое как консоль или файл. Обработчик является основой для подклассов, таких как StreamHandler, FileHandler, SMTPHandler, HTTPHandler и других. Эти подклассы отправляют выходные данные журнала соответствующим адресатам, таким как sys.stdout или файл на диске.
Formatter: Здесь вы указываете формат вывода, задавая строковый формат, в котором перечислены атрибуты, которые должны содержать выходные данные.

Из всего перечисленного мы в основном имеем дело с объектами класса Logger, которые создаются с помощью функции уровня модуля logging.getLogger(name). Многократные вызовы getLogger() с одним и тем же именем возвращают ссылку на один и тот же объект Logger, что избавляет нас от передачи объектов logger в каждую часть, где это необходимо. Вот пример:

import logging

logger = logging.getLogger('example_logger')
logger.warning('This is a warning')

This is a warning

Этот код создает пользовательский logger с именем example_logger, но в отличие от корневого logger, имя настраиваемого регистратора не является частью выходного формата по умолчанию и должна быть добавлена в конфигурацию. Конфигурирование его в формате для отображения имени logger даст вывод, подобный этому:

WARNING:example_logger:This is a warning

Опять же, в отличие от корневого logger, пользовательский logger нельзя настроить с помощью basicConfig(). Вы должны настроить его с помощью Handlers и Formatters:

Использование Handlers

Обработчики используются, когда вы хотите настроить свои собственные logger и предназначены для отправки сообщений в сконфигурированные места назначения мест, такие как стандартный поток вывода или файл или HTTP, или на вашу электронную почту через SMTP.

У созданного вами logger может быть несколько обработчиков, а это значит, что вы можете настроить его на сохранение в файл журнала, а также на отправку по электронной почте.

Подобно logger, вы также можете установить уровень severity в обработчиках. Это полезно, если вы хотите установить несколько обработчиков для одного и того же logger, но хотите иметь разные уровни severity для каждого из них. Например, вы можете захотеть, чтобы журналы с уровнем WARNING и выше регистрировались на консоли, но все с уровнем ERROR и выше также должно быть сохранены в файл. Вот пример кода, который делает это:

# logging_example.py

import logging

# Create a custom logger
logger = logging.getLogger(__name__)

# Create handlers
c_handler = logging.StreamHandler()
f_handler = logging.FileHandler('file.log')
c_handler.setLevel(logging.WARNING)
f_handler.setLevel(logging.ERROR)

# Create formatters and add it to handlers
c_format = logging.Formatter('%(name)s - %(levelname)s - %(message)s')
f_format = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
c_handler.setFormatter(c_format)
f_handler.setFormatter(f_format)

# Add handlers to the logger
logger.addHandler(c_handler)
logger.addHandler(f_handler)

logger.warning('This is a warning')
logger.error('This is an error')

__main__ - WARNING - This is a warning
__main__ - ERROR - This is an error

Здесь logger.warning() создает LogRecord, который содержит всю информацию о событии, и передает ее всем имеющимся обработчикам: c_handler и f_handler.

c_handler является StreamHandler с уровнем WARNING и берет информацию из LogRecord для генерации вывода в указанном формате и выводит его на консоль. f_handler – это FileHandler с уровнем ERROR, и он игнорирует LogRecord, так как его уровень – WARNING.

Когда вызывается logger.error(), c_handler ведет себя точно так же, как и раньше, а f_handler получает LogRecord на уровне ERROR, поэтому он продолжает генерировать вывод точно так же, как c_handler, но вместо вывода на консоль, он записывает сообщение в указанный файл в этом формате:

2018-08-03 16:12:21,723 - __main__ - ERROR - This is an error

Имя logger, соответствующее переменной __name__, записывается как __main__, то есть имя, которое Python присваивает модулю, с которого начинается выполнение. Если этот файл импортируется каким-либо другим модулем, то переменная __name__ будет соответствовать его имени logging_example. Вот как это будет выглядеть:

# run.py

import logging_example

logging_example - WARNING - This is a warning
logging_example - ERROR - This is an error

Другие методы настройки

Вы можете настроить ведение журнала, как показано выше, используя функции модуля и класса или создав файл конфигурации или словарь и загрузив его с помощью fileConfig() или dictConfig() соответственно. Это полезно, если вы хотите часто менять конфигурацию ведения журнала в работающем приложении.

Вот пример файла конфигурации:

[loggers]
keys=root,sampleLogger

[handlers]
keys=consoleHandler

[formatters]
keys=sampleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_sampleLogger]
level=DEBUG
handlers=consoleHandler
qualname=sampleLogger
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=sampleFormatter
args=(sys.stdout,)

[formatter_sampleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

В приведенном выше файле есть два logger, один обработчик и один форматер. После того, как определены их имена, они настраиваются путем добавления слов logger, handler и formatter перед их именами, разделенными подчеркиванием.

Чтобы загрузить этот файл конфигурации, вы должны использовать fileConfig():

import logging
import logging.config

logging.config.fileConfig(fname='file.conf', disable_existing_loggers=False)

# Get the logger specified in the file
logger = logging.getLogger(__name__)

logger.debug('This is a debug message')

2018-07-13 13:57:45,467 - __main__ - DEBUG - This is a debug message

Путь к файлу конфигурации передается в качестве параметра методу fileConfig(), а параметр disable_existing_loggers используется для сохранения или отключения logger, которые присутствуют при вызове функции. По умолчанию установлено значение True, если не упомянуто.

Вот та же конфигурация в формате YAML для подхода с dictionary:

version: 1
formatters:
  simple:
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: simple
    stream: ext://sys.stdout
loggers:
  sampleLogger:
    level: DEBUG
    handlers: [console]
    propagate: no
root:
  level: DEBUG
  handlers: [console]

Пример, который показывает, как загрузить конфигурацию из файла yaml:

import logging
import logging.config
import yaml

with open('config.yaml', 'r') as f:
    config = yaml.safe_load(f.read())
    logging.config.dictConfig(config)

logger = logging.getLogger(__name__)

logger.debug('This is a debug message')

2018-07-13 14:05:03,766 - __main__ - DEBUG - This is a debug message

Заключение

Модуль logging считается очень гибким. Его дизайн очень практичен и должен подходить для любого случая использования. Вы можете добавить базовое ведение логов в небольшой проект или даже создать собственные настраиваемые уровни журналов, классы обработчиков и многое другое, если вы работаете над большим проектом.

Если вы не использовали логирование в своих приложениях до сих пор, сейчас самое время начать. Если все сделаете правильно, ведение логов, несомненно, устранит много проблем как в процессе разработки так и в процессе эксплуатации и поможет вам найти возможности поднять ваше приложение на новый уровень.

Оригинальная статья: Abhinav Ajitsaria Logging in Python

Была ли вам полезна эта статья?

Источник

Создаем простой логгер

Логирование из нескольких модулей (а также форматирование)

Конфигурация логов для работы

Подведем итоги

Зачем нужны логи?

logging и Python

Logger

Handler

Formatter

Filter

LoggerAdapter

extra и не только

Конфигурация logging

Наследование в logging

Отправляем логи в Telegram

Заключение

💌 Присоединяйтесь к рассылке

Концепции Python Logging

Уровни Python Logging

Форматирование лога в Python

Обработчик ведения лога в Python

Python Logger

Эффективный уровень логгера

Рекомендации по работе с Python Logging

Модуль Logging

Базовая конфигурация

Формат вывода

Логирование переменных

Вывод стека

Классы и функции

Использование Handlers

Другие методы настройки

Заключение

Не пропустите эти материалы по теме: