Welcome | Get started | Dive | Contribute | Topics | Reference | Changes | More

About logging

This document explains additional information about logging for developers. We assume that you have read About logging in the Hoster’s Guide.

Overview

Lino’s default logging messages go only to the console and (when an error occurs) to the ADMIN_EMAILS.

When you create a log directory in your project directory, Lino will additionally log to a file lino.log in that directory.

On a production site you probably want to also run a log server.

About logging in a development environment

On my development machine I have a runserver script that does:

set LINO_LOGLEVEL=DEBUG
python manage.py runserver

Logging 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

Lines starting with >>> in this document are code snippets that get tested as part of our development workflow.

>>> 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")

History-aware logging

When Lino is in history-aware logging mode, it logs a message Started %s (using %s) --> PID %s at process startup (and a message Done PID %s at termination).

This kind of messages are usually disturbing for development and testing, but they are interesting for the system administrator of a production site.

The history-aware logging mode is automatically set to True when a logger directory (log) exists in the project directory.

Testing the log directory

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 that is responsible for writing to the lino.log file.

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.

>>> 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 200 object(s) from 8 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 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 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 200 object(s) from 8 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)
...