0

First time playing around with the logging module. I have two questions really:

All of the examples I have found on creating a FileHandler just use a dummy file name, but I want my log file to have a certain title format.

log = time.strftime('./logs/'+'%H:%M:%S %d %b %Y', time.localtime())+'.log'
logger = logging.getLogger('myproject')
formatter = logging.Formatter('%(asctime)s %(message)s', '%H:%M:%S %d %b %Y')
handler = logging.FileHandler(log)
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.setLevel(logging.DEBUG)

This seems to work at first, in that the log file is created, but when I kill the script and examine it, there is nothing in it. And before you suggest using with open(log) as f:, using f in place of log in handler = logging.FileHandler(log) gives me errors about the file not even being created. What am I doing wrong to not have the log file written to? Is it because I'm trying to be too clever with the filename?

The second question may subsume the first somehow. What I would really like is a way to write to both the console and the log file concurrently, since this script takes a long time and I'd like to gauge progress. I have seen that there are answers on how to do this, such as here, but all of these seem to assume that I want different levels of logging for the two different outputs; I don't. Incidentally, I do realize that if my script didn't dynamically generate the name of the log file, I could do something like python myscript.py | tee log.file to avoid making different handlers.

I feel I am having trouble answering my second question because of the variables involved in the first, but I am foggy right now due to illness and subsequent lack of sleep. If someone could explain to me like a five-year-old how to write to both a console and log file with identical output, I would greatly appreciate it.

Many thanks.

Community
  • 1
  • 1
verbsintransit
  • 888
  • 3
  • 8
  • 18
  • Uhhhm. I guess I'm an honorary Windows dev? My script is in `.` and I intend to create the logfile in `logs`, which is located in same. And like I said, the file does get created, if nothing else. – verbsintransit Feb 28 '13 at 21:36
  • Definitely; running the script from the CLI right now and watching it do something, or nothing. – verbsintransit Feb 28 '13 at 21:39
  • OK, good, we're past all that; now let me see if I can figure out the real problem. :) – abarnert Feb 28 '13 at 21:40
  • Another possibly stupid question: Are you logging with `logger.log` or `logging.log` (or with `debug`, etc.; the issue is whether you're using methods on the logger you got back, or the top-level module functions). – abarnert Feb 28 '13 at 21:42
  • Not a stupid question. I myself have no idea. Everything you see in the body of the question is how I cobbled it together. I had only gotten as far as thinking that I needed to go beyond basic logging as shown in the docs. – verbsintransit Feb 28 '13 at 21:46
  • You don't have any code in the body that logs anything. If I create the `logs` directory and run that code and then do `logger.debug('foo'); logging.debug('bar')`, the former ends up in my log file, the latter does not. That's because `logging.debug` looks up the right logger based on your current module, and it will find the default logger, not the `'myproject'` one. But if you explicitly use the one you looked up, of course it works. So… could that be your problem? – abarnert Feb 28 '13 at 21:48
  • Ah, well, I had previously converted all of my scaffolding `print` statements in the rest of the program to `logging.info('foo bar')`. So those _should_ be logged, I think. – verbsintransit Feb 28 '13 at 21:51
  • No, that's your problem. You're using `logging`, which is using the default logger. Let me write this up as an answer. – abarnert Feb 28 '13 at 21:53

1 Answers1

2

Your code is configuring a logger named 'myproject':

logger = logging.getLogger('myproject')
logger.addHandler(handler)
logger.setLevel(logging.DEBUG)

If you use methods on that logger, everything will work:

logger.info('foo bar')
logging.getLogger('myproject').info('foo bar')

But if you just use the module-level functions, it will not:

logging.info('foo bar')

Why? Because the module-level functions use the default root logger, which is not the one you've configured. See the docs for details on how this works.

Generally, the way you deal with this is either to create a module-level logger object for each module, like this:

logger = logging.getLogger(__name__)

… or a class or instance attribute logger, something like this:

self.logger = logging.getLogger('{}.{}'.format(__name__, cls.__name__))

And then do everything through that logger or self.logger object, not through the module-level functions.

So, why are the module-level functions even there? For convenience in simple programs, mainly. If that sounds appropriate for you, and you want to use them, you can; you just have to configure the root logger instead of a different one. Change the first line to this:

logger = logging.getLogger()

Now when you configure logger, you're also configuring the module-level functions.

abarnert
  • 354,177
  • 51
  • 601
  • 671