gyscos / cursive

A Text User Interface library for the Rust programming language
MIT License
4.25k stars 244 forks source link

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

Open vi opened 1 year ago

vi commented 1 year ago

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

gyscos commented 1 year ago

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 commented 1 year ago

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:

Toerktumlare commented 1 year ago

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?