[SàT dev] Logging and debugging

[Goffi]

G'day,

Logging system has been largely refactored lastly, here are some explanations.
The goal was to use a unique logging system, and as SàT can be used in 
different environments (Twisted, Pyjamas, Urwid, etc), the new logging system 
use backends.

3 backends are available:
	- basic backend, which use print (mainly useful for Pyjamas)
	- twisted backend
	- standard backend which use stantard logging module

The logging system is inspired (and use directly for the standard backend) by 
standard logging module, with some special additions.

logging system use options, which can be configured in 2 ways:
	- either with an environment variable, in the form SAT_LOG_[UPPERCASE 
OPTION NAME], e.g. SAT_LOG_LEVEL=debug
	- or with a configuration option, in the frontend section ("DEFAULT" for 
backend), with log_[lowercase option name] = value, e.g.:
	[primitivus]
	log_level = debug

The available options are as follow:

	- level: logging level (default "info")

	- colors: can be:

		* no: no color at all

		* true: use ANSI colors only if possible (output on a tty)

		* force: always use ANSI colors (can be usefull to log colors in a 
file, to replay when needed)

	- fmt: logging format, as for standard logging (values are formatted as 
for the % operator, e.g. "%(message)s". Available attribute depends on 
backend, but the following ones are always available:

		* name: name of the logger (see below)

		* message: the logged message itself

		* level: logging level (DEBUG, INFO, WARNING, ERROR or CRITICAL)

	- output: where to emit the logs. The syntax is "\\output_type(options)" 
where (options) is not mandatory. If there is only one file backend, a short 
syntax "/path/to/log/file" is used. The available outputs are:

		* \\default: use default logging backend (for Twisted, the one given 
with --logfile, for standard backend it's StreamHandler on stderr)

		* \\file: a file, options is the path (e.g. "\\file(/tmp/sat.log)")

		* \\memory: log are kept in a buffer, options is the limit of logs 
(default 50). Only available for standard backend yet. log.memoryGet is used 
to retrive the logs.

	outputs can be combinated, some examples:

		* "\\default\\file(/tmp/bla.log)": use the default output and the 
/tmp/bla.log file

		* "/tmp/sat.log": use only the /tmp/sat.log file

		* "\\memory\\file(/tmp/toto.log)\\file(/tmp/titi.log)": use memory 
output, and 2 files: /tmp/toto.log and /tmp/titi.log.

	- logger: a regex used to filter on logger name (see below)


Logger:
*******
	at the begining of the module, the log object is instancied as follow:

		from sat.core.log import getLogger
		log = getLogger(__name__)

	That's directly coming from standard logging module. That allow to know 
where the log is comming from. By default this information is not shown, use 
something like SAT_LOG_FMT='[%(name)s] %(message)s' to show it.

	For Twisted backend, if the log is not coming directly from SàT, the 
"twisted" backend is used. If logger is not specify (e.g. a module use 
directly log.debug without getLogger), the "root" logger is used.

	You can filter on logger name, using a regex (with a search not a match, 
i.e. you have to specify "^" to tell "from the beginning of line, and "$" for 
the end). Some example:

		SAT_LOG_LOGGER="(xep_0095|xep_0065)": show only logs coming from 
plugin_xep_0095.py or plugin_xep_0065.py

		SAT_LOG_LOGGER=twisted: show only logs generated by Twisted or an 
other external module, not directly by SàT

		SAT_LOG_LOGGER="^sat.bridge.DBus$": show only logs coming from the 
DBus bridge


Twisted backend:
***************
	For Twisted backend, in debug mode a stdout logging is automaticaly added 
if "\\default" output is set. If you want to use stdout in non daemon mode 
(and if debug is not activated), you have to specify a "-" \\file yourself.

	Also note that before this refactoring, logging in backend was broken, 
and some messages were lost (like debugging informations for Deferred 
failure). Everything should be fixed now.


Primitivus:
*********
	by default Primitivus use a \\memory output. To get the logs, use the 
command ":messages"


Profile:
******
	A magic FMT attribute "profile" is used to add the profile to the log. This 
method use introspection and slow down the logging, it's here to help 
debugging, but DO *NOT* USE IN PRODUCTION. To use it, you can do something 
like:

	SAT_LOG_FMT='[%(name)s {%(profile)s}] %(message)s'


Important to know:
*****************
	Logging methods use only one argument, which can be unicode. You have do 
to any formatting (other that SAT_LOG_FMT formatting) before, using the "%" 
operator or format method.

	If you use unicode, be sure to use the correct unicode string 
(u"something"), or the logging will fail.


recommandations:
*****************
	The default options are alright for production. If you want to develop, 
you can use something like:

	[DEFAULT]
	log_level=debug
	log_fmt="[%(name)s {%(profile)s}] %(message)s"
	
	[primitivus]
	log_level=debug
	log_fmt="%(level)s: %(message)s"
	
	[wix]
	log_level=debug
	log_fmt="[%(name)s] %(message)s"

	New logging system is not yet implemented in jp and Libervia.




Last but not least, I have also made a small modification in the backend to use 
ipdb instead of pdb in debug mode. So if you are developping on the backend, I 
strongly recommand to install ipdb.


Enjoy
Goffi