the more handlers I add I get duplicate Log outputs

[gampam2000]

Hi, thanks for your great logging tool, i helps alot.

first i only used 2 handler (info, to_term and error, to_file) now i added two more to_term handlers and now i get duplicate logs on the terminal:

here my logutil.py:

# loguitl.py
import ulogger
from machine import RTC
import ntptime
import time

class Clock(ulogger.BaseClock):
    def __init__(self):
        self.rtc = RTC()
        #try:
        #    ntptime.settime()
        #    print ('Time set: {}'.format(time.localtime()))
        #except Exception as e:
        #    print(e)	
        #    print ('NTP time set failed')
        #    return	
        
    def __call__(self) -> str:
        # Format the datetime object as a string using strftime() method
        y,m,d,wd,h,min,s,ms = self.rtc.datetime()
        #return '%d-%d-%d %d:%d:%d' % (y,m,d,h,mi,s)
        #Todo change to %F formatted string for better performance
        return "%04d-%02d-%02d %02d:%02d:%02d" % (y,m,d,h,min,s)

clock = Clock()
    
handlers = (
    ulogger.Handler(
        level=ulogger.INFO,
        colorful=True,
        fmt="&(time)% - &(level)% - &(name)% - &(fnname)% - &(msg)%",
        clock=clock,
        direction=ulogger.TO_TERM,
    ),
    ulogger.Handler(
        level=ulogger.WARN,
        colorful=True,
        fmt="&(time)% - &(level)% - &(name)% - &(fnname)% - &(msg)%",
        clock=clock,
        direction=ulogger.TO_TERM,
    ),
    ulogger.Handler(
        level=ulogger.DEBUG,
        colorful=True,
        fmt="&(time)% - &(level)% - &(name)% - &(fnname)% - &(msg)%",
        clock=clock,
        direction=ulogger.TO_TERM,
    ),
    ulogger.Handler(
        level=ulogger.ERROR,
        colorful=True,
        fmt="&(time)% - &(level)% - &(name)% - &(fnname)% - &(msg)%",
        clock=clock,
        direction=ulogger.TO_FILE,
        file_name="log.txt",
        max_file_size=32768 # max for 4k
    )
)

def get_logger(name: str):
    return ulogger.Logger(name, handlers)

all = (get_logger)

from my different python tasks (i use a lot of async tasks) i get the logger like this:

log = logutil.get_logger("SMW")
log = logutil.get_logger("WEB")
....

all log.info are duplicated and all log.error and log.warn i get 3 times, for example my log output looks like this:

2024-06-08 08:58:46 - ERROR - WEB - handle_request - need more than 0 values
2024-06-08 08:58:46 - ERROR - WEB - handle_request - need more than 0 values
2024-06-08 08:58:46 - ERROR - WEB - handle_request - need more than 0 values

2024-06-08 08:58:51 - INFO - SMW - queue_data - TFS Event awaited
2024-06-08 08:58:51 - INFO - SMW - queue_data - TFS Event awaited

Any ideas why this is happening? Am i doing something wrong?

[majoson-chen]

当你设置较低级的 handler 时，是会输出更高级的信息的，假设你设置了一个 info 级别的 handler，同时设置了一个 error 的 handler，那么你调用 log.error，两个 handler 都会 catch 这个请求。

这是一个设计上的设定，因为单片机平台资源有限，在支持库中处理这个问题可能会占用较多资源。

而且一般的用法是将低等级的 log 输出到控制台方便调试，只有高等级的才会输出至文件。

如果你想解决这个问题，可以尝试自己去做 filter。