python logger prints everything twice

Question

I try using this openshift-restclient-python library. My custom Logger prints everything twice after I run into this bug.

modules/logging/Logging.py

import logging
class CustomLogger:
    logger=None
    def __init__(self):
        if (CustomLogger.logger==None):
            logger = logging.getLogger(__name__)
            logger.setLevel(logging.DEBUG)
            stdout_handler = logging.StreamHandler()
            stdout_handler.setLevel(logging.DEBUG)
            logger.addHandler(stdout_handler)
            CustomLogger.logger=logger

    def getLogger(self):
    return CustomLogger.logger

logger = CustomLogger().getLogger()

This ist my main.py:

#!/usr/bin/env python3
import sys
from modules.logging.Logging import logger
from kubernetes import client, config
from openshift.dynamic import DynamicClient
from openshift.helper.userpassauth import OCPLoginConfiguration
import warnings
warnings.filterwarnings("ignore")
apihost = 'myhost'
username = 'myuser'
password = 'insecure'
ca_cert = '/path/to/cert'
kubeConfig = OCPLoginConfiguration(ocp_username=username, ocp_password=password)
kubeConfig.host = apihost
kubeConfig.verify_ssl = False
kubeConfig.ssl_ca_cert = ca_cert
kubeConfig.get_token()
k8s_client = client.ApiClient(kubeConfig)
logger.warning("this is printed once")
dyn_client = DynamicClient(k8s_client)
logger.warning("this is printed twice")
v1_projects = dyn_client.resources.get(api_version='project.openshift.io/v1', kind='Project')
project_list = v1_projects.get()
sys.exit(0)

executing the main.py I get the following output

this is printed once
ERROR:root:load cache error: ResourceList.__init__() got an unexpected keyword argument 'base_resource_lookup'
this is printed twice
WARNING:modules.logging.Logging:this is printed twice

If I do not use my custom logger but a simple configuration as below in main.py then everything is printed once.

import logging
logging.basicConfig(level=logging.DEBUG)

I have found this answer so I also tried removing any handler but the only handler is the one that contains my customization, so I end up with a basic logger.

What am I doing wrong? Thanks

EDIT: There is an easier way reproducing the issue. I still have my custom logger as posted before but my main.py now:

#!/usr/bin/env python3
import sys
from modules.logging.Logging import logger
import logging
print(logger.handlers)
print("number handlers: " +str(len(logger.handlers)))
logger.warning("this is printed once")
logging.basicConfig(level=logging.DEBUG)
logger.warning("this is printed twice")
print("number handlers: " +str(len(logger.handlers)))
for h in logger.handlers:
logger.removeHandler(h)
print("number handlers: " +str(len(logger.handlers)))
logger.warning("still get printed")
sys.exit(0)

the output:

[<StreamHandler <stderr> (DEBUG)>]
number handlers: 1
this is printed once
this is printed twice
WARNING:modules.logging.Logging:this is printed twice
number handlers: 1
number handlers: 0
WARNING:modules.logging.Logging:still get printed

The code logging.basicConfig(level=logging.DEBUG) doesn't add another handler but cause everything to be logged. I actually only want the customized logs printed by the streamingHandler. How can I revert what is done by logging.basicConfig(level=logging.DEBUG)?

Does this answer your question? [Why do I get duplicated logging messages?](https://stackoverflow.com/questions/26730233/why-do-i-get-duplicated-logging-messages) — 555Russich, Aug 09 '22 at 10:44

score 1 · Accepted Answer · answered Aug 09 '22 at 14:06

I solved it that way:

class CustomLogger:
      logger=None
      def __init__(self):
          if (CustomLogger.logger==None):
              logging.basicConfig(filename='/dev/null', filemode='w', format='%(name)s - %(levelname)s - %(message)s')
              logger = logging.getLogger(__name__)
              logger.setLevel(logging.DEBUG)
              fmt = '%(asctime)s | %(message)s'
              stdout_handler = logging.StreamHandler()
              stdout_handler.setLevel(logging.DEBUG)
              stdout_handler.setFormatter(CustomFormatter(fmt))
              logger.addHandler(stdout_handler)
              CustomLogger.logger=logger

    def getLogger(self):
        return CustomLogger.logger

logger = CustomLogger().getLogger()

It seems that the library I am using at some place logs to the RootLogger. According to this answer logging.basicConfig() is a constructor of a streamHandler that connects to the RootLogger.

If I use logger = logging.getLogger('root') instead of logger = logging.getLogger(__name__) then everything is printed once. However, in that case everything the library logs on DEBUG-Level is printed to the terminal.

The line logging.basicConfig(filename='/dev/null', filemode='w', format='%(name)s - %(levelname)s - %(message)s') causes that everything logged by the root logger is printed to /dev/null.

555Russich · Answer 2 · 2022-08-09T10:39:05.620

0

Please try remove this peace of code from class CustomLogger

stdout_handler = logging.StreamHandler()
stdout_handler.setLevel(logging.DEBUG)
logger.addHandler(stdout_handler)

btw i was struggling with the same. Found answers using search on this website. https://stackoverflow.com/a/26730545/15637940

https://stackoverflow.com/a/70876179/15637940

and a lot more answered questions...

edited Aug 09 '22 at 10:39

answered Aug 09 '22 at 10:24

555Russich

354
2
10

Unfortunately, I already tried removing the handler. As I wrote I have found a similar answer so I also tried removing any handler but the only handler is the one that contains my customization, so I end up with a basic logger that has no customizing. – Amit Aug 09 '22 at 11:11

python logger prints everything twice

2 Answers2