search

Delgan / loguru

Python logging made (stupidly) simple
MIT License
19.62k stars 695 forks source link

KeyError: "'type'" #1154

Closed adhadse closed 3 months ago

adhadse commented 3 months ago

Receiving KeyError when using logger with no patching. Occuring in loguru/_logger.py#L2021

 2024-06-18 12:57:42.796 | ERROR    | __main__:find_unfulfilled_or_uncancelled:94 - exception handled
Traceback (most recent call last):
  File "/mnt/Data/pycharm_repo/Kavida/agentUX/agentux/adapters/mongodb/purchase_orders.py", line 83, in find_unfulfilled_or_uncancelled
    line_items = list(map(lambda x: LineItem(**x), documents))
                                    │              └ [{'_id': ObjectId('662893277916a9c9cd6b283b'), 'po_number': 'split12345-1', 'customer_po_number': [], 'client_id': '610ca70a0...
                                    └ <class 'agentux.domain.models.purchase_order.LineItem'>
  File "/mnt/Data/pycharm_repo/Kavida/agentUX/agentux/adapters/mongodb/purchase_orders.py", line 83, in <lambda>
    line_items = list(map(lambda x: LineItem(**x), documents))
                                 │  │          └ {'_id': ObjectId('662893277916a9c9cd6b283b'), 'po_number': 'split12345-1', 'customer_po_number': [], 'client_id': '610ca70a0b...
                                 │  └ <class 'agentux.domain.models.purchase_order.LineItem'>
                                 └ {'_id': ObjectId('662893277916a9c9cd6b283b'), 'po_number': 'split12345-1', 'customer_po_number': [], 'client_id': '610ca70a0b...
  File "/mnt/Data/pycharm_repo/Kavida/agentUX/.venv/lib/python3.12/site-packages/pydantic/main.py", line 176, in __init__
    self.__pydantic_validator__.validate_python(data, self_instance=self)
    │    │                      │               │                   └ LineItem()
    │    │                      │               └ {'_id': ObjectId('662893277916a9c9cd6b283b'), 'po_number': 'split12345-1', 'customer_po_number': [], 'client_id': '610ca70a0b...
    │    │                      └ <method 'validate_python' of 'pydantic_core._pydantic_core.SchemaValidator' objects>
    │    └ SchemaValidator(title="LineItem", validator=Model(
    │          ModelValidator {
    │              revalidate: Never,
    │              validator: ModelFi...
    └ LineItem()
pydantic_core._pydantic_core.ValidationError: 2 validation errors for LineItem
quantity
  Input should be a valid number [type=float_type, input_value=[100], input_type=list]
    For further information visit https://errors.pydantic.dev/2.7/v/float_type
price
  Input should be a valid number [type=float_type, input_value=[100.0], input_type=list]
    For further information visit https://errors.pydantic.dev/2.7/v/float_type
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/home/adhadse/.local/share/JetBrains/Toolbox/apps/PyCharm-C/ch-0/241.17011.127/plugins/python-ce/helpers/pydev/pydevd.py", line 2238, in <module>
    main()
    └ <function main at 0x7fc3199837e0>
  File "/home/adhadse/.local/share/JetBrains/Toolbox/apps/PyCharm-C/ch-0/241.17011.127/plugins/python-ce/helpers/pydev/pydevd.py", line 2220, in main
    globals = debugger.run(setup['file'], None, None, is_module)
              │        │   │                          └ False
              │        │   └ {'port': 33149, 'vm_type': None, 'client': '127.0.0.1', 'server': False, 'DEBUG_RECORD_SOCKET_READS': False, 'multiproc': Fal...
              │        └ <function PyDB.run at 0x7fc319982480>
              └ <__main__.PyDB object at 0x7fc319db59d0>
  File "/home/adhadse/.local/share/JetBrains/Toolbox/apps/PyCharm-C/ch-0/241.17011.127/plugins/python-ce/helpers/pydev/pydevd.py", line 1530, in run
    return self._exec(is_module, entry_point_fn, module_name, file, globals, locals)
           │    │     │          │               │            │     │        └ {'__name__': '__main__', '__doc__': None, '__package__': '', '__loader__': <_frozen_importlib_external.SourceFileLoader objec...
           │    │     │          │               │            │     └ {'__name__': '__main__', '__doc__': None, '__package__': '', '__loader__': <_frozen_importlib_external.SourceFileLoader objec...
           │    │     │          │               │            └ '/mnt/Data/pycharm_repo/Kavida/agentUX/agentux/adapters/mongodb/purchase_orders.py'
           │    │     │          │               └ None
           │    │     │          └ ''
           │    │     └ False
           │    └ <function PyDB._exec at 0x7fc319982520>
           └ <__main__.PyDB object at 0x7fc319db59d0>
  File "/home/adhadse/.local/share/JetBrains/Toolbox/apps/PyCharm-C/ch-0/241.17011.127/plugins/python-ce/helpers/pydev/pydevd.py", line 1537, in _exec
    pydev_imports.execfile(file, globals, locals)  # execute the script
    │             │        │     │        └ {'__name__': '__main__', '__doc__': None, '__package__': '', '__loader__': <_frozen_importlib_external.SourceFileLoader objec...
    │             │        │     └ {'__name__': '__main__', '__doc__': None, '__package__': '', '__loader__': <_frozen_importlib_external.SourceFileLoader objec...
    │             │        └ '/mnt/Data/pycharm_repo/Kavida/agentUX/agentux/adapters/mongodb/purchase_orders.py'
    │             └ <function execfile at 0x7fc319b71bc0>
    └ <module '_pydev_bundle.pydev_imports' from '/home/adhadse/.local/share/JetBrains/Toolbox/apps/PyCharm-C/ch-0/241.17011.127/pl...
  File "/home/adhadse/.local/share/JetBrains/Toolbox/apps/PyCharm-C/ch-0/241.17011.127/plugins/python-ce/helpers/pydev/_pydev_imps/_pydev_execfile.py", line 18, in execfile
    exec(compile(contents+"\n", file, 'exec'), glob, loc)
                 │              │              │     └ {'__name__': '__main__', '__doc__': None, '__package__': '', '__loader__': <_frozen_importlib_external.SourceFileLoader objec...
                 │              │              └ {'__name__': '__main__', '__doc__': None, '__package__': '', '__loader__': <_frozen_importlib_external.SourceFileLoader objec...
                 │              └ '/mnt/Data/pycharm_repo/Kavida/agentUX/agentux/adapters/mongodb/purchase_orders.py'
                 └ 'import pydantic\nfrom bson import ObjectId\nfrom pymongo.collection import Collection\nfrom pymongo.database import Database...
  File "/mnt/Data/pycharm_repo/Kavida/agentUX/agentux/adapters/mongodb/purchase_orders.py", line 100, in <module>
    data = PurchaseOrdersCollection.find_unfulfilled_or_uncancelled()
           │                        └ <classmethod(<function PurchaseOrdersCollection.find_unfulfilled_or_uncancelled at 0x7fc31282a8e0>)>
           └ <class '__main__.PurchaseOrdersCollection'>
> File "/mnt/Data/pycharm_repo/Kavida/agentUX/agentux/adapters/mongodb/purchase_orders.py", line 89, in find_unfulfilled_or_uncancelled
    logger.error(
    │      └ <function Logger.error at 0x7fc31286c680>
    └ <loguru.logger handlers=[(id=0, level=10, sink=<stderr>)]>
KeyError: "'type'"

Maybe similar to #1008.

The code is something like this:

try:
    documents = item["documents"]
    if len(documents) == 0:
        continue
    line_items = list(map(lambda x: LineItem(**x), documents))
    po = PurchaseOrder(**documents[0], line_items=line_items)
    purchase_orders.append(po)
except pydantic.ValidationError as validation_error:
    from loguru import logger as another_logger
    try:
        logger.error(
            f"validation error {validation_error.errors()}",
            extra_message=validation_error.errors(),

        )
    except:
        another_logger.exception("exception handled")

the another_logger is just to view what's happening inside the logger before it errors out. You can create simple Pydantic model and try validating it in order to recreate this issue.

A simple test in notebook gave me, "'type'" is expected in string to be formatted, but it doesn't exist. How is it possible?

  "{a}, {'b'}".format(a=1)

Error:

  KeyError                                  Traceback (most recent call last)
[<ipython-input-4-78751c3a6bdf>](https://localhost:8080/#) in <cell line: 1>()
----> 1 "{a}, {'b'}".format(a=1)

KeyError: "'b'"
Delgan commented 3 months ago

When using a logging method with positional or keyword arguments, Loguru will try to format your message. Example:

logger.info("Value: {num}", num=42)
# Output: "Value: 42"

I suppose the KeyError you're facing is due to these lines:

logger.error(
    f"validation error {validation_error.errors()}",
    extra_message=validation_error.errors(),
)

The message is a f-string already formatted, but Loguru will tries to format it again due to the extra_message keyword argument. This likely can cause errors depending on the content of validation_error.errors().

Maybe try the following instead:

logger.error("validation error {extra_message}", extra_message=validation_error.errors())
adhadseKavida commented 3 months ago

Cool, I'll add this. Shouldn't loguru internally handle if the key doesn't exist in the string?

Delgan commented 3 months ago

That's not really possible (would imply re-implementing parsing and formatting of str.format()), but I plan to disable the automatic formatting of keyword arguments (since it leads to confusing errors like the one you faced, and because f-string are now prevalent).

adhadse commented 3 months ago

Cool, got it! Thanks Delgan. I'll be closing this issue.