`logging` duplicated lines issues on Raspberry Pi

[pblase]

Bug report

Bug description:

On a Raspberry Pi,

PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"

Python 3.11

#wrapper for logging
#logging functions:
# logger.debug(s : str)
# logger.error(s : str)
# logger.info(s : str)
# logger.warning(s : str)


import numpy as np
import time

import logging
from logging.handlers import RotatingFileHandler

class MessageLogging :
    def __init__(self,
                 logfile_name: str) :
        _format = "%(asctime)s.%(msecs)03d: %(levelname)s: %(funcName)s(): %(lineno)d:\t %(message)s "
        _datefmt = '%Y-%m-%d %H:%M:%S'
        logging_level = logging.DEBUG  # levels: NOTSET, DEBUG, INFO, WARNING, ERROR,  CRITICAL.
                
        self.logger = logging.getLogger(__name__)
        self.logger.setLevel(logging_level)

        stdout_handler = logging.StreamHandler()
        stdout_handler.setLevel(logging_level)
        stdout_handler.setFormatter(logging.Formatter(_format, _datefmt))

        file_handler = RotatingFileHandler(logfile_name, maxBytes=200000, backupCount=5)
        file_handler.setLevel(logging_level)
        file_handler.setFormatter(logging.Formatter(_format, _datefmt))

        self.logger.addHandler(stdout_handler)
        self.logger.addHandler(file_handler)
        
if __name__=="__main__":
    import Read_settings

    print("Starting")
    
    setup1    = Read_settings.Read_settings('setup.txt')
    settings1 = Read_settings.Read_settings('settings.txt')

    logger1 = MessageLogging(settings1.setting_data['logfile_name'])
    
    logger1.logger.debug('debug_test')
    logger1.logger.error('error_test')
    logger1.logger.info('info_test')
    
    print("Done.")

After recent updates, when I log to the file, as in the main test entries at the end, I get multiple entries on both the screen and in the log file.
e.g.

2025-10-09 10:49:45.402: DEBUG: init(): 65: debug_test
2025-10-09 10:49:45.402: DEBUG: init(): 65: debug_test
2025-10-09 10:49:45.402: DEBUG: init(): 65: debug_test
2025-10-09 10:49:45.402: DEBUG: init(): 65: debug_test
2025-10-09 10:49:45.402: DEBUG: init(): 65: debug_test
2025-10-09 10:49:45.406: ERROR: init(): 66: error_test
2025-10-09 10:49:45.406: ERROR: init(): 66: error_test
2025-10-09 10:49:45.406: ERROR: init(): 66: error_test
2025-10-09 10:49:45.406: ERROR: init(): 66: error_test
2025-10-09 10:49:45.406: ERROR: init(): 66: error_test
2025-10-09 10:49:45.409: INFO: init(): 67: info_test
2025-10-09 10:49:45.409: INFO: init(): 67: info_test
2025-10-09 10:49:45.409: INFO: init(): 67: info_test
2025-10-09 10:49:45.409: INFO: init(): 67: info_test
2025-10-09 10:49:45.409: INFO: init(): 67: info_test

and the number appears to increase as the program progresses:
(the numbers are other output data)

352
2025-10-09 10:49:50.666: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:50.666: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:50.666: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
384
2025-10-09 10:49:50.666: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:50.666: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:50.666: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:50.666: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:50.666: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
416
448
480
512
544
576
608
640
672
2025-10-09 10:49:51.679: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:51.679: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:51.679: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:51.679: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:51.679: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:51.679: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:51.679: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
2025-10-09 10:49:51.679: INFO: Box_heater_thread(): 142: Heater off, box temp: 26.375
704

Needless to say, I'm only calling
self.mlogger.logger.info('Heater {}, box temp: {}'.format(H_txt, self.box_temp_C)) once in the loop.

CPython versions tested on:

3.11

Operating systems tested on:

Other

[picnixz]

How many instances of MessageLogging actually live? it seems that there is some multi-threading stuff hapenning. Because each instance of MessageLogging re-uses the same logger (that is tied to __name__) and re-adds handlers. You're likely having duplicated handlers for some reasons.

Also, please share all the code, not just a subset of it. What is the "loop"? how is it called? where is it called? the code as given is unfortunately not sufficient.

[picnixz]

The script you gave as a "reproducer" doesn't reproduce for me. I only have a single entry, so I guess it's really because there are multiple MessageLogging objects living at the same time or if the screen is being refreshed for some reason? (it might be also because of it's on an RPi that you see duplicated lines; the lines in the log file should however be uniquely emitted)

[StanFromIreland]

Note that there are four raspberry pi buildbots where all tests pass. I can try reproducing it one one.

[pblase]

It does appear to be thread related.

main.py

MessageLogging.py

LED.py

In each thread, I have the same line
self.mlogger = MessageLogging.MessageLogging(settings1.setting_data['logfile_name'])
where the settings1 structure returns the log file path. LED.py is a typical thread structure.
So obviously I have multiple handlers at once. What is the best way to structure this, then? I was assuming that each instance of MessageLogging would return a unique handler that would not interfere with any other thread's handler.