comet-ml / opik

Open-source end-to-end LLM Development Platform
Apache License 2.0
2.44k stars 151 forks source link

[Bug]: litellm integration logs tag more than once #528

Open dsblank opened 1 month ago

dsblank commented 1 month ago

Willingness to contribute

Yes. I can contribute a fix for this bug independently.

What component(s) are affected?

Opik version

Describe the problem

When I run the below code, the tag "openai" is repeated multiple times.

image

Above you can see two "openai". Sometimes it shows 15.

And two other items can be seen when running the code:

Traceback (most recent call last):
  File "/home/dblank/miniconda3/envs/py310/lib/python3.10/site-packages/litellm/integrations/opik/opik.py", line 68, in __init__
    asyncio.create_task(self.periodic_flush())
  File "/home/dblank/miniconda3/envs/py310/lib/python3.10/asyncio/tasks.py", line 336, in create_task
    loop = events.get_running_loop()
RuntimeError: no running event loop

and:

/home/dblank/miniconda3/envs/py310/lib/python3.10/site-packages/litellm/integrations/opik/opik.py:74: RuntimeWarning: coroutine 'CustomBatchLogger.periodic_flush' was never awaited
  self.flush_lock = None
RuntimeWarning: Enable tracemalloc to get the object allocation traceback

But it appears to log everything.

Reproduction steps

Here is the stripped down code:

import litellm
from litellm.integrations.opik.opik import OpikLogger
import opik
import os
from uuid import uuid4

model = "openai/gpt-3.5-turbo"

# Set these:
os.environ["OPIK_WORKSPACE"] = "WORKSPACE"
os.environ["OPIK_API_KEY"] = "COMET-API-KEY"
os.environ["OPIK_PROJECT_NAME"] = "bug-test"
os.environ["OPENAI_API_KEY"] = "OPENAI-API-KEY"

def get_response(stream):
    for chunk in stream:
        if chunk["choices"][0]["delta"]["content"]:
            yield chunk["choices"][0]["delta"]["content"]

opik.configure(use_local=False)

logger = OpikLogger()

litellm.callbacks = [logger]

# Get a new prompt, and stream the output:
prompt = "Why do birds sing?"

stream = litellm.completion(
    model=model,
    messages=[
        {"role": "user", "content": prompt}
    ],
    metadata={
        "opik": {
            "tags": [model],
            "chat_id": str(uuid4()),
        },
    },
    stream=True,
)
response = "".join(list(get_response(stream)))
print(response)

This shows the tag "openai" added from litellm integration twice. Sometimes it adds 15 or more.

dsblank commented 1 month ago

Also, it might be related to the logger. It looks like if I reuse the logger, it keeps add the "openai" tag over and over.

dsblank commented 1 month ago

Regarding the traceback, and looking at https://github.com/BerriAI/litellm/blob/main/litellm/integrations/opik/opik.py#L67-L74

It doesn't seem like this is a situation where we should show a traceback, but just info. I don't understand the consequences, but it seems everything works correctly if async periodic flushing is not enabled.

        try:
            asyncio.create_task(self.periodic_flush())
            self.flush_lock = asyncio.Lock()
        except Exception as e:
            verbose_logger.exception(
                f"OpikLogger - Asynchronous processing not initialized as we are not running in an async context {str(e)}"
            )
            self.flush_lock = None