This is an overview, and a quick entry-by-example for (potential) rrlog users. It doesn't cover everything. For all features available, you may need to browse the → index
The rrlog is a pure Python logging tool. It is indended for both debugging and production, while the focus is somewhat more on debugging features. It supports Out-Of-The-Box:
Where it sucks
There are at least the following caveats:When using database logging, the SQLAlchemy library is required. When logging into text files only, SQLAlchemy is not required.
Tested environment:
Only this environment is tested. There's still a wider range of versions expected to work:
SQLAlchemy: all >= 0.3.2
Python: all from 2.3 to 2.6.
If something of this "supported version range" is broken, please [Report bugs] and I'll try to fix. (Or mail a patch).
Philosophy statement: The rrlog is intended to be compatible with a passably wide range of versions (both Python and SQLAlchemy) to minimize dependency problems. The minimum version of Python will remain 2.3 as long as maintainable with reasonable effort. (Your SQLAlchemy version may come with stricter requirements, e.g. SA0.5 requires Python >=2.4.)
Python 3(000): The rrlog won't be fully functional with Python 3 until SQLAlchemy does (0.6 is expected to support it). (And MySQL users have to wait for python-MySQLdb, too.) When database logging is not required, you may already try the experimental lib3k/ directory (instead of lib/).
You always create a "log" object using a "create...() function".There are different create functions, depending on which log configuration you need, e.g. locally or remotely, into a file or a database ...etc...
These create functions are shown by examples in the Logging ... chapter.
The resulting log object is callable, and takes usually ...
Example:
log("Uuups!","E")
where the category "E" is interpreted by you (resp.your application); by convention, it indicates an Error.
[all log() arguments]Optional custom keyword arguments can be provided, along with optional custing output formatting.
The log object can be used instantly which is very suitable with small and ad-hoc code. With large applications, you probably want to use the Python standard logging framework. Therefore, the log can be registered as a logging handler.
There are more parameters and customizations. These are mainly about text line formatting,database column configuration,rotation policies and debug features.
Log into standard out, as print would do (but with more options).
from rrlog.server.printwriter import createLocalLog # local == non-remote log = createLocalLog() # now, log some lines: for i in range(0,25): log("Dear log reader, this is line #%s"%(i))→ rrlog.server.printwriter-module
Log rotating into 3 files, each with 10 lines max. (files in the working directory can be overwritten.)
from rrlog.server.filewriter import createLocalLog # local == non-remote log = createLocalLog( filePathPattern="./demo-log-%s.txt", # "pattern" because %s (or %d) is required for the rotate-number rotateCount=3, # rotate over 3 files rotateLineMin=10, #at least 10 lines in each file before rotating ) # now, log some lines: for i in range(0,25): log("usingFiles:Dear log reader, this is line #%s"%(i))→ rrlog.server.filewriter-module
Log rotating into 3 tables, each with 10 lines max. (Tables are overwritten.)
from rrlog.server.dbwriter_sa import createLocalLog # local == non-remote # This is a RFC-1738 style URL, as required by SQLAlchemy. # It includes in this order: # the database type (e.g.mysql,postgres,sqlite...) # the database user (that has write permission) # the database name (here: "logtest") # See SQLAlchemy Doc for a more accurate and up-to-date description. engineStr = "mysql://logtester@localhost/logtest" log = createLocalLog( engineStr = engineStr, tableNamePattern = "logtable_%s", # "pattern" because %s (or %d) is required for the rotate-number rotateCount = 3, # rotate over 3 tables rotateLineMin = 10, # at least 10 lines in each table before rotating ) # now, log some lines: for i in range(0,25): log("usingDatabase: this is line #%s"%(i))→ rrlog.server.dbwriter_sa-module
Remote logging is intended to log on a remote machine, or, which may be the most common use, to write the same file/table(s) with multiple processes. All processes, or a part of them, can reside on the same machine. Check also these sections:
This requires two create* calls, one to start a server, the other for the client inside your application. Most parameters are now found in the server create* function, e.g. the rotation parameters. Client and server connect using one common port, or using a sequence of ports. In the latter case, the server uses the first free port of the sequence, while the clients uses the first port where a server is found.
# First, create a pure print server: # (this is independent from the connection type, like XMLRPC) from rrlog.server.printwriter import createServer logServer = createServer() # Start the server as an XMLRPC server: from rrlog.server.xmlrpc import startServer startServer( logServer, ports=(8000, 8001, 8002), # try ports in this order, use the first one that is available. host="localhost", ) # Now, the server should be waiting for requests.→ rrlog.server.xmlrpc-module , → rrlog.server.printwriter-module
# First, create a pure file-writing server: # (this is independent from the connection type, like XMLRPC) from rrlog.server.filewriter import createRotatingServer logServer = createRotatingServer( filePathPattern = "./demolog_%s.txt", # "pattern" because %s (or %d) is required for the rotate-number rotateCount=3, rotateLineMin=10, ) # Start the server as an XMLRPC server: from rrlog.server.xmlrpc import startServer startServer( logServer, ports=(8000, 8001, 8002), # try ports in this order, use the first one that is available. host="localhost", ) # Now, the server should be waiting for requests.→ rrlog.server.xmlrpc-module , → rrlog.server.filewriter-module
# First, create a pure database-writing server: # (this is independent from the connection type, like XMLRPC) from rrlog.server.dbwriter_sa import createRotatingServer engineStr = "mysql://logtester@localhost/logtest" logServer = createRotatingServer( engineStr = engineStr, tableNamePattern = "logtable_%s", # "pattern" because %s (or %d) is required for the rotate-number rotateCount=3, rotateLineMin=10, tsFormat="std1", # Timestamp format: std1 is shorthand for the strftime-format "%H:%M.%S;%3N" ) # Start the server as an XMLRPC server: from rrlog.server.xmlrpc import startServer startServer( logServer, ports=(8000, 8001, 8002), # try ports in this order, use the first one that is available. host="localhost", ) # Now, the server should be waiting for requests.→ rrlog.server.xmlrpc-module , → rrlog.server.dbwriter_sa-module
Create a logging client, and logs on an already-running server. (Start some server before, as shown above.)
from rrlog.xmlrpc import createClientLog log = createClientLog( host="localhost", ports=(8000, 8001, 8002), # use the first port that seems to belong to a running log server. errorHandler="stderr", # Prints any logging problem to Stderr. see handling of logging errors. ) # now, log some lines: for i in range(0,25): log("Dear log reader, this is xmlrpc-logged line #%s"%(i))→ rrlog.xmlrpc-module
You can register the log as a handler, and use the Python logging system as usual.
# "log" is the callable object we made as usual. # Lets register it as a logging handler: import logging logger = logging.getLogger("Demo") logger.setLevel(logging.WARNING) logger.addHandler(log.logging23_handler()) # now we can use the standard logging.Now it should already work, but there appear ugly lines in the logged stack path always. In fact, the logging frameworks source will occupy most of the stacktrace - but is not interesting in most cases. You can hide it:
# we create a log as usual, e.g. for file logging: from rrlog.server.filewriter import createLocalLog # local == non-remote from rrlog.logging23 import seFilesExclude # Note: the OPTIONAL traceOffset skips the standard-logging-code from logged stacktraces # Required value may depend on Python version! If given, seFilesExcluded is redundant.See manual. log = createLocalLog( filePathPattern="./demo-log-%s.txt", # "pattern" because %s (or %d) is required for the rotate-number rotateCount=3, # rotate over 3 files rotateLineMin=10, #at least 10 lines in each file before rotating seFilesExclude=seFilesExclude, # optional, remove all "logging.__init__" from logged stack path # traceOffset=5, # optional, value fits with Python2.5 stackMax=20, )
This will remove all the "logging.__init__" - lines from the logged stack path: [See seFilesExclude parameter in → rrlog.Log.__init__]
As an alternative, you can adjust the stack logging so that the calls inside the logging module are omitted, see stackMax in the example, or see: Stack Trace logging This is perfectly OK but the drawback is that stackMax needs to fit the number of calls in the logging module, and this value could change with another Python environment.
A small drawback of the logging module is that our message categories are limited now to ordered integer (the LEVELS as used by the logging package.). The category values mapped to the logging LEVEL constants are in a LEVELMAP ;you may modify the map.While this is a limitation, in turn we gain some degrees of freedom because the logging packages allows to easily register a lot of separate handlers.
When your log was added as a Handler, you still may continue to use the log directly. There's (at least no technical) reason against mixing pure rrlog and logging calls in an application.
Note that while the Python logging is designed for thread safety, the rrlog is not. Features
→ rrlog.logging23-module
Generally, the log is designed with multiple processes in mind, but not multiple threads. But with multiple processes, there's not much the log can/should do automatically.
If your processes arise by forking, you need to create the logs after forking (and if required, the parent process may use another log before forking.)
These logs can still write into the same files/tables; use remote logging for that purpose. Generally, remote logging with a single log server is the preferred way for multiple processes. As long as a fast (XMLRPC free) remote logging implementation is pending, this is for low traffic or development only.
If not logging remotely, provide a separate file/table name pattern (resp.directory/database name) for each process, e.g. by including the process id.
Strictly speaking, it is not generally impossible to let multiple processes write the same file. But, contrary to database tables, this may fail occasionally, depending on your operating system. More important, in a productive environment we need rotation - but different processes trying to control the same rotation would fail (and cause data loss.)
(Yes, there are ideas to implement safe rotation for multiple processes with the same ressources. But these all would require a speed impact and an additional file/table, so probably none of them will be implemented. That's why, instead, fast remote logging (without XMLRPC) will be added.)
Still need it with Threads ??
It would be nice to use the same log object shared by multiple threads; but currently, the log is not designed and tested for multithreading. I see 4 solutions if you need to log from multiple threads:
There is an archiving tool to rescue selected messages from becoming a rotation victim.
The cat archiver creates additional files or DB tables and conserves messages of defined categories. These categories are typically errors and security issues (most apps use the category keys "E" resp."S" for these.)
To archive what may have caused the issue, the archiver can save a number of preceding messages.
The archiver is hooked into the log as an "observer". Example Code:
from rrlog.server.dbwriter_sa import createLocalLog # local == non-remote # This is a RFC-1738 style URL, as required by SQLAlchemy. # It includes in this order: # the database type (e.g.mysql,postgres,sqlite...) # the database user (that has write permission) # the database name (here: "logtest") # See SQLAlchemy Doc for a more accurate and up-to-date description. engineStr = "mysql://logtester@localhost/logtest" # create an archiver instance: from rrlog.contrib.catarch_dbsa import createCatArchiver arch = createCatArchiver( engineStr=engineStr, cats=("E","W"), # Message Categories that we want to archive ) log = createLocalLog( engineStr = engineStr, tableNamePattern = "logtable_%s", # "pattern" because %s (or %d) is required for the rotate-number rotateCount = 3, # rotate over 3 tables rotateLineMin = 10, # at least 10 lines in each table before rotating observers = (arch,) # the Archiver is hooked in as an observer ) # now, log some lines: for i in range(0,25): if i==5: log("usingDatabase_plusCatArchiver: this is a warning in line #%s"%(i),"W") elif i==15: log("usingDatabase_plusCatArchiver: this is an error in line #%s"%(i),"E") else: log("usingDatabase_plusCatArchiver: this is line #%s"%(i)) # Because of the 2 problem messages, the arch tables get some entries.The example above shows how to create an archiver that writes into a database [ → rrlog.contrib.catarch_dbsa.createCatArchiver]
When you have defined custom table columns, you probably want these to appear in the archive table, too. Give the same cols parameter to the archiver [ → rrlog.contrib.catarch_dbsa.createCatArchiver] to see the same columns in your archive.
For archiving into files, we have an analogous creation method ( → rrlog.contrib.catarch_file.createCatArchiver)You can combine archivers as you like. It might be a good idea to log into files for best performance, but use an archiver that writes into a database for easy error analyzing.
If you want to rotate the archive, please have a look into the code of the createCatArchiver method. You can extract the code here, and set the rotateCount and rotateLineMin parameters as required.
Further customization: You can customize how many preceding messages are saved. In case of multiple clients, you can separately set these count for the client that triggered archiving (i.e.you can tell the archiver to save more preceding messages from the "guilty" client, and less from the others.) See → rrlog.contrib.catarch.CatArchiver.__init__ for the minClientArchCount parameter (which is available in the createCatArchiver methods, too.)
The mail module can notify you when messages of selected categories are logged. The messages are buffered and sent bundled; the maximum "collect" time is configurable separate for the categories (e.g. security relevant messages can be configured to be buffered for a short time only.)
→ rrlog.contrib.mail.create_observer_tmtp
Remarks: The mail notifier is bound to the log as observer (see also: Observe and filter the messages )Currently, SMTP only is implemented. todo:sendmail
Hint for a common case: When using an archiver, you can also bind the mail notifier as an observer there, instead to the main log server.
The difference is not only that the categories are not specified again. (To catch every category, specify a single "catch-all" mail rule, see → rrlog.contrib.mail.CatRule-class ) The main difference is that you get everything mailed what is archived (eventually too much...) If the archiver is configured to store preceding messages, you'll see even the history of the triggering message in the mails.
This is a debugging feature. Along with each message, a (configurable) part of the stack trace can be logged.
traceOffset: You can adjust the start point of the stack path. By default, the path starts with the line of the application doing the log() call.
But assume you put a wrapper around your log() call, e.g. because you add the current process-id into every log call. This will work well but every stack path begins with that wrapper function now. That's really not interesting for you.
Increase the traceOffset in the create* functions to 1. (Or to 2, if you wrapped your wrapper again and so on.) → rrlog.Log.__init__(There's also a traceDepth parameter in the log call, to adjust the current call only.) → rrlog.Log.__call__
... by line indention: There's a filter already included which indents each line depending on the stack depth. → rrlog.contrib.stackindent-moduleThe filter can be applied with Database logging, too, but certainly looks best with files or standard-out.
Example with standard out:from rrlog.contrib.stackindent import createPrintIndentLog log = createPrintIndentLog(token="++",stackMax=0) # stackMax=0 suppresses filename/line number # log as usual. The first call will "tara" the indention to zero. def egg(): log("egg here") def spam(): log("spam here") #log("did tara=0",stackindent_tara=0) # tara justifies the current indent to be 0 egg() log("begin") spam()Example with files:
from rrlog.server.filewriter import createLocalLog # local == non-remote from rrlog.contrib.stackindent import StackIndentFilter # add a filter while log creation: log = createLocalLog( filePathPattern="./demo-log-%s.txt", tsFormat=None, # no time stamps rotateCount=1, rotateLineMin=None, # no rotation filters=(StackIndentFilter(token="."),), # indent with a dot token ) # log as usual. The first call will "tara" the indention to zero. def egg(): log("egg here") def spam(): log("spam here") #log("did tara=0",stackindent_tara=0) # tara justifies the current indent to be 0 egg() log("begin") spam()
We sometimes want to get rid of a part of out logging output temporarily (e.g. inside a unit test that partially works fine.) There are log.off() and log.on() methods to temporarily disable the log.
You can use your own line format (with both files or Stdout) and add own arguments to the log call. Provide your own formatting method:
from rrlog.server.filewriter import createLocalLog # This demonstrates how you can use your own formatting, # and even ad-hoc add a named argument ("ip") which gets available to your format method. def format_line(job): return "Hey! Read:%s ! And the ip address is:%d !\n"%(job.msg, job.special.get("ip",-1)) # make default -1 when ip is missing log = createLocalLog( format_line=format_line, filePathPattern="./demo-log-%s.txt", # "pattern" because %s (or %d) is required for the rotate-number rotateCount=3, # rotate over 3 files rotateLineMin=10, #at least 10 lines in each file before rotating ) # now, log some lines: for i in range(0,25): log("customizeFiles: line #%s"%(i),ip=12345) log("customizeFiles: This is a line without ip argument.")
For the available attributes of the job, see → rrlog.server.MsgJob-class
There's a default formatting method which may serve as an example:→ rrlog.server.textwriter.default_format_line
You can re-order all columns, or add/insert your own. The names of these new columns can be used as named parameters in the log call.
from rrlog.server.dbwriter_sa import DBConfig,createLocalLog # local == non-remote # This is a RFC-1738 style URL, as required by SQLAlchemy. # It includes in this order: # the database type (e.g.mysql,postgres,sqlite...) # the database user (that has write permission) # the database name (here: "logtest") # See SQLAlchemy Doc for a more accurate and up-to-date description. engineStr = "mysql://logtester@localhost/logtest" log = createLocalLog( engineStr = engineStr, tableNamePattern = "logtable_%s", # "pattern" because %s (or %d) is required for the rotate-number rotateCount = 3, # rotate over 3 tables rotateLineMin = 10, # at least 10 lines in each table before rotating # This adds two new columns, a string and an integer type: # (care for the brackets, we need tuples of two-tuples) cols = DBConfig.COLS_DEFAULT + (("customstring",DBConfig.String(20)),) # String() is unlimited string length + (("custominteger",DBConfig.Integer),), ) # You may do more than just adding columns. # Use COLS_DEFAULT as template for you own colums layout, # e.g. by doing mycols=list(COLS_DEFAULT) # and then re-order columns, or add/insert new ones. # But you need to keep the already defined columns (like "msg") # because the default writer expects them. # If you need completely different columns, you need to override # the writer (which is not covered here, sorry - discover the source code.) # now, log some lines using our custom fields: for i in range(0,25): log("customizeDatabase:",customstring="Here's line %d"%(i),custominteger=i)
You can change the maximum length of string columns (e.g.to allow a longer "msg" column). String(maxlen) optionally takes the maximum length.
You can also modify the format for each single element. See the format_dict argument of the create methods. There's a default formatting method which may serve as an example:→ rrlog.server.dbwriter_sa.default_format_dict
You can modify the time stamp format. The above create* functions take a tsFormat parameter. → rrlog.server.LogServer.__init__ When remote logging, this parameter is found in the server creation function.
The 'Standard Case' is defined to be rotation, along with overwriting of old files/tables.To disable the rotation:
Set rotateLineMin=None in the create* functions. Rotation is switched off, and the file/table is appended forever.
The rotateCount parameter must be set to 1.
You may want to process each log message at log server side (for example with an alarm tool that sends an email when a critical message appears.)
You can add an observer (some callable, or an object with an "observe" method) to the server.
(See parameter 'observers' in the server [→ rrlog.server.LogServer.__init__] for the parameter and the observer protocol. The parameter is also available in the create* functions, see the usage examples.)
There' an analogous "filters" parameter. The difference is, that filters are applied before the job is written, while observers are called afterwards. Thus, the filter can modify the job.
For an observer implementation example, you may look into the archiving tool [→ rrlog.contrib.catarch.CatArchiver-class] which implements the observer protocol.
Logging into a database is expected to be slower than into files since the DB engine has to write with overhead for comfort and safety. A simple benchmark estimates how bad it is:
We write 10000 log messages with pure rrlog (without Python logging framework.) Each message is of 20 characters plus an increasing number. Files are plain text files on the local hard disk, the database is MySQL5/MyISAM. SQLALchemy is v0.4.2. The rrlog flushes the file after each line.
Times are: Files: 0.35 sec, database: 4.4 sec.
The times increase linear as expected (5000 messages take half the time.) As a comparison, an SQLite memory-only database (which is somewhat unusual for a log) takes half the time of MySQL.
=> Database logging can be estimated to be about 10 times slower than pure text files. Of course, runtime performance is not always our worst bottleneck. Direct logging into a database can save working time since we can easy analyse,search,sort and selective-backup without parsing and converting files. So we conclude: Database logging is fine but with high log traffic, we have to go with files only.
XMLRPC remote connection is quickly implemented and stable with all environments. But its performance appears lousy; we can use it with low log traffic only. Measuring with a typical desktop PC (AMD 64 Bit Single Core), and Log Server&Client on the same machine, XMLRPC logging is about 15-25 times slower than non-remote logging. That's why the standard SocketHandler is first choice when remote logging with high traffic is required.
Another significant slowdown is the stacktrace logging feature which is intended for debugging and development; it can slow down logging about 2-3 times, depending on the max size of the stacktraces (For best performance, completely switch off stack extraction: Stack Trace logging)
The messages are ASCII intentionally, since it is fast,small and easy to support with most remote protocols.
Sorry there's no unicode support implemented. For occasional unicode messages, you may use the lu2a* methods in rrlog.tool to "convert" unicode into an ASCII str.
(Once with Python3000, we may start to use unicode in all places.)
XMLRPC is re-using HTTP, which is tolerated by most firewalls. This can become a security issue. When running an XMLRPC logging server, it is a good idea to double check that it cannot be accessed via HTTP from addresses that don't need it.
Furthermore, we have the feature that you can provide multiple ports for server and client(s). This is nice in development (the feature addresses the problem that sometimes ports are not accessible until freed by timeout). In production, you should use a single port only to have better control over the connections going on.
Report bugs to rrlog *at* reifenberg.de
If the address should be outdated, see the home page
or the sourceforge project siteCopyright (c) 2007
Ruben Reifenberg, Germany, 07381.
All rights reserved.
Redistribution and use in source and binary forms, with or without
modification, are permitted provided that the following conditions
are met:
1. Redistributions of source code must retain the above copyright
notice, this list of conditions and the following disclaimer as
the first lines of this file unmodified.
2. Redistributions in binary form must reproduce the above copyright
notice, this list of conditions and the following disclaimer in the
documentation and/or other materials provided with the distribution.
THIS SOFTWARE IS PROVIDED BY Ruben Reifenberg ``AS IS'' AND ANY EXPRESS OR
IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.
IN NO EVENT SHALL Ruben Reifenberg BE LIABLE FOR ANY DIRECT, INDIRECT,
INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT
NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
(INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.