log.add creates a batch of log files but cannot write into files (hashtag648)

[vikramsubramanian]

Here is an example. When the element in list self._chips_list[i] == 1, add a logger with a specific log file. The method record is to record something to a specific log file. Generally I was used logger.info in an async function such as main as below. The log was printed to console as expected but was not recorded in file. I don't know hot to fix it☹

from loguru import logger
from pathlib import Path
import asyncio

async def main():
    manager = LogManager()
    msg = "hello world"
    manager.record(2, msg)

class LogManager:
    def __init__(self):
        self._chips_list = [1, 0, 1, 0, 0]
        self._logger_id = []

        for index in range(0, len(self._chips_list)):
            if self._chips_list[index] == 1:
                log_path = Path.cwd() / (str(index) +  ".log")
                lid = logger.add(log_path, enqueue=True, filter=lambda record: record["extra"]["chip"] == str(index))
                self._logger_id.append(lid)
            else:
                self._logger_id.append(0)

    def record(self, index: int, msg: str):
        logger.bind(chip=str(index)).info(f"{index} | {msg}")

if __name__ == '__main__':
    loop = asyncio.get_event_loop()
    loop.run_until_complete(main())
    loop.close()

[vikramsubramanian]

I now got the crux of the above questions. For example, When I'm using for to create a batch of logs with regular names, loguru can create log files OK, but I cannot write into files using logger.bind(...).info(...). Log files are empty.

from loguru import logger
logger.remove()

for i in range(0, 8):
    logger.add(f"{i}.log", filter=lambda record: record["extra"]["chip"] == i)

hashtag logger.add("1.log", filter=lambda record: record["extra"]["chip"] == 1)
hashtag logger.add("2.log", filter=lambda record: record["extra"]["chip"] == 2) 
hashtag logger.add("3.log", filter=lambda record: record["extra"]["chip"] == 3)
hashtag logger.add("4.log", filter=lambda record: record["extra"]["chip"] == 4) 
hashtag logger.add("5.log", filter=lambda record: record["extra"]["chip"] == 5)
hashtag logger.add("6.log", filter=lambda record: record["extra"]["chip"] == 6)

logger.bind(chip=2).error("Error chip hashtag2")    
logger.bind(chip=5).info("Hello chip hashtag5")

Then, if I add logs via logger.add(...) obviously enough, loguru can create and write into log files.🤔

from loguru import logger
logger.remove()

hashtag for i in range(0, 8):
hashtag     logger.add(f"{i}.log", filter=lambda record: record["extra"]["chip"] == i)

logger.add("1.log", filter=lambda record: record["extra"]["chip"] == 1)
logger.add("2.log", filter=lambda record: record["extra"]["chip"] == 2) 
logger.add("3.log", filter=lambda record: record["extra"]["chip"] == 3)
logger.add("4.log", filter=lambda record: record["extra"]["chip"] == 4) 
logger.add("5.log", filter=lambda record: record["extra"]["chip"] == 5)
logger.add("6.log", filter=lambda record: record["extra"]["chip"] == 6)

logger.bind(chip=2).error("Error chip hashtag2")    
logger.bind(chip=5).info("Hello chip hashtag5")

Windows, Python 3.9.10

[vikramsubramanian]

Hi

You're hitting a classical pitfall of Python, see [Why do lambdas defined in a loop with different values all return the same result?](

Try the following:

for i in range(0, 8):
    logger.add(f"{i}.log", filter=lambda record, i=i: record["extra"]["chip"] == i)

[vikramsubramanian]

Wow thanks a lot! This is truly a classic pitfall about lambda function! As you can see, I will create a batch of logs to write, and then I'd like to logger.add(sys.stderr), logging on my console. If so, when I use logger.info(..) instead of the limit of logger.bind(...).info(...), the loguru will raise logging error.

[vikramsubramanian]

Which error exactly? Can you share the message so I can understand it please?

[vikramsubramanian]

Here is the simplified scenario:

from loguru import logger
import sys
logger.remove()
logger.add(sys.stderr)

