As of Pylons 0.9.6, Pylons controllers (created via paster
controller/restcontroller) and websetup.py create their own Logger objects
via Python's logging module.
For example, in the helloworld project's hello controller
(helloworld/controllers/hello.py):
1
2
3
4
5
6
7
8
9
10 | import logging
from helloworld.lib.base import *
log = logging.getLogger(__name__)
class HelloController(BaseController):
def index(self):
# Return a...
|
Python's special __name__ variable refers to the current module's fully
qualified name; in this case, helloworld.controllers.hello.
To log messages, simply use methods available on that Logger object:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15 | import logging
from helloworld.lib.base import *
log = logging.getLogger(__name__)
class HelloController(BaseController):
def index(self):
content_type = 'text/plain'
content = 'Hello World!'
log.debug('Returning: %s (content-type: %s)', content, content_type)
response.content_type = content_type
return content
|
Which will result in the following printed to the console, on stderr:
1 | 16:20:20,440 DEBUG [helloworld.controllers.hello] Returning: Hello World! (content-type: text/plain)
|
As of Pylons 0.9.6, the default ini files include a basic configuration for the
logging module. Paste ini files use the Python standard ConfigParser format; the same format used
for the Python logging module's Configuration file format.
paster, when loading an application via the paster serve, shell
or setup-app commands, calls the logging.fileConfig function on that specified ini
file if it contains a 'loggers' entry. logging.fileConfig reads the logging
configuration from a ConfigParser file.
Logging configuration is provided in both the default development.ini and
the production ini file (created via paster make-config <package_name>
<ini_file>). The production ini's logging setup is a little simpler than the
development.ini's, and is as follows:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22 | # Logging configuration
[loggers]
keys = root
[handlers]
keys = console
[formatters]
keys = generic
[logger_root]
level = INFO
handlers = console
[handler_console]
class = StreamHandler
args = (sys.stderr,)
level = NOTSET
formatter = generic
[formatter_generic]
format = %(asctime)s %(levelname)-5.5s [%(name)s] %(message)s
|
One root Logger is created that logs only messages at a level above or equal to
the INFO level to stderr, with the following format:
1 | 2007-08-17 15:04:08,704 INFO [helloworld.controllers.hello] Loading resource, id: 86
|
For those familiar with the logging.basicConfig function, this configuration
is equivalent to the code:
1
2 | logging.basicConfig(level=logging.INFO,
format='%(asctime)s %(levelname)-5.5s [%(name)s] %(message)s')
|
The default development.ini's logging section has a couple of differences:
it uses a less verbose timestamp, and defaults your application's log messages
to the DEBUG level (described in the next section).
Pylons and many other libraries (such as Beaker, SQLAlchemy, Paste) log a number
of messages for debugging purposes. Switching the root Logger level to DEBUG
reveals them:
1
2
3
4 | [logger_root]
#level = INFO
level = DEBUG
handlers = console
|
Often times 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 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:
1
2
3
4 | [logger_sqlalchemy.pool]
level = DEBUG
handlers =
qualname = sqlalchemy.pool
|
then add it to the list of Loggers:
1
2 | [loggers]
keys = root, 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:
1
2
3 | # Logging configuration
[loggers]
keys = root, helloworld
|
1
2
3
4 | [logger_helloworld]
level = DEBUG
handlers =
qualname = helloworld
|
All of the child Loggers of the helloworld Logger will inherit the DEBUG
level unless they're explicitly set differently. Meaning the
helloworld.controllers.hello, helloworld.websetup (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 object; however it cannot be used
directly from the configuration file.
To capture log output to a separate file, use a FileHandler (or a RotatingFileHandler):
1
2
3
4
5 | [handler_accesslog]
class = FileHandler
args = ('access.log','a')
level = INFO
formatter = generic
|
Before it's recognized, it needs to be added to the list of Handlers:
1
2 | [handlers]
keys = console, accesslog
|
and finally utilized by a Logger.
1
2
3 | [logger_root]
level = INFO
handlers = console, accesslog
|
These final 3 lines of configuration directs all of the root Logger's output to
the access.log as well as the console; we'll want to disable this for the next
section.
Paste provides the TransLogger middleware for logging
requests using the Apache Combined Log Format. TransLogger combined
with a FileHandler can be used to create an access.log file similar to
Apache's.
Like any standard middleware with a Paste entry point, TransLogger can be
configured to wrap your application in the [app:main] section of the ini
file:
1
2
3
4
5 | filter-with = translogger
[filter:translogger]
use = egg:Paste#translogger
setup_console_handler = False
|
This is equivalent to wrapping your app in a TransLogger instance via the bottom
of your project's config/middleware.py file:
1
2
3 | 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.
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:
1
2
3 | 00:50:53,694 INFO [helloworld.controllers.hello] Returning: Hello World! (content-type: text/plain)
00:50:53,695 INFO [wsgi] 192.168.1.111 - - [11/Aug/2007: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 the access.log FileHandler defined above, we need
to add that FileHandler to the wsgi Logger's list of Handlers:
1
2
3 | # Logging configuration
[loggers]
keys = root, wsgi
|
1
2
3
4
5 | [logger_wsgi]
level = INFO
handlers = handler_accesslog
qualname = wsgi
propagate = 0
|
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:
1
2 | [formatters]
keys = generic, accesslog
|
1
2 | [formatter_accesslog]
format = %(message)s
|
Then wire this new accesslog Formatter into the FileHandler:
1
2
3
4
5 | [handler_accesslog]
class = FileHandler
args = ('access.log','a')
level = INFO
formatter = accesslog
|
Pylons provides a custom logging Handler class, pylons.log.WSGIErrorsHandler, for
logging output to environ['wsgi.errors']: the WSGI server's error stream
(see the WSGI Spefification, PEP 333 for more
information). wsgi.errors can be useful to log to in certain situations,
such as when deployed under Apache mod_wsgi/mod_python, where the
wsgi.errors stream is the Apache error log.
To configure logging of only ERROR (and CRITICAL) messages to
wsgi.errors, add the following to the ini file:
1
2 | [handlers]
keys = console, wsgierrors
|
1
2
3
4
5 | [handler_wsgierrors]
class = pylons.log.WSGIErrorsHandler
args = ()
level = ERROR
format = generic
|
then add the new Handler name to the list of Handlers used by the root Logger:
1
2
3 | [logger_root]
level = INFO
handlers = console, wsgierrors
|
Warning
WSGIErrorsHandler does not receive log messages created during
application startup. This is due to the wsgi.errors stream only being
available through the environ dictionary; which isn't available until a
request is made.
Java's log4j project provides the Java GUI application Chainsaw for viewing and managing
log messages. Among its features are the ability to filter log messages on the
fly, and customizable color highlighting of log messages.
We can configure Python's logging module to output to a format parsable by
Chainsaw, log4j's XMLLayout
format.
To do so, we first need to install the Python XMLLayout package:
It provides a log Formatter that generates XMLLayout XML. It also provides
RawSocketHandler; like the logging module's SocketHandler, it sends log
messages across the network, but does not pickle them.
The following is an example configuration for sending XMLLayout log messages
across the network to Chainsaw, if it were listening on localhost port 4448:
1
2
3
4
5
6
7
8
9 | [handlers]
keys = console, chainsaw
[formatters]
keys = generic, xmllayout
[logger_root]
level = INFO
handlers = console, chainsaw
|
1
2
3
4
5 | [handler_chainsaw]
class = xmllayout.RawSocketHandler
args = ('localhost', 4448)
level = NOTSET
formatter = xmllayout
|
1
2 | [formatter_xmllayout]
class = xmllayout.XMLLayout
|
This configures any log messages handled by the root Logger to also be sent to
Chainsaw. The default development.ini configures the root Logger to the
INFO level, however in the case of using Chainsaw, it is preferable to
configure the root Logger to NOTSET so all log messages are sent to
Chainsaw. Instead, we can restrict the console handler to the INFO level:
1
2
3
4
5
6
7
8
9 | [logger_root]
level = NOTSET
handlers = console
[handler_console]
class = StreamHandler
args = (sys.stderr,)
level = INFO
formatter = generic
|
Chainsaw can be downloaded from its home page, but can also be launched
directly from a Java-enabled browser via the link: Chainsaw web start.
It can be configured from the GUI, but it also supports reading its
configuration from a log4j.xml file.
The following log4j.xml file configures Chainsaw to listen on port 4448
for XMLLayout style log messages. It also hides Chainsaw's own logging
messages under the WARN level, so only your app's log messages are
displayed:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18 | <?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE configuration>
<configuration xmlns="http://logging.apache.org/">
<plugin name="XMLSocketReceiver" class="org.apache.log4j.net.XMLSocketReceiver">
<param name="decoder" value="org.apache.log4j.xml.XMLDecoder"/>
<param name="port" value="4448"/>
</plugin>
<logger name="org.apache.log4j">
<level value="warn"/>
</logger>
<root>
<level value="debug"/>
</root>
</configuration>
|
Chainsaw will prompt for a configuration file upon startup. The configuration
can also be loaded later by clicking File/Load Log4J File.... You should see
an XMLSocketReceiver instance loaded in Chainsaw's Receiver list, configured at
port 4448, ready to receive log messages.
Here's how the Pylons stack's log messages can look with colors defined (using
Chainsaw on OS X):
Posted by
please note that in order for SQLAlchemy to print it's logging you need to pass in
sqlalchemy.echo = True
in the config file.