need to see the descriptions of logging output of various modules in python

Question

I want to create a log file in addition to standard output. I am using the inbuilt module such as:

def dedup_col_col2(final_recos):
    """
    Removing duplicate combination of col1-col2 for any single Muid
    """
    recommendation_log()
    def f(data,col1, col2):
        ra=data[~(data[[col1,col2]].duplicated())]
        return ra
    .....Do something(carry on)

def function_logger(file_level, console_level = None):
    """
    Logging function to log all the warning/error messages
    It writes both to console and log file
    """
    function_name = inspect.stack()[1][3]
    logger = logging.getLogger(function_name)
    logger.setLevel(logging.DEBUG) #By default, logs all messages
    if console_level != None:
        ch = logging.StreamHandler() #StreamHandler logs to console
        ch.setLevel(console_level)
        ch_format = logging.Formatter('%(asctime)s - %(message)s')
        ch.setFormatter(ch_format)
        logger.addHandler(ch)
    fh = logging.FileHandler("{0}.log".format(function_name))
    fh.setLevel(file_level)
    fh_format = logging.Formatter('%(asctime)s - %(lineno)d - %(levelname)-8s - %(message)s')
    fh.setFormatter(fh_format)
    logger.addHandler(fh)
    return logger

def recommendation_log():
    recommendation_log_logger = function_logger(logging.DEBUG, logging.DEBUG)
    recommendation_log_logger.debug('debug message')
    recommendation_log_logger.info('info message')
    recommendation_log_logger.warn('warn message')
    recommendation_log_logger.error('error message')
    recommendation_log_logger.critical('critical message')    
def main():
    recommendation_log()  
    final_recos1=dedup_tbid_tbidrank(final_recos)
    logging.shutdown()

Code is taken from the following link: How do I write log messages to a log file and the console at the same time?

Now when I execute it code it shows various debug-error messages on console. When I open the log file, it shows me following output in the recommendation_log.log file:

2015-07-07 12:19:16,392 - 339 - DEBUG    - debug message
2015-07-07 12:19:16,392 - 340 - INFO     - info message
2015-07-07 12:19:16,393 - 341 - WARNING  - warn message
2015-07-07 12:19:16,393 - 342 - ERROR    - error message
2015-07-07 12:19:16,393 - 343 - CRITICAL - critical message
2015-07-07 12:22:03,176 - 339 - DEBUG    - debug message
2015-07-07 12:22:03,176 - 339 - DEBUG    - debug message

Now I want to understand that what is the source of these errors and I want to see the descriptions of these messages, in the same way as they are shown on the console.

EDIT: On console it displays me warnings such as:

***Cmeans_omni.py:37: SettingWithCopyWarning: 
A value is trying to be set on a copy of a slice from a DataFrame.
Try using .loc[row_indexer,col_indexer] = value instead
See the the caveats in the documentation: http://pandas.pydata.org/pandas-docs/stable/indexing.html#indexing-view-versus-copy
  df['CampaignName_upd'] = df['CampaignName']
/home/ubuntu/anaconda/lib/python2.7/site-packages/pandas/io/parsers.py:1170: DtypeWarning: Columns (3,7) have mixed types. Specify dtype option on import or set low_memory=False.
  data = self._reader.read(nrows)***

Now I want to understand that what is the source of these errors and I also want to see the descriptions of these messages in the log file, in the same way as they are shown on the console.

Basically I want to see the description, as stated above in the log file and actual line no , from where it is originating. The line number, shown in sample output is not the actual line number, it is the line number of the line corresponding to error in function.

I have been reading about the logging module a day long, but cannot figure out the solution.

Answer 1

You are mixing two things.

Let's first concentrate on the logging. Your approach seems to work, but looks quite messy. This is the same idea, but with less overhead:

import logging

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

fmt = logging.Formatter("%(asctime)s - "
                        "%(module)s:%(lineno)s - "
                        "%(levelname)s: %(message)s")

# Loggers need handlers for handling log messages.
# Lets's add a StreamHandler for console output...
sh = logging.StreamHandler()
sh.setFormatter(fmt)
sh.setLevel(logging.DEBUG)
logger.addHandler(sh)

# ...and a FileHandler for Logfile writing:
fh = logging.FileHandler('log.file', 'a')
fh.setFormatter(fmt)
fh.setLevel(logging.WARN)
logger.addHandler(fh)

# Now let's log some stuff:
logger.debug("Foobar")
logger.info("Meh")
logger.warn("I warned you.")
logger.error("This might be an error.")

If you encounter errors and want to include the traceback in your log, use logger.exception():

try:
    x = 1 / 0
except ZeroDivisionError as e:
    # this includes the traceback as level ERROR
    logger.exception(e)

However, your Error is just a Warning, which does not force the program to terminate. If you need to do some warning-related stuff, you might want to take a look at the warnings module.

In this case, pandas throws a SettingWithCopyWarning, you are assigning values to a copy of a part of your DataFrame. This means, everything you modify will not affect your original data, since you are working with the copy only. Use df.loc[] as explained in the documentation to get past this.

---

Update:

Using warnings.warn() messages, you could add them to your logger using the catch_warnings()-contextmanager:

import warnings

class WarningsAdapter(logging.LoggerAdapter):
    """Copy `warnings.WarningMessage` information to log record"""
    def process(self, msg, kwargs):
        if isinstance(msg, warnings.WarningMessage):
            msg = "%s: %s" % (msg.category.__name__, msg.message)
        return msg, kwargs

adapter = WarningsAdapter(logger, extra=None)

with warnings.catch_warnings(record=True) as warning_list:
    # do something throwing a warning
    warnings.warn("This is a warning message.", RuntimeWarning)
    warnings.warn("Something might have gone wrong.", UserWarning)
    # something else
    for w in warning_list:
        adapter.warning(w)

You might want to take a look at this question though, the use cases of warnings.warn() and logging.warning() are being discussed there.