Merge remote-tracking branch 'refs/remotes/Pylons/master'

1 files changed, 430 insertions, 0 deletions

diff --git a/docs/narr/logging.rst b/docs/narr/logging.rst
new file mode 100644
index 000000000..9c6e8a319
--- /dev/null
+++ b/docs/narr/logging.rst
@@ -0,0 +1,430 @@
+.. _logging_chapter:
+
+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.
+
+.. 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 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.
+
+.. 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.
+
+PasteDeploy ``.ini`` files use the Python standard library :mod:`ConfigParser
+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.
+
+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
+
+   [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
+
+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
+
+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:
+
+  .. code-block:: text
+
+     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.
+
+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
+:app:`Pyramid` application.  Its existence means that you can log to a known
+logging location from any :app:`Pyramid` application generated via a scaffold.
+
+: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
+
+    [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.
+
+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``
+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
+    :linenos:
+
+    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
+        return request.response
+
+This will result in the following printed to the console, on ``stderr``:
+
+.. code-block:: text
+
+    16:20:20,440 DEBUG [myapp.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``.
+
+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
+
+    [logger_sqlalchemy.pool]
+    level = DEBUG
+    handlers =
+    qualname = sqlalchemy.pool
+
+then add it to the list of loggers:
+
+.. code-block:: ini
+
+    [loggers]
+    keys = root, myapp, 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.
+
+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
+
+    # Begin logging configuration
+
+    [loggers]
+    keys = root, myapp
+
+    [logger_myapp]
+    level = DEBUG
+    handlers =
+    qualname = myapp
+
+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
+effective level of ``DEBUG`` too.
+
+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
+----------------------
+
+To capture log output to a separate file, use :class:`logging.FileHandler` (or
+:class:`logging.handlers.RotatingFileHandler`):
+
+.. code-block:: ini
+
+    [handler_filelog]
+    class = FileHandler
+    args = ('%(here)s/myapp.log','a')
+    level = INFO
+    formatter = generic
+
+Before it's recognized, it needs to be added to the list of handlers:
+
+.. code-block:: ini
+
+    [handlers]
+    keys = console, myapp, filelog
+
+and finally utilized by a logger.
+
+.. code-block:: ini
+
+    [logger_root]
+    level = INFO
+    handlers = console, filelog
+
+These final three lines of configuration direct all of the root logger's output
+to the ``myapp.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/>`_.
+
+.. 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
+----------------------------------------
+
+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 <http://pythonpaste.org/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
+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
+translogger and your application in it.  For instance, change from this:
+
+.. code-block:: ini
+
+    [app:main]
+    use = egg:MyProject
+
+To this:
+
+.. code-block:: ini
+
+    [app:mypyramidapp]
+    use = egg:MyProject
+
+    [filter:translogger]
+    use = egg:Paste#translogger
+    setup_console_handler = False
+
+    [pipeline:main]
+    pipeline = translogger
+               mypyramidapp
+
+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
+
+    ...
+    app = config.make_wsgi_app()
+    from paste.translogger import TransLogger
+    app = TransLogger(app, setup_console_handler=False)
+    return app
+
+.. 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:
+
+.. code-block:: text
+
+    00:50:53,694 INFO [myapp.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"
+
+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
+
+    # Begin logging configuration
+
+    [loggers]
+    keys = root, myapp, wsgi
+
+    [handlers]
+    keys = console, accesslog
+
+    [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 including the following in your configuration file:
+
+.. code-block:: ini
+
+    [formatters]
+    keys = generic, accesslog
+
+    [formatter_accesslog]
+    format = %(message)s
+
+Finally alter the existing configuration to wire this new ``accesslog``
+formatter into the FileHandler:
+
+.. code-block:: ini
+
+    [handler_accesslog]
+    class = FileHandler
+    args = ('%(here)s/access.log','a')
+    level = INFO
+    formatter = accesslog