CODEWITHSUNDEEP
pythonpython-2.7
WBAR
WBAR

Reputation: 4984

Python logging: FileHandler when in mode 'w' not working but in mode 'a' works fine

In python 2.7.5 under Windows when FileHandler is in mode 'w' (truncate file before writing) handler does NOT write only last line. When in mode 'a' everything is fine.

My logging.conf file:

[loggers]
keys=root

[handlers]
keys=consoleHandler,fileHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=NOTSET
handlers=fileHandler

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)

[handler_fileHandler]
class=FileHandler
level=DEBUG
formatter=simpleFormatter
args=('generator.log', 'a', 'utf8', 0)

[formatter_simpleFormatter]
format=[ %(asctime)s ] [ %(name)s ] [ %(levelname)-5s ] - %(message)s
datefmt=

My oracle.py file:

__author__ = 'wbar'
import cx_Oracle
from contextlib import closing
import logging


class Connector(object):
    __connection__ = None
    __user_name__ = None
    __password__ = None
    __tns_name__ = None
    __logger__ = None

    def get_connection(self, auto_connect=True):
        if auto_connect and not self.__connection__:
            self.__logger__.info(u'Connecting into Oracle: %s@%s', self.__user_name__, self.__tns_name__)
            self.__connection__ = cx_Oracle.connect(
                u'%s/%s@%s' % (self.__user_name__, self.__password__, self.__tns_name__))
        return self.__connection__

    def __init__(self, user_name, password, tns_name):
        self.__user_name__ = user_name
        self.__password__ = password
        self.__tns_name__ = tns_name
        self.__logger__ = logging.getLogger('OracleConnector')
        self.__logger__.addHandler(logging.NullHandler())

    def __del__(self):
        self.close_connection()

    def close_connection(self):
        connection = self.get_connection(auto_connect=False)
        if connection:
            self.__logger__.info(u'Closing connection with Oracle: %s@%s', self.__user_name__, self.__tns_name__)
            connection.close()

    def execute(self, sql):
        with closing(self.get_connection().cursor()) as cursor:
            self.__logger__.debug(u'Executing: %s', sql)
            cursor.execute(sql)
            return cursor.fetchall()

And finally my main file generator.py:

__author__ = 'wbar'
import logging
import logging.config

logging.FileHandler
logging.config.fileConfig('logging.conf')

from oracle import Connector as OracleConnector
DATABASE = OracleConnector(user_name=u'foo', password=u'bar', tns_name=u'db_local')

for line in DATABASE.execute('select * from dual'):
    print(line[0])

logger = logging.getLogger('root')

logger.debug('DEBUG')
logger.info('INFO')
logger.error('ERROR')

When in mode 'a' log file looks like:

[ 2013-11-13 17:15:25,608 ] [ OracleConnector ] [ INFO  ] - Connecting into Oracle: pms_test@db_impaq_local
[ 2013-11-13 17:15:25,727 ] [ OracleConnector ] [ DEBUG ] - Executing: select * from dual
[ 2013-11-13 17:15:25,730 ] [ root ] [ DEBUG ] - DEBUG
[ 2013-11-13 17:15:25,730 ] [ root ] [ INFO  ] - INFO
[ 2013-11-13 17:15:25,730 ] [ root ] [ ERROR ] - ERROR
[ 2013-11-13 17:15:25,734 ] [ OracleConnector ] [ INFO  ] - Closing connection with Oracle: pms_test@db_impaq_local

When in mode 'w' log file looks like:

[ 2013-11-13 17:06:24,239 ] [ OracleConnector ] [ INFO  ] - Closing connection with Oracle: pms_test@db_impaq_local

Upvotes: 3

Views: 14267

Answers (1)

Martijn Pieters
Martijn Pieters

Reputation: 1124238

The logging module registers an atexit shutdown hook closing all handlers. This closes the open 'w' file object when Python exits.

However, your oracle.Connector() class has a __del__ method, which is also called when Python exits. Python calls atexit before globals are cleaned up, so the exact order of operations here is:

  1. logging's atexit hook is called, file is closed.
  2. oracle.Connector().__del__() is called, which calls self.__logger__.info(). This reopens the closed file handler to log, truncating the file.

To prevent this, explicitly close your connector before exiting Python:

DATABASE.close_connection()

Upvotes: 5

Related Questions