logfire icon indicating copy to clipboard operation
logfire copied to clipboard

Google Colab/IPython cell output conflicts on logfire import

Open lifefoundry-scott opened this issue 5 months ago • 13 comments

Description

Problem Statement

We have previously run some python scripts via Google Colab notebooks, usually using the shell command !uv run my_script.py . After instrumenting the codebase with logfire, there is some unexpected behavior blocking cell output.

Logfire configures properly within the script and the script itself executes perfectly. Spans and instrumented functions, auto-instrumented objects, etc are all properly logged and sent to the dashboard. However, the cell output shows Logfire Project URL: ____ (blank) in the output, rendered as expecting input but no change in behavior upon typing anything in. After this appears, everything further is blocked from appearing in the cell output, including print statements, Python logging records, or Logfire logging records (manual and instrumented).

Behavior of the same script is normal locally and in a container on a production server.

Investigation

  • Cell/script output is normal prior to import logfire and importing is what initiates the erroneous behavior.
  • Write token was used to configure, but behavior is the same whether supplied via env variable or logfire.configure(). The blank project URL printout appears prior to configuration regardless, but the write token is working fine as the script executes.
  • When !logfire auth is called, logfire logging statements, print statements, etc behave as expected when manually typed into notebook cells.
  • When !logfire auth is called and then the script is run via shell command, the script file itself behaves properly, but the first imported file that contains a logfire import triggers the erroneous behavior
  • As mentioned, behavior with the same script is normal locally and on a production server, as well as when run via the bash terminal supplied with the colab notebook.
  • Tried all documented logfire.configure() settings and environment variables, which seem not to do anything because the problem occurs on logfire import
  • Tried some Colab and IPython settings to reduce rendering of outputs, no luck there

Workarounds

  1. uv run my_script.py &> output.txt writes the expected output to the file
  2. Executing using the %%bash or %%sh cell magics prints the expected output, albeit dumped at the end of execution rather than printed real-time

Expected Behavior

  1. Importing logfire and using logfire-instrumented code does not cause any erroneous behavior that blocks real-time print statements, logging records, or logfire console outputs. If need be, environment variables, or config/credential files are supplied prior to script execution.
  2. Alternatively, a flag or environment variable is set that disables interactive outputs (and raises exceptions if disabled when CLI commands are called that rely on them)

Thanks! Enjoying logfire so far in general and looking forward to the future development

Python, Logfire & OS Versions, related packages (not required)

Behavior exhibited on 3.21.1 and 3.25.0

lifefoundry-scott avatar Jul 22 '25 00:07 lifefoundry-scott

I'm not able to reproduce any problems by just importing logfire. But I can see that printing the project link is a problem. Here's how to prevent that:

import logfire

logfire.configure(console=logfire.ConsoleOptions(show_project_link=False))

Here's a demo of the general problem:

import rich
import threading
import time

def p():
    rich.print('before link [link=link_url]inside link[/link] after link')

threading.Thread(target=p).start()
print('before rich')

time.sleep(1)

print('after rich')

This prints:

before rich
before link 

This seems like an issue to report to Google Colab and/or rich.

alexmojaki avatar Jul 22 '25 10:07 alexmojaki

Appreciate the demo! It's definitely possible I misinterpreted the issue as being related to logfire import. Unfortunately setting show_project_link to False does not prevent the issue on my side, but my workaround is good enough for now and I'll look into escalating the issue with Colab and/or rich.

lifefoundry-scott avatar Jul 22 '25 21:07 lifefoundry-scott

what does print(1); import logfire; print(2); logfire.configure(); print(3) do?

alexmojaki avatar Jul 22 '25 22:07 alexmojaki

Just noticed that threading isn't needed:

%%writefile issue.py
import rich

print('before rich')

rich.print('before link [link=link_url]inside link[/link] after link')

print('after rich')

alexmojaki avatar Jul 22 '25 22:07 alexmojaki

what does print(1); import logfire; print(2); logfire.configure(); print(3) do?

I've done some further digging and found it was an import of a different library that is triggering something. print(1), print(2), print(3) are working but print(4) after that library is imported is where the problem starts. I'll have to dig deeper into its dependencies

PS: While setting console=False or the show_project_link=False in logfire.configure() does not help, setting these via environment variables does prevent the issue.

lifefoundry-scott avatar Jul 22 '25 22:07 lifefoundry-scott

print(4) after that library is imported is where the problem starts

are you sure that's not just because importing that library takes time and the project link gets printed in the background thread?

PS: While setting console=False or the show_project_link=False in logfire.configure() does not help, setting these via environment variables does prevent the issue.

but logfire.configure(console=False) doesn't print the project link, right?

alexmojaki avatar Jul 22 '25 23:07 alexmojaki

are you sure that's not just because importing that library takes time and the project link gets printed in the background thread?

This could be the case, I was manually imported the dependencies of that other library and I saw importing beautifulsoup4 triggered the issue roughly half the time. Same thing with another of its dependencies weasyprint, which was slower import and triggered every time. However trying these in the minimal example notebook did not trigger anything

Update: Yes, importing a dummy file with time.sleep(10) in it consistently triggers.

but logfire.configure(console=False) doesn't print the project link, right?

If this is set, or the ConsoleOptions(show_project_link=False) is set, it still shows the blank project URL printout. Only if the environment variable is set does it not print any project link or block the outputs

lifefoundry-scott avatar Jul 22 '25 23:07 lifefoundry-scott

If this is set, or the ConsoleOptions(show_project_link=False) is set, it still shows the blank project URL printout. Only if the environment variable is set does it not print any project link or block the outputs

sounds like something else is calling logfire.configure()

alexmojaki avatar Jul 23 '25 19:07 alexmojaki

I double-checked, but it's the only time it's called from my code

lifefoundry-scott avatar Jul 23 '25 21:07 lifefoundry-scott

You're saying that if you remove logfire.configure(), no project URL gets printed, but adding logfire.configure(console=False) prints a project URL? That definitely doesn't happen locally.

alexmojaki avatar Jul 23 '25 21:07 alexmojaki

Sorry, you're right. configure() was being called a second time from an init.py file. Now setting logfire.configure(console=False) does not print out the project URL, and commenting out logfire.configure() raises the LogfireNotConfiguredWarning when an instrumented function is called, and prints nothing in the console if no instrumented function is called.

With that out of the way I was able to consistently reproduce the issue with the example below. In my actual case, the issue is triggered part of the way into the workflow when reading Google sheets with gspread, which takes a few seconds.

%%writefile logfire_example.py
print('_top-level file imports')
import logging
import time
import logfire

print('_begin import chain')
time.sleep(1) #imports here
print('_end import chain')

print('_configuring logger')
logger = logging.getLogger(__name__)
logging.basicConfig(level=logging.INFO, force=True)

print('_configuring logfire')
logfire.configure(token="valid_logfire_token")
print('_top-level file imports done')

@logfire.instrument(              #Behavior is the same with and without instrumentation
    msg_template="msg",
    span_name="span",
)
def runner(*args):
    print('Begin func')
    time.sleep(1)
    print('End func') # Does not print when valid logfire token provided

if __name__ == "__main__":
    runner()

Prints:

_top-level file imports
_begin import chain
_end import chain
_configuring logger
_configuring logfire
_top-level file imports done
Begin func
Logfire project URL:    

lifefoundry-scott avatar Jul 23 '25 23:07 lifefoundry-scott

Image

I ran threading.enumerate() before and after the time.sleep() and found which thread has died

lifefoundry-scott avatar Jul 23 '25 23:07 lifefoundry-scott

Yes, the token is checked in a background thread, and if it's valid it prints the project URL.

OK there's no more mystery here. I think we can just remove the link styling, it's not really useful.

alexmojaki avatar Jul 24 '25 09:07 alexmojaki