I would like to add my solution (which is based on logging cookbook and other articles and suggestions from this thread. However it took me quite a while to figure out, why it wasn't immediately working how I expected. So I created a little test project to learn how logging is working.
Since I have figured it out, I wanted to share my solution, maybe it can be of help to someone.
I know some of my code might not be best practice, but I am still learning. I left the print() functions in there, as I used them, while logging was not working as expected. Those are removed in my other application. Also I welcome any feedback on any parts of the code or structure.
my_log_test project structure (cloned/simplified from another project I work on)
my_log_test
├── __init__.py
├── __main__.py
├── daemon.py
├── common
│ ├── my_logger.py
├── pkg1
│ ├── __init__.py
│ └── mod1.py
└── pkg2
├── __init__.py
└── mod2.py
Requirements
A few things different or that I have not seen explicitly mentioned in the combination I use:
- the main module is
daemon.pywhich is called by __main__.py
- I want to be able to call the modules
mod1.py and mod2.py seperately while in development/testing
- At this point I did not want to use
basicConfig() or FileConfig() but keep it like in the logging cookbook
So basically, that means, I need to initialize the root logger in daemon.py (always) and in the modules mod1.py and mod2.py (only when calling them directly).
To make this init in several modules easier, I created my_logger.py which does, what is described in the cookbook.
My mistakes
Beforehand, my mistake in that module was to init the logger with logger = logging.getLogger(__name__) (module logger) instead of using logger = logging.getLogger() (to get the root logger).
The first problem was, that when called from daemon.py the logger's namespace was set to my_log_test.common.my_logger. The module logger in mod1.py with an "unmatching" namespace my_log_test.pkg1.mod1 could hence not attach to the other logger and I would see no log output from mod1.
The second "problem" was, that my main program is in daemon.py and not in __main__.py. But after all not a real problem for me, but it added to the namespace confusion.
Working solution
This is from the cookbook but in a separate module. I also added a logger_cleanup function that I can call from daemon, to remove logs older than x days.
## my_logger.py
from datetime import datetime
import time
import os
## Init logging start
import logging
import logging.handlers
def logger_init():
print("print in my_logger.logger_init()")
print("print my_logger.py __name__: " +__name__)
path = "log/"
filename = "my_log_test.log"
## get logger
#logger = logging.getLogger(__name__) ## this was my mistake, to init a module logger here
logger = logging.getLogger() ## root logger
logger.setLevel(logging.INFO)
# File handler
logfilename = datetime.now().strftime("%Y%m%d_%H%M%S") + f"_{filename}"
file = logging.handlers.TimedRotatingFileHandler(f"{path}{logfilename}", when="midnight", interval=1)
#fileformat = logging.Formatter("%(asctime)s [%(levelname)s] %(message)s")
fileformat = logging.Formatter("%(asctime)s [%(levelname)s]: %(name)s: %(message)s")
file.setLevel(logging.INFO)
file.setFormatter(fileformat)
# Stream handler
stream = logging.StreamHandler()
#streamformat = logging.Formatter("%(asctime)s [%(levelname)s:%(module)s] %(message)s")
streamformat = logging.Formatter("%(asctime)s [%(levelname)s]: %(name)s: %(message)s")
stream.setLevel(logging.INFO)
stream.setFormatter(streamformat)
# Adding all handlers to the logs
logger.addHandler(file)
logger.addHandler(stream)
def logger_cleanup(path, days_to_keep):
lclogger = logging.getLogger(__name__)
logpath = f"{path}"
now = time.time()
for filename in os.listdir(logpath):
filestamp = os.stat(os.path.join(logpath, filename)).st_mtime
filecompare = now - days_to_keep * 86400
if filestamp < filecompare:
lclogger.info("Delete old log " + filename)
try:
os.remove(os.path.join(logpath, filename))
except Exception as e:
lclogger.exception(e)
continue
to run deamon.py (through __main__.py) use python3 -m my_log_test
## __main__.py
from my_log_test import daemon
if __name__ == '__main__':
print("print in __main__.py")
daemon.run()
to run deamon.py (directly) use python3 -m my_log_test.daemon
## daemon.py
from datetime import datetime
import time
import logging
import my_log_test.pkg1.mod1 as mod1
import my_log_test.pkg2.mod2 as mod2
## init ROOT logger from my_logger.logger_init()
from my_log_test.common.my_logger import logger_init
logger_init() ## init root logger
logger = logging.getLogger(__name__) ## module logger
def run():
print("print in daemon.run()")
print("print daemon.py __name__: " +__name__)
logger.info("Start daemon")
loop_count = 1
while True:
logger.info(f"loop_count: {loop_count}")
logger.info("do stuff from pkg1")
mod1.do1()
logger.info("finished stuff from pkg1")
logger.info("do stuff from pkg2")
mod2.do2()
logger.info("finished stuff from pkg2")
logger.info("Waiting a bit...")
time.sleep(30)
if __name__ == '__main__':
try:
print("print in daemon.py if __name__ == '__main__'")
logger.info("running daemon.py as main")
run()
except KeyboardInterrupt as e:
logger.info("Program aborted by user")
except Exception as e:
logger.info(e)
To run mod1.py (directly) use python3 -m my_log_test.pkg1.mod1
## mod1.py
import logging
# mod1_logger = logging.getLogger(__name__)
mod1_logger = logging.getLogger("my_log_test.daemon.pkg1.mod1") ## for testing, namespace set manually
def do1():
print("print in mod1.do1()")
print("print mod1.py __name__: " +__name__)
mod1_logger.info("Doing someting in pkg1.do1()")
if __name__ == '__main__':
## Also enable this pkg to be run directly while in development with
## python3 -m my_log_test.pkg1.mod1
## init root logger
from my_log_test.common.my_logger import logger_init
logger_init() ## init root logger
print("print in mod1.py if __name__ == '__main__'")
mod1_logger.info("Running mod1.py as main")
do1()
To run mod2.py (directly) use python3 -m my_log_test.pkg2.mod2
## mod2.py
import logging
logger = logging.getLogger(__name__)
def do2():
print("print in pkg2.do2()")
print("print mod2.py __name__: " +__name__) # setting namespace through __name__
logger.info("Doing someting in pkg2.do2()")
if __name__ == '__main__':
## Also enable this pkg to be run directly while in development with
## python3 -m my_log_test.pkg2.mod2
## init root logger
from my_log_test.common.my_logger import logger_init
logger_init() ## init root logger
print("print in mod2.py if __name__ == '__main__'")
logger.info("Running mod2.py as main")
do2()
Happy if it helps. Happy to receive feedback as well!
fileConfigin every module that does logging, unless you haveif __name__ == '__main__'logic in all of them. prost's answer is not good practice if the package is a library, though it might work for you - one should not configure logging in library packages, other than to add aNullHandler. – Peachypackage/__init__.py. That's not normally the place you putif __name__ == '__main__'code. Also, prost's example looks like it will call the config code unconditionally on import, which doesn't look right to me. Generally, logging config code should be done in one place and should not happen as a side-effect of import except when you're importing __main__. – Peachy