2

When I use the PIL.ImageTk library to load a png to my GUI and use logging to log some events, it creates some unwanted logs in DEBUG mode.

I have tried changing the level of logging to INFO or WARNING (or higher). But that does not help:

logging.basicConfig(filename='mylog.log', filemode='a', format='%(asctime)s %(levelname)s: %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p', level=logging.INFO)

For example, the following code will create a log file with some unwanted lines:

from PIL import ImageTk, Image
import logging

try:
    import tkinter as tk # Python 3.x
except ImportError:
    import Tkinter as tk # Python 2.x

class Example(tk.Frame):
    def __init__(self, parent):
        tk.Frame.__init__(self, parent)

        for i in range(2):
            self.grid_rowconfigure(i, weight=1)

        self.grid_columnconfigure(0, weight=1)

        self.img = ImageTk.PhotoImage(Image.open('test.png'))
        logo = tk.Label(self, image = self.img)
        logo.grid(row=0, column=0, columnspan=2, sticky="nw", pady=5, padx=10)

        testLabel = tk.Label(self, width=8, text="This is a test")
        testLabel.grid(row=1, column=0, sticky='ew', padx=5, pady=5)
        logging.info("This is a test log...")


if __name__ == "__main__":
    logging.basicConfig(filename='mylog.log', filemode='a', format='%(asctime)s %(levelname)s: %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p', level=logging.DEBUG)

    root = tk.Tk()
    Example(root).pack(side="top", fill="both", expand=True)
    root.mainloop()

Here is a sample image test.png

enter image description here

This will create a log file with some unwanted lines like this:

07/23/2019 01:34:23 PM DEBUG: STREAM b'IHDR' 16 13
07/23/2019 01:34:23 PM DEBUG: STREAM b'IDAT' 41 6744
07/23/2019 01:34:23 PM INFO: This is a test log...

It should have been only:

07/23/2019 01:34:23 PM INFO: This is a test log...

If you remove the image from the GUI, the problem goes away. Is there any workaround for this?

EDIT: I apologize for not going through the docs carefully. This was happening because the root module was created with DEBUG level when I first ran the script in Spyder with level=DEBUG and it was never changed by basicConfig subsequently when I changed the level to INFO. If I reload all the modules and libs (only by restarting the kernel in Spyder), the problem goes away, which means level=INFO would work perfectly as I want.

Jakaria
  • 197
  • 1
  • 7
  • Your question is a bit unclear. Are you saying that even when you set the log level to INFO, the log contains DEBUG messages? – Bryan Oakley Jul 23 '19 at 18:51
  • if I'm not wrong it doesn't change `level` when you use `basicConfig`. Maybe some bug. – furas Jul 23 '19 at 20:39
  • problem can be because module already set level and now `basicConfig` can't change it: [python logging set level in basicConfig](https://stackoverflow.com/questions/17848281/python-logging-set-level-in-basicconfig). Maybe if you create new logger then you get only your messages in logger. – furas Jul 23 '19 at 20:47
  • I apologize for not going through the docs carefully. @BryanOakley: Yes, even if I set the log level to INFO, I was getting DEBUG messages. The reason was the root module was created with DEBUG level when I first ran the script and it was never changed by `basicConfig` subsequently when I changed the level to INFO. If I reload all the modules and libs (only by restarting the kernel in Spyder), the problem goes away. @furas: Thanks, you saved my day! – Jakaria Jul 24 '19 at 15:28

3 Answers3

3

Add:

pil_logger = logging.getLogger('PIL')
pil_logger.setLevel(logging.INFO)

(source: https://github.com/camptocamp/pytest-odoo/issues/15#issuecomment-559203242)

Raphvanns
  • 1,766
  • 19
  • 21
1

Problem is because module already created root logger and now basicConfig uses this logger but it can't change level for existing logger.

Doc: basicConfig

This function does nothing if the root logger already has handlers configured for it.

You have to create own logger (you can use __name__ to make it unique) and then you can set root level and levels for file and console handlers. In own logger you will no see warnings from other loggers.

if __name__ == "__main__":

    logger = logging.getLogger(__name__)
    logger.setLevel(logging.DEBUG) # root level

    # console
    ch = logging.StreamHandler()
    ch.setLevel(logging.DEBUG) # level only for console (if not collide with root level)
    logger.addHandler(ch)

    # file
    fh = logging.FileHandler('mylog.log')
    fh.setLevel(logging.DEBUG) # level only for file (if not collide with root level)
    logger.addHandler(fh)

    root = tk.Tk()
    Example(root).pack(side="top", fill="both", expand=True)
    root.mainloop()

Doc: logging-advanced-tutorial,

furas
  • 134,197
  • 12
  • 106
  • 148
0

Instead Of Using:

...
level=logging.DEBUG
...

Use:

...
level=logging.INFO
...

And Your File Will Be:

DD/MM/YYYY HH:MM:SS PM INFO: This is a test log...

SF12 Study
  • 375
  • 4
  • 18