Roundup Tracker - Issues

Issue 2550944

classification
Title: Adjust log levels to have INFO log interesting regular events
Type: Severity: normal
Components: Web interface, Mail interface Versions: devel
process
Status: new Resolution:
Dependencies: Superseder:
Assigned To: Nosy List: ber
Priority: normal Keywords: Effort-Low

Created on 2017-05-10 10:50 by ber, last changed 2017-05-10 10:50 by ber.

Messages
msg5980 Author: [hidden] (ber) Date: 2017-05-10 10:50
Right now in hg5241:092c4522b3bf the logging default level set in
roundup/configuration.py is "ERROR".

This will let some emails vanish via mailgw without trace as INFO would
be needed to get the messages :
  'IgnoreMessage raised (Message-id=%r)'
  'Exception handling message (Message-id=%r)'

And IgnoreMessage does not lead to a bounce.

A sensible default would log what the final destination of messages was,
so INFO seems to be a useful default for mailgw.

On the other hand, there are a number of INFO outputs that should rather
be DEBUG, example of INFO output for an bounced email:

```
2017-05-09 17:30:06,681 INFO Handling message
(Message-id='<201705091730.05372.somebody@example.org>')
2017-05-09 17:30:06,690 INFO open database 'roundup-test'
2017-05-09 17:30:06,783 INFO commit
2017-05-09 17:30:06,799 INFO commit
2017-05-09 17:30:06,802 INFO close
```

So if we check that all INFO log entries are likely to be interesting
in a regular production setup and won't flood the logs, we could switch
the default.

The following grep finds a number of INFO logging places in the code:


grep -r "\.info(" .
./scripts/imapServer.py:        log.info('Adding mailbox %s', mailbox)
./scripts/imapServer.py:            log.info('Connecting to server: %s',
server)
./scripts/imapServer.py:                        log.info('Connecting as
user: %s', user)
./scripts/imapServer.py:                            log.info('Using
mailbox: %s, home: %s',
./scripts/imapServer.py:                            log.info('Found %s
messages', nMessages)
./scripts/imapServer.py:        log.info('Running as Daemon')
./scripts/imapServer.py:            log.info('Time: %s',
time.strftime('%Y-%m-%d %H:%M:%S'))

./roundup/roundupdb.py:        logger.info(msg, *args, **kwargs)
./roundup/mailgw.py:        self.logger.info(msg)
./roundup/mailgw.py:            self.logger.info(msg)
./roundup/backends/back_anydbm.py:       
logging.getLogger('roundup.hyperdb.backend').info('clear')
./roundup/backends/back_anydbm.py:       
logging.getLogger('roundup.hyperdb.backend').info(
./roundup/backends/back_anydbm.py:               
logging.getLogger('roundup.hyperdb.backend').info(
./roundup/backends/back_anydbm.py:       
logging.getLogger('roundup.hyperdb.backend').info('commit %s transactions'%(
./roundup/backends/back_anydbm.py:       
logging.getLogger('roundup.hyperdb.backend').info('rollback %s
transactions'%(
./roundup/backends/rdbms_common.py:        logger.info('update_class
%s'%spec.classname)
./roundup/backends/rdbms_common.py:       
logging.getLogger('roundup.hyperdb.backend').info('clear')
./roundup/backends/rdbms_common.py:       
logging.getLogger('roundup.hyperdb.backend').info('destroynode %s%s'%(
./roundup/backends/rdbms_common.py:       
logging.getLogger('roundup.hyperdb.backend').info('commit')
./roundup/backends/rdbms_common.py:       
logging.getLogger('roundup.hyperdb.backend').info('rollback')
./roundup/backends/rdbms_common.py:       
logging.getLogger('roundup.hyperdb.backend').info('close')
./roundup/backends/back_postgresql.py:   
logging.getLogger('roundup.hyperdb').info(command)
./roundup/backends/back_postgresql.py:   
logging.getLogger('roundup.hyperdb').info(command)
./roundup/backends/back_postgresql.py:       
logging.getLogger('roundup.hyperdb').info(
./roundup/backends/back_postgresql.py:       
logging.getLogger('roundup.hyperdb').info('commit')
./roundup/backends/back_postgresql.py:               
logging.getLogger('roundup.hyperdb').info(
./roundup/backends/back_mysql.py:            logging.info(command)
./roundup/backends/back_mysql.py:    logging.info(command)
./roundup/backends/back_sqlite.py:       
logging.getLogger('roundup.hyperdb').info('open database %r'%db)
./roundup/backends/back_sqlite.py:       
logging.getLogger('roundup.hyperdb').info(
./roundup/dist/command/build_scripts.py:                log.info("would
create %s" % outfile)
./roundup/dist/command/build_scripts.py:            log.info("writing
%s" % outfile)
History
Date User Action Args
2017-05-10 10:50:37bercreate