diff options
Diffstat (limited to 'docs/narr/logging.rst')
| -rw-r--r-- | docs/narr/logging.rst | 468 |
1 files changed, 205 insertions, 263 deletions
diff --git a/docs/narr/logging.rst b/docs/narr/logging.rst index 75428d513..7b60beda9 100644 --- a/docs/narr/logging.rst +++ b/docs/narr/logging.rst @@ -4,327 +4,267 @@ Logging ======= :app:`Pyramid` allows you to make use of the Python standard library -:mod:`logging` module. This chapter describes how to configure logging and -how to send log messages to loggers that you've configured. +:mod:`logging` module. This chapter describes how to configure logging and how +to send log messages to loggers that you've configured. .. warning:: - This chapter assumes you've used a :term:`scaffold` to create a - project which contains ``development.ini`` and ``production.ini`` files - which help configure logging. All of the scaffolds which ship along with - :app:`Pyramid` do this. If you're not using a scaffold, or if you've used - a third-party scaffold which does not create these files, the - configuration information in this chapter may not be applicable. + This chapter assumes you've used our :term:`cookiecutter` to create a project + which contains ``development.ini`` and ``production.ini`` files which help + configure logging. The Pyramid cookiecutter provided by the Pylons Project does + this. If you're not using our cookiecutter, or if you've used a third-party + cookiecutter which does not create these files, the configuration information in + this chapter may not be applicable. + +.. index:: + pair: settings; logging + pair: .ini; logging + pair: logging; configuration .. _logging_config: Logging Configuration --------------------- -A :app:`Pyramid` project created from a :term:`scaffold` is configured to -allow you to send messages to :mod:`Python standard library logging package -<logging>` loggers from within your -application. In particular, the :term:`PasteDeploy` ``development.ini`` and -``production.ini`` files created when you use a scaffold include a basic -configuration for the Python :mod:`logging` package. +A :app:`Pyramid` project created from our :term:`cookiecutter` is configured to allow +you to send messages to :mod:`Python standard library logging package +<logging>` loggers from within your application. In particular, the +:term:`PasteDeploy` ``development.ini`` and ``production.ini`` files created +when you use our cookiecutter include a basic configuration for the Python +:mod:`logging` package. PasteDeploy ``.ini`` files use the Python standard library :mod:`ConfigParser -format <ConfigParser>`; this is the same format used as the Python +format <ConfigParser>`. This is the same format used as the Python :ref:`logging module's Configuration file format <logging-config-fileformat>`. The application-related and logging-related sections in the configuration file can coexist peacefully, and the logging-related sections in the file are used from when you run ``pserve``. -The ``pserve`` command calls the :func:`pyramid.paster.setup_logging` -function, a thin wrapper around the :func:`logging.config.fileConfig` -using the specified ``.ini`` file if it contains a ``[loggers]`` section -(all of the scaffold-generated ``.ini`` files do). ``setup_logging`` reads the -logging configuration from the ini file upon which ``pserve`` was -invoked. +The ``pserve`` command calls the :func:`pyramid.paster.setup_logging` function, +a thin wrapper around the :func:`logging.config.fileConfig` using the specified +``.ini`` file, if it contains a ``[loggers]`` section (all of the +cookiecutter-generated ``.ini`` files do). ``setup_logging`` reads the logging +configuration from the ini file upon which ``pserve`` was invoked. Default logging configuration is provided in both the default -``development.ini`` and the ``production.ini`` file. The logging -configuration in the ``development.ini`` file is as follows: - -.. code-block:: ini - :linenos: - - # Begin logging configuration - - [loggers] - keys = root, {{package_logger}} - - [handlers] - keys = console +``development.ini`` and the ``production.ini`` files. If you use our cookiecutter to generate a Pyramid project with the name of the package as ``hello_world``, then the logging configuration +in the ``development.ini`` file is as follows: - [formatters] - keys = generic - - [logger_root] - level = INFO - handlers = console - - [logger_{{package_logger}}] - level = DEBUG - handlers = - qualname = {{package}} - - [handler_console] - class = StreamHandler - args = (sys.stderr,) - level = NOTSET - formatter = generic - - [formatter_generic] - format = %(asctime)s %(levelname)-5.5s [%(name)s][%(threadName)s] %(message)s - - # End logging configuration +.. literalinclude:: myproject/development.ini + :language: ini + :lineno-match: + :lines: 29- The ``production.ini`` file uses the ``WARN`` level in its logger -configuration, but it is otherwise identical. - -The name ``{{package_logger}}`` above will be replaced with the name of your -project's :term:`package`, which is derived from the name you provide to your -project. For instance, if you do: - -.. code-block:: text - :linenos: - - pcreate -s starter MyApp - -The logging configuration will literally be: - -.. code-block:: ini - :linenos: - - # Begin logging configuration - - [loggers] - keys = root, myapp - - [handlers] - keys = console - - [formatters] - keys = generic - - [logger_root] - level = INFO - handlers = console - - [logger_myapp] - level = DEBUG - handlers = - qualname = myapp - - [handler_console] - class = StreamHandler - args = (sys.stderr,) - level = NOTSET - formatter = generic - - [formatter_generic] - format = %(asctime)s %(levelname)-5.5s [%(name)s][%(threadName)s] %(message)s - - # End logging configuration +configuration instead of ``DEBUG``, but it is otherwise identical. In this logging configuration: -- a logger named ``root`` is created that logs messages at a level above - or equal to the ``INFO`` level to stderr, with the following format: +- a logger named ``root`` is created that logs messages at a level above or + equal to the ``INFO`` level to stderr, with the following format: - .. code-block:: text + .. code-block:: text - 2007-08-17 15:04:08,704 INFO [packagename] - Loading resource, id: 86 + 2007-08-17 15:04:08,704 INFO [packagename] Loading resource, id: 86 -- a logger named ``myapp`` is configured that logs messages sent at a level - above or equal to ``DEBUG`` to stderr in the same format as the root - logger. +- a logger named ``myproject`` is configured that logs messages sent at a level + above or equal to ``DEBUG`` to stderr in the same format as the root logger. The ``root`` logger will be used by all applications in the Pyramid process -that ask for a logger (via ``logging.getLogger``) that has a name which -begins with anything except your project's package name (e.g. ``myapp``). -The logger with the same name as your package name is reserved for your own -usage in your Pyramid application. Its existence means that you can log to a -known logging location from any Pyramid application generated via a scaffold. - -Pyramid and many other libraries (such as Beaker, SQLAlchemy, Paste) log a -number of messages to the root logger for debugging purposes. Switching the +that ask for a logger (via ``logging.getLogger``) that has a name which begins +with anything except your project's package name (e.g., ``myproject``). The logger +with the same name as your package name is reserved for your own usage in your +:app:`Pyramid` application. Its existence means that you can log to a known +logging location from any :app:`Pyramid` application generated via our cookiecutter. + +:app:`Pyramid` and many other libraries (such as Beaker, SQLAlchemy, Paste) log +a number of messages to the root logger for debugging purposes. Switching the root logger level to ``DEBUG`` reveals them: -.. code-block:: ini +.. code-block:: ini - [logger_root] - #level = INFO - level = DEBUG - handlers = console + [logger_root] + #level = INFO + level = DEBUG + handlers = console -Some scaffolds configure additional loggers for additional subsystems they -use (such as SQLALchemy). Take a look at the ``production.ini`` and -``development.ini`` files rendered when you create a project from a scaffold. +Some configurations of the :app:`Pyramid` cookiecutter configure additional loggers for +additional subsystems they use (such as SQLAlchemy). Take a look at the +``production.ini`` and ``development.ini`` files rendered when you create a +project from our cookiecutter. Sending Logging Messages ------------------------ Python's special ``__name__`` variable refers to the current module's fully -qualified name. From any module in a package named ``myapp``, the -``__name__`` builtin variable will always be something like ``myapp``, or -``myapp.subpackage`` or ``myapp.package.subpackage`` if your project is named -``myapp``. Sending a message to this logger will send it to the ``myapp`` +qualified name. From any module in a package named ``myproject``, the ``__name__`` +builtin variable will always be something like ``myproject``, or +``myproject.subpackage`` or ``myproject.package.subpackage`` if your project is named +``myproject``. Sending a message to this logger will send it to the ``myproject`` logger. To log messages to the package-specific logger configured in your ``.ini`` file, simply create a logger object using the ``__name__`` builtin and call methods on it. -.. code-block:: python +.. code-block:: python :linenos: - import logging - log = logging.getLogger(__name__) + import logging + log = logging.getLogger(__name__) def myview(request): - content_type = 'text/plain' - content = 'Hello World!' - log.debug('Returning: %s (content-type: %s)', content, content_type) - request.response.content_type = content_type + content_type = 'text/plain' + content = 'Hello World!' + log.debug('Returning: %s (content-type: %s)', content, content_type) + request.response.content_type = content_type return request.response -This will result in the following printed to the console, on ``stderr``: +This will result in the following printed to the console, on ``stderr``: -.. code-block:: text +.. code-block:: text - 16:20:20,440 DEBUG [myapp.views] Returning: Hello World! - (content-type: text/plain) + 16:20:20,440 DEBUG [myproject.views] Returning: Hello World! + (content-type: text/plain) Filtering log messages ---------------------- -Often there's too much log output to sift through, such as when switching -the root logger's level to ``DEBUG``. +Often there's too much log output to sift through, such as when switching the +root logger's level to ``DEBUG``. -An example: you're diagnosing database connection issues in your application +For example, you're diagnosing database connection issues in your application and only want to see SQLAlchemy's ``DEBUG`` messages in relation to database connection pooling. You can leave the root logger's level at the less verbose ``INFO`` level and set that particular SQLAlchemy logger to ``DEBUG`` on its own, apart from the root logger: -.. code-block:: ini +.. code-block:: ini - [logger_sqlalchemy.pool] - level = DEBUG - handlers = - qualname = sqlalchemy.pool + [logger_sqlalchemy.pool] + level = DEBUG + handlers = + qualname = sqlalchemy.pool -then add it to the list of loggers: +then add it to the list of loggers: -.. code-block:: ini +.. code-block:: ini - [loggers] - keys = root, myapp, sqlalchemy.pool + [loggers] + keys = root, myproject, sqlalchemy.pool -No handlers need to be configured for this logger as by default non root -loggers will propagate their log records up to their parent logger's -handlers. The root logger is the top level parent of all loggers. +No handlers need to be configured for this logger as by default non-root +loggers will propagate their log records up to their parent logger's handlers. +The root logger is the top level parent of all loggers. This technique is used in the default ``development.ini``. The root logger's level is set to ``INFO``, whereas the application's log level is set to ``DEBUG``: -.. code-block:: ini +.. code-block:: ini - # Begin logging configuration + # Begin logging configuration - [loggers] - keys = root, myapp + [loggers] + keys = root, myproject - [logger_myapp] - level = DEBUG - handlers = - qualname = helloworld + [logger_myproject] + level = DEBUG + handlers = + qualname = myproject -All of the child loggers of the ``myapp`` logger will inherit the ``DEBUG`` -level unless they're explicitly set differently. Meaning the ``myapp.views``, -``myapp.models`` (and all your app's modules') loggers by default have an +All of the child loggers of the ``myproject`` logger will inherit the ``DEBUG`` +level unless they're explicitly set differently. Meaning the ``myproject.views``, +``myproject.models``, and all your app's modules' loggers by default have an effective level of ``DEBUG`` too. -For more advanced filtering, the logging module provides a `Filter -<http://docs.python.org/lib/node423.html>`_ object; however it cannot be used -directly from the configuration file. +For more advanced filtering, the logging module provides a +:class:`logging.Filter` object; however it cannot be used directly from the +configuration file. -Advanced Configuration +Advanced Configuration ---------------------- -To capture log output to a separate file, use a `FileHandler -<http://docs.python.org/lib/node412.html>`_ (or a `RotatingFileHandler -<http://docs.python.org/lib/node413.html>`_): +To capture log output to a separate file, use :class:`logging.FileHandler` (or +:class:`logging.handlers.RotatingFileHandler`): -.. code-block:: ini +.. code-block:: ini - [handler_filelog] - class = FileHandler - args = ('%(here)s/myapp.log','a') - level = INFO - formatter = generic + [handler_filelog] + class = FileHandler + args = ('%(here)s/myproject.log','a') + level = INFO + formatter = generic -Before it's recognized, it needs to be added to the list of handlers: +Before it's recognized, it needs to be added to the list of handlers: -.. code-block:: ini +.. code-block:: ini - [handlers] - keys = console, myapp, filelog + [handlers] + keys = console, myproject, filelog -and finally utilized by a logger. +and finally utilized by a logger. -.. code-block:: ini +.. code-block:: ini - [logger_root] - level = INFO + [logger_root] + level = INFO handlers = console, filelog -These final 3 lines of configuration directs all of the root logger's output -to the ``myapp.log`` as well as the console. +These final three lines of configuration direct all of the root logger's output +to the ``myproject.log`` as well as the console. Logging Exceptions ------------------ -To log (or email) exceptions generated by your :app:`Pyramid` application, -use the :term:`pyramid_exclog` package. Details about its configuration are -in its `documentation -<http://docs.pylonsproject.org/projects/pyramid_exclog/dev/>`_. +To log or email exceptions generated by your :app:`Pyramid` application, use +the :term:`pyramid_exclog` package. Details about its configuration are in its +`documentation +<https://docs.pylonsproject.org/projects/pyramid_exclog/en/latest/>`_. -Request Logging with Paste's TransLogger +.. index:: + single: TransLogger + single: middleware; TransLogger + pair: configuration; middleware + single: settings; middleware + pair: .ini; middleware + +.. _request_logging_with_pastes_translogger: + +Request Logging with Paste's TransLogger ---------------------------------------- -Paste provides the `TransLogger -<http://pythonpaste.org/modules/translogger.html>`_ :term:`middleware` for -logging requests using the `Apache Combined Log Format -<http://httpd.apache.org/docs/2.2/logs.html#combined>`_. TransLogger combined -with a FileHandler can be used to create an ``access.log`` file similar to -Apache's. +The :term:`WSGI` design is modular. Waitress logs error conditions, debugging +output, etc., but not web traffic. For web traffic logging, Paste provides the +`TransLogger <https://web.archive.org/web/20160707041338/http://pythonpaste.org:80/modules/translogger.html>`_ +:term:`middleware`. TransLogger produces logs in the `Apache Combined Log +Format <http://httpd.apache.org/docs/2.2/logs.html#combined>`_. But +TransLogger does not write to files; the Python logging system must be +configured to do this. The Python :class:`logging.FileHandler` logging handler +can be used alongside TransLogger to create an ``access.log`` file similar to +Apache's. Like any standard :term:`middleware` with a Paste entry point, TransLogger can -be configured to wrap your application using ``.ini`` file syntax. First, +be configured to wrap your application using ``.ini`` file syntax. First rename your Pyramid ``.ini`` file's ``[app:main]`` section to -``[app:mypyramidapp]``, then add a ``[filter:translogger]`` section, then use -a ``[pipeline:main]`` section file to form a WSGI pipeline with both the +``[app:mypyramidapp]``, then add a ``[filter:translogger]`` section, then use a +``[pipeline:main]`` section file to form a WSGI pipeline with both the translogger and your application in it. For instance, change from this: -.. code-block:: ini +.. code-block:: ini [app:main] - use = egg:MyProject + use = egg:myproject To this: -.. code-block:: ini +.. code-block:: ini [app:mypyramidapp] - use = egg:MyProject + use = egg:myproject - [filter:translogger] - use = egg:Paste#translogger + [filter:translogger] + use = egg:Paste#translogger setup_console_handler = False [pipeline:main] @@ -335,82 +275,84 @@ Using PasteDeploy this way to form and serve a pipeline is equivalent to wrapping your app in a TransLogger instance via the bottom of the ``main`` function of your project's ``__init__`` file: -.. code-block:: python +.. code-block:: python - ... + # ... app = config.make_wsgi_app() - from paste.translogger import TransLogger - app = TransLogger(app, setup_console_handler=False) - return app + from paste.translogger import TransLogger + app = TransLogger(app, setup_console_handler=False) + return app -TransLogger will automatically setup a logging handler to the console when -called with no arguments, so it 'just works' in environments that don't -configure logging. Since we've configured our own logging handlers, we need -to disable that option via ``setup_console_handler = False``. +.. note:: + TransLogger will automatically setup a logging handler to the console when + called with no arguments, so it "just works" in environments that don't + configure logging. Since our logging handlers are configured, we disable + the automation via ``setup_console_handler = False``. With the filter in place, TransLogger's logger (named the ``wsgi`` logger) will -propagate its log messages to the parent logger (the root logger), sending -its output to the console when we request a page: +propagate its log messages to the parent logger (the root logger), sending its +output to the console when we request a page: -.. code-block:: text +.. code-block:: text - 00:50:53,694 INFO [myapp.views] Returning: Hello World! - (content-type: text/plain) + 00:50:53,694 INFO [myproject.views] Returning: Hello World! + (content-type: text/plain) 00:50:53,695 INFO [wsgi] 192.168.1.111 - - [11/Aug/2011:20:09:33 -0700] "GET /hello - HTTP/1.1" 404 - "-" - "Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.6) Gecko/20070725 - Firefox/2.0.0.6" + HTTP/1.1" 404 - "-" + "Mozilla/5.0 (Macintosh; U; Intel macOS; en-US; rv:1.8.1.6) Gecko/20070725 + Firefox/2.0.0.6" -To direct TransLogger to an ``access.log`` FileHandler, we need to add that -FileHandler to the list of handlers (named ``accesslog``), and ensure that the -``wsgi`` logger is configured and uses this handler accordingly: +To direct TransLogger to an ``access.log`` FileHandler, we need the following +to add a FileHandler (named ``accesslog``) to the list of handlers, and ensure +that the ``wsgi`` logger is configured and uses this handler accordingly: -.. code-block:: ini +.. code-block:: ini - # Begin logging configuration + # Begin logging configuration [loggers] - keys = root, myapp, wsgi + keys = root, myproject, wsgi [handlers] keys = console, accesslog - [logger_wsgi] - level = INFO - handlers = handler_accesslog - qualname = wsgi - propagate = 0 - - [handler_accesslog] - class = FileHandler - args = ('%(here)s/access.log','a') - level = INFO - formatter = generic - -As mentioned above, non-root loggers by default propagate their log records -to the root logger's handlers (currently the console handler). Setting -``propagate`` to ``0`` (``False``) here disables this; so the ``wsgi`` logger + [logger_wsgi] + level = INFO + handlers = accesslog + qualname = wsgi + propagate = 0 + + [handler_accesslog] + class = FileHandler + args = ('%(here)s/access.log','a') + level = INFO + formatter = generic + +As mentioned above, non-root loggers by default propagate their log records to +the root logger's handlers (currently the console handler). Setting +``propagate`` to ``0`` (``False``) here disables this; so the ``wsgi`` logger directs its records only to the ``accesslog`` handler. Finally, there's no need to use the ``generic`` formatter with TransLogger as -TransLogger itself provides all the information we need. We'll use a -formatter that passes-through the log messages as is. Add a new formatter -called ``accesslog`` by include the following in your configuration file: +TransLogger itself provides all the information we need. We'll use a formatter +that passes through the log messages as is. Add a new formatter called +``accesslog`` by including the following in your configuration file: -.. code-block:: ini +.. code-block:: ini - [formatters] - keys = generic, accesslog + [formatters] + keys = generic, accesslog - [formatter_accesslog] - format = %(message)s + [formatter_accesslog] + format = %(message)s -Then wire this new ``accesslog`` formatter into the FileHandler: +Finally alter the existing configuration to wire this new ``accesslog`` +formatter into the FileHandler: -.. code-block:: ini +.. code-block:: ini - [handler_accesslog] - class = FileHandler - args = ('%(here)s/access.log','a') - level = INFO - formatter = accesslog + [handler_accesslog] + class = FileHandler + args = ('%(here)s/access.log','a') + level = INFO + formatter = accesslog |