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

[BUG] Log flood in the debug console by default. #714

Open
vi opened this issue Feb 10, 2023 · 5 comments
Open

[BUG] Log flood in the debug console by default. #714

vi opened this issue Feb 10, 2023 · 5 comments
Labels

Comments

@vi
Copy link

vi commented Feb 10, 2023

Describe the bug

Debug console with logs show too many DEBUG-level messages by default.

To Reproduce

Implement simple app based on README and some functions' documentation. In particular, use toggle_debug_console and logger::init.

    let mut siv = Cursive::new();
    cursive::logger::init();

    let linear_layout = LinearLayout::vertical()
    .child(TextView::new("Top of the page"))
    .child(TextArea::new().fixed_size((20, 5)))
    .child(Button::new("Ok", |s| s.quit()));
    siv.set_window_title("myapp");
    siv.add_fullscreen_layer(linear_layout);
    
    siv.add_global_callback('~', Cursive::toggle_debug_console);
    siv.add_global_callback('q', |s| s.quit());
    
    siv.run();

Expected behavior

Resulting console activated by ~ contains few logs (unless errors happen) from Cursive itself (e.g. just something like "Hello from Cursive version ... running on backend ... on terminal ... on locale ...", "Main window initialized", etc.). New logs from user app are easily visible in it. Interaction with the debug console itself (e.g. scrolling it) does not typically produce new logs. Debug-level logs (especially from Cursive itself) appear only if user explictily configures it from within the code or environment.

Actual behavior

The console is flooded by DEBUG-level logs originating from Cursive itself, which pile up more and more as I attempt to scroll the console to the bottom. Even starting with RUST_LOG=info does not seems to stop this.

Environment

  • Operating system used: Linux Debian Bookworm amd64
  • Backend used: ncurses
  • Current locale: C.UTF-8
  • Cursive version: 0.20.0
@vi vi added the bug label Feb 10, 2023
@gyscos
Copy link
Owner

gyscos commented Feb 21, 2023

Hi,
That's interesting; what kind of debug logs are you seeing?

Grepping for log:: in the repo, I see a couple warn!, but that's about it. It's possible some dependencies do emit logs of their own though; emitting a lot of things at the DEBUG level doesn't sound unreasonable.

The current logger implementation is also very basic, and doesn't offer much filtering. Something like flexi-logger should allow you to specify per-module levels, so you could only allow warnings and errors from cursive (and other dependencies), but see info logs from your own module.

@blaisdellma
Copy link
Contributor

Running the above example, I'm seeing logs from

I'm using tracing with tracing-subscriber and it has a feature 'env-filter' which allows you to set per-module logging levels. Without it I get spammed with debug messages from LinearLayout.

It seems like even when at the bottom of a ScrollView scrolling causes a redraw and triggers more debug messages. I think this is because the debug console is added as a layer on the current screen so scrolling the debug console causes the rest of the screen to be redrawn. I guess this didn't get caught cause only some views have debug messages in draw(). Searching for log::debug shows that only 3 views (LinearLayout, TextArea, and ListView) use debug messages at all . The only other parts of cursive that use log::debug are the ncurses and pancurses backends.

Also, the reason that setting RUST_LOG=info is ineffective is because CursiveLogger::enabled() is hardcoded to true, instead of checking the log level. There's even a TODO in CursiveLogger::init() for this.

I think this can be addressed by:

  • changing CursiveLogger to set a log level by checking RUST_LOG or as an argument to cursive::logger::init()
  • changing the debug console to use a new screen instead of just a layer on the current screen to avoid redrawing application and triggering lots of extra debug messages when scrolling

@Toerktumlare
Copy link

i experienced this today also, in the debug console, logs are flooded with cursive logs. Nice to see that this is being addressed. When might we see a new release with the fixed?

@JimmyCabbage
Copy link

I am experiencing problems with this as well, whenever I use cursive with a logger that has the log level set to debug, cursive spews my log with tens-of-thousands of logs of updates to positions, sizes, and other such things, and without buffering they choke the application due to the sheer amount of IO.

Screenshot of log file:
cursivelogs

In my opinion, some of these debug statements might serve better as trace statements, as they are in excess and drown out other debug logs, but I would like to hear a second opinion.

@gyscos
Copy link
Owner

gyscos commented Nov 8, 2024

True, we could reduce the level of these.
You might also be able to apply a lower level threshold to your own code, while keeping info-only for third party code.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

5 participants