About logging¶

We are going to play in the min1 demo project:

>>> from atelier.sheller import Sheller
>>> shell = Sheller('lino_book/projects/min1')

The demo sites have no log directory and hence no lino.log file. Logging messages go only to the console (and to the ADMIN_EMAILS when an error occurs)

>>> shell("ls log")
ls: cannot access 'log': No such file or directory

>>> shell("python manage.py prep --noinput")
... 
`initdb std demo demo2` started on database .../min1/default.db.
...
Installed 199 object(s) from 7 fixture(s)

For the following snippets we temporarily enable file logging in the min1 demo site by creating a log directory.

>>> shell("mkdir log")

>>> shell("python manage.py prep --noinput")
... 
Started manage.py prep --noinput (using lino_book.projects.min1.settings) --> PID ...
`initdb std demo demo2` started on database .../min1/default.db.
...
Done manage.py prep --noinput (PID ...)

>>> shell("ls log")
lino.log

>>> shell("cat log/lino.log")
... 
2... INFO [lino ...] : Started manage.py prep --noinput (using lino_book.projects.min1.settings) --> PID ...
2... INFO [lino ...] : `initdb std demo demo2` started on database .../min1/default.db.
2...
2... INFO [lino ...] : Done manage.py prep --noinput (PID ...)

When there is a log directory, the Lino logger will log to the lino.log file as well.

The log server ¶

In a production environment you can have multiple processes running on a same site at the same time, which can lead to conflicts when these processes write to the lino.log file. that's why we also have a log server

log server¶: A background process used when multiple processes need to write to a same lino.log file on a production site.

When a socket file exists (a file named lino.log.sock in the log directory), then Lino assumes that you have a log server running who is responsible for writing to the lino.log file.

The following snippet demonstrates an edge case: we simulate a log server by creating a fake socket file.

>>> shell("rm log/lino.log")

>>> shell("touch log/lino.log.sock")

The process then "blindly" sends log records to that socket, without asking whether the server actually runs:

>>> shell("python manage.py prep --noinput")
... 
Started manage.py prep --noinput (using lino_book.projects.min1.settings) --> PID ...
...

But since in our case no log server is actually running, the lino.log file has not been written (only the socket file is there):

>>> shell("ls log")
lino.log.sock

Tidy up and remove all traces:

>>> shell("rm log/lino.log.sock")

>>> shell("rmdir log")

Relation between logging level and verbosity¶

The relation between logging level and verbosity is not yet clear.

You can set LINO_LOGLEVEL to "WARNING" in order to get rid of quite some messages:

>>> import os
>>> env = dict()
>>> env.update(os.environ)
>>> env.update(LINO_LOGLEVEL="WARNING")
>>> shell("python manage.py prep --noinput", env=env)
... 
No changes detected
Operations to perform:
  Synchronize unmigrated apps: about, bootstrap3, contacts, countries, extjs, jinja, lino, office, printing, staticfiles, system, users, xl
  Apply all migrations: sessions
Synchronizing apps without migrations:
  Creating tables...
    Creating table system_siteconfig
    Creating table users_user
    Creating table users_authority
    Creating table countries_country
    Creating table countries_place
    Creating table contacts_partner
    Creating table contacts_person
    Creating table contacts_companytype
    Creating table contacts_company
    Creating table contacts_roletype
    Creating table contacts_role
    Running deferred SQL...
Running migrations:
  Applying sessions.0001_initial... OK
Installed 199 object(s) from 7 fixture(s)

Setting LINO_LOGLEVEL to "WARNING" does not remove messages issued by Django because Django does not use the logging system to print these messages. To get rid of these messages as well, you can set verbosity to 0:

>>> shell("python manage.py prep --noinput -v0", env=env)
... 

About logging in a development environment¶

Showing SQL statements¶

The default logging level for the django.db.backends handler is WARNING. You can change this default value by setting the LINO_SQL_LOGLEVEL variable.

LINO_SQL_LOGLEVEL¶: The logging level to set for the django.db.backends handler instead of the default value WARNING.

The Lino logger¶

This is a tested document. The following instructions are used for initialization:

>>> from lino import startup
>>> startup('lino_book.projects.noi1e.settings.demo')
>>> from lino.api.doctest import *

>>> from lino import logger
>>> logger.handlers
[<StreamHandler (INFO)>, <AdminEmailHandler (ERROR)>]
>>> logger.info("Hello, world!")
Hello, world!
>>> logger.debug("Foolish humans trying to understand me")