logger.add("1.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 1)
logger.add("2.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 2)
logger.add("3.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 3)
logger.add("4.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 4)
logger.add("5.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 5)
logger.add("6.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 6)

logger.bind(chip=5).info("Hello chip hashtag5")
logger.bind(chip=2).error("Error chip hashtag2")

logger.info("System info blahblahblah")

I wanna record some info just printed on console but not writed into logs.

2022-05-04 19:46:30.958 | INFO     | __main__:<module>:17 - Hello chip hashtag5
2022-05-04 19:46:30.982 | ERROR    | __main__:<module>:18 - Error chip hashtag2
2022-05-04 19:46:30.985 | INFO     | __main__:<module>:20 - System info blahblahblah
--- Logging error in Loguru Handler hashtag2 ---
Record was: {'elapsed': datetime.timedelta(microseconds=162851), 'exception': None, 'extra': {}, 'file': (name='t.py', path='d:\\WORK\\JXR151T_VERIFY_BOARD\\VerifyConsoleJXR151T_V020\\t.py'), 'function': '<module>', 'level': (name='INFO', no=20, icon='ℹ️'), 'line': 20, 'message': 'System info blahblahblah', 'module': 't', 'name': '__main__', 'process': (id=544, name='MainProcess'), 'thread': (
id=22864, name='MainThread'), 'time': datetime(2022, 5, 4, 19, 46, 30, 985198, tzinfo=datetime.timezone(datetime.timedelta(seconds=28800), '中国标准时间'))}
Traceback (most recent call last):
  File "D:\miniconda3\envs\jxr151t\lib\site-packages\loguru\_handler.py", line 104, in emit
    if not self._filter(record):
  File "d:\WORK\JXR151T_VERIFY_BOARD\VerifyConsoleJXR151T_V020\t.py", line 10, in <lambda>
    li.append(logger.add("1.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 1))
KeyError: 'chip'
--- End of logging error ---
--- Logging error in Loguru Handler hashtag3 ---
Record was: {'elapsed': datetime.timedelta(microseconds=162851), 'exception': None, 'extra': {}, 'file': (name='t.py', path='d:\\WORK\\JXR151T_VERIFY_BOARD\\VerifyConsoleJXR151T_V020\\t.py'), 'function': '<module>', 'level': (name='INFO', no=20, icon='ℹ️'), 'line': 20, 'message': 'System info blahblahblah', 'module': 't', 'name': '__main__', 'process': (id=544, name='MainProcess'), 'thread': (
id=22864, name='MainThread'), 'time': datetime(2022, 5, 4, 19, 46, 30, 985198, tzinfo=datetime.timezone(datetime.timedelta(seconds=28800), '中国标准时间'))}
Traceback (most recent call last):
  File "D:\miniconda3\envs\jxr151t\lib\site-packages\loguru\_handler.py", line 104, in emit
    if not self._filter(record):
  File "d:\WORK\JXR151T_VERIFY_BOARD\VerifyConsoleJXR151T_V020\t.py", line 11, in <lambda>
    li.append(logger.add("2.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 2))
KeyError: 'chip'
--- End of logging error ---
--- Logging error in Loguru Handler hashtag4 ---
Record was: {'elapsed': datetime.timedelta(microseconds=162851), 'exception': None, 'extra': {}, 'file': (name='t.py', path='d:\\WORK\\JXR151T_VERIFY_BOARD\\VerifyConsoleJXR151T_V020\\t.py'), 'function': '<module>', 'level': (name='INFO', no=20, icon='ℹ️'), 'line': 20, 'message': 'System info blahblahblah', 'module': 't', 'name': '__main__', 'process': (id=544, name='MainProcess'), 'thread': (
id=22864, name='MainThread'), 'time': datetime(2022, 5, 4, 19, 46, 30, 985198, tzinfo=datetime.timezone(datetime.timedelta(seconds=28800), '中国标准时间'))}
Traceback (most recent call last):
  File "D:\miniconda3\envs\jxr151t\lib\site-packages\loguru\_handler.py", line 104, in emit
    if not self._filter(record):
  File "d:\WORK\JXR151T_VERIFY_BOARD\VerifyConsoleJXR151T_V020\t.py", line 12, in <lambda>
    li.append(logger.add("3.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 3))
KeyError: 'chip'
--- End of logging error ---
--- Logging error in Loguru Handler hashtag5 ---
Record was: {'elapsed': datetime.timedelta(microseconds=162851), 'exception': None, 'extra': {}, 'file': (name='t.py', path='d:\\WORK\\JXR151T_VERIFY_BOARD\\VerifyConsoleJXR151T_V020\\t.py'), 'function': '<module>', 'level': (name='INFO', no=20, icon='ℹ️'), 'line': 20, 'message': 'System info blahblahblah', 'module': 't', 'name': '__main__', 'process': (id=544, name='MainProcess'), 'thread': (
id=22864, name='MainThread'), 'time': datetime(2022, 5, 4, 19, 46, 30, 985198, tzinfo=datetime.timezone(datetime.timedelta(seconds=28800), '中国标准时间'))}
Traceback (most recent call last):
  File "D:\miniconda3\envs\jxr151t\lib\site-packages\loguru\_handler.py", line 104, in emit
    if not self._filter(record):
  File "d:\WORK\JXR151T_VERIFY_BOARD\VerifyConsoleJXR151T_V020\t.py", line 13, in <lambda>
    li.append(logger.add("4.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 4))
KeyError: 'chip'
--- End of logging error ---
--- Logging error in Loguru Handler hashtag6 ---
Record was: {'elapsed': datetime.timedelta(microseconds=162851), 'exception': None, 'extra': {}, 'file': (name='t.py', path='d:\\WORK\\JXR151T_VERIFY_BOARD\\VerifyConsoleJXR151T_V020\\t.py'), 'function': '<module>', 'level': (name='INFO', no=20, icon='ℹ️'), 'line': 20, 'message': 'System info blahblahblah', 'module': 't', 'name': '__main__', 'process': (id=544, name='MainProcess'), 'thread': (
id=22864, name='MainThread'), 'time': datetime(2022, 5, 4, 19, 46, 30, 985198, tzinfo=datetime.timezone(datetime.timedelta(seconds=28800), '中国标准时间'))}
Traceback (most recent call last):
  File "D:\miniconda3\envs\jxr151t\lib\site-packages\loguru\_handler.py", line 104, in emit
    if not self._filter(record):
  File "d:\WORK\JXR151T_VERIFY_BOARD\VerifyConsoleJXR151T_V020\t.py", line 14, in <lambda>
    li.append(logger.add("5.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 5))
KeyError: 'chip'
--- End of logging error ---
--- Logging error in Loguru Handler hashtag7 ---
Record was: {'elapsed': datetime.timedelta(microseconds=162851), 'exception': None, 'extra': {}, 'file': (name='t.py', path='d:\\WORK\\JXR151T_VERIFY_BOARD\\VerifyConsoleJXR151T_V020\\t.py'), 'function': '<module>', 'level': (name='INFO', no=20, icon='ℹ️'), 'line': 20, 'message': 'System info blahblahblah', 'module': 't', 'name': '__main__', 'process': (id=544, name='MainProcess'), 'thread': (
id=22864, name='MainThread'), 'time': datetime(2022, 5, 4, 19, 46, 30, 985198, tzinfo=datetime.timezone(datetime.timedelta(seconds=28800), '中国标准时间'))}
Traceback (most recent call last):
  File "D:\miniconda3\envs\jxr151t\lib\site-packages\loguru\_handler.py", line 104, in emit
    if not self._filter(record):
  File "d:\WORK\JXR151T_VERIFY_BOARD\VerifyConsoleJXR151T_V020\t.py", line 15, in <lambda>
    li.append(logger.add("6.log", enqueue=True, filter=lambda record: record["extra"]["chip"] == 6))
KeyError: 'chip'
--- End of logging error ---

[vikramsubramanian]

Thanks. That's because not all loggers are bound with the chip parameter. Consequently, when you use logger.info() directly (without calling bind()) the record["extra"]["chip"] value does not exist. Try settings a default one globally at the beginning of your file using [configure()](

logger.configure(extra={"chip": None})

[vikramsubramanian]

My hero! 🌹 Besides, if I wanna output log on my console and write into logs by bind(...) as above, there is no need to logger.remove() and then logger.add(sys.stderr) at the beginning of my code?

[vikramsubramanian]

Indeed, this is not required because you are re-adding the sys.stderr without any modification to the others parameters. That means you are re-adding the default sink, while you don't need to if you don't call logger.remove() beforehand.

[vikramsubramanian]

Thank you!