Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add a -vv log level and make -v more readable #2301

Merged
merged 5 commits into from Mar 11, 2024
Merged

Add a -vv log level and make -v more readable #2301

merged 5 commits into from Mar 11, 2024

Conversation

konstin
Copy link
Member

@konstin konstin commented Mar 8, 2024

Behind error messages, the debug log is the second most important resource to finding out what and why went wrong when there was a problem with uv. It is important to see which paths it has found and how the decisions in the resolver were made. I'm trying to improve the experience interacting with the debug log.

The hierarchical layer is verbose and hard to follow, so it's moved to the -vv extra verbose setting, while -v works like RUST_LOG=uv=debug.

For installing jupyter with a warm cache:

The tracing_subcriber formatter always print the current span, so i replaced it with a custom formatter.

image

Best read commit-by-commit.

@zanieb
Copy link
Member

zanieb commented Mar 8, 2024

Without reading through everything here.. my initial thoughts about logging are:

  • -v should include some additional tracing messages. It should not be for debugging. It should be for users who want to understand what uv is doing. We definitely need to show less messages than our current verbose output. A flat format makes a lot of sense.
  • -vv should include debug level messages. It should be used for debugging. I think using a flat format is fine here too. This should be our recommended level when reporting bugs.
  • -vvv should include trace level messages. It should be used for advanced debugging. Using the nested format makes sense here.

@konstin
Copy link
Member Author

konstin commented Mar 8, 2024

My thought was to not have too many flags but have users quickly switch to RUST_LOG=debug or RUST_LOG=<module>=trace, the filtering feature is something a counted cli flag can't compete with.

@zanieb
Copy link
Member

zanieb commented Mar 8, 2024

I don't think RUST_LOG levels are a reasonable thing to expect from users. It seems like a power-user feature. I agree filtering seems nice but it's not like a counted flag will prevent power users from using it? We don't have to override RUST_LOG if it is set.

@konstin
Copy link
Member Author

konstin commented Mar 8, 2024

We definitely need to show less messages than our current verbose output

Where would you source those messages, from what we currently show as reporter spinner status message?

@konstin konstin closed this Mar 8, 2024
@konstin konstin reopened this Mar 8, 2024
@zanieb
Copy link
Member

zanieb commented Mar 8, 2024

We definitely need to show less messages than our current verbose output

Where would you source those messages, from what we currently show as reporter spinner status message?

I'm not sure! I'm not super familiar with our logging setup. I presume we'd use info! level logs for things that should be shown with -v

The hierarchical layer is verbose and hard to follow, so it's moved to the `-vv` extra verbose setting, while `-v` works like `RUST_LOG=uv=debug`.

For installing jupyter with a warm cache:

* Default: https://gist.github.com/konstin/4de6e466127311c5a5fc2f99c56a8e11
* `-v`: https://gist.github.com/konstin/e7bafe0ec7d07e47ba98a3865ae2ef3e
* `-vv`: https://gist.github.com/konstin/3ee1aaff37f91cceb6275dd5525f180e
Ideally, we would have `-v`, `-vv` and `-vvv`, but we're lacking the the `info!` layer for `-v`, so there's only two layers for now.

The `tracing_subcriber` formatter always print the current span, so i replaced it with a custom formatter.

![image](https://github.com/astral-sh/uv/assets/6826232/75f5cfd1-da7b-432e-b090-2f3916930dd1)
@konstin
Copy link
Member Author

konstin commented Mar 10, 2024

I agree, but we're currently lacking an info! layer, we effectively don't use it at all but only debug! and trace!. I don't want to extend the scope here even more to recategorizing all our debug! into info! and debug!. Instead, i'd like to go ahead with the -v/-vv split now, we can split them into three levels later.

@konstin konstin marked this pull request as ready for review March 10, 2024 15:33
@konstin konstin requested a review from zanieb March 10, 2024 15:33
@konstin konstin changed the title Improve debug logging Add a -vv log level and make -v more readable Mar 11, 2024
@konstin konstin added the tracing Verbose output and debugging label Mar 11, 2024
@konstin konstin merged commit f70ae72 into main Mar 11, 2024
7 checks passed
@konstin konstin deleted the konsti/logging branch March 11, 2024 07:58
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
tracing Verbose output and debugging
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants