Feeding minus with text from a network call results in corrupted text until resizing

[Kinchkun]

Describe the bug

Hi,

I'm using reqwest and tokio to make an async network call. Utilizing the stream feature of reqwest I'm reading chunks of the response text and write! it into minus using the dynamic_paging feature.

Then the text, line numbers and so forth gets corrupted until I resize the terminal window, which (I assume) causes a refresh of the view.

To Reproduce

use bstr::ByteSlice;
use bytes::Bytes;
use minus::LineNumbers;

#[tokio::main]
async fn main() {
    use futures::StreamExt;
    use minus::{dynamic_paging, MinusError, Pager};
    use std::fmt::Write;
    use tokio::{join, task::spawn_blocking};

    let pager = Pager::new();
    pager.set_line_numbers(LineNumbers::Enabled).unwrap();

    let task = async {
        let mut pager = pager.clone();
        let client = reqwest::Client::default();
        let mut stream = client.get("https://www.google.de/")
            .send()
            .await
            .unwrap()
            .bytes_stream();

        while let Some(chunk) = stream.next().await {
            let bytes: Bytes = chunk.unwrap();
            let text = bytes.to_str_lossy().to_string();
            write!(pager, "{}", text).unwrap();
        }
        Result::<_, MinusError>::Ok(())
    };

    let pager = pager.clone();
    let (res1, res2) = join!(spawn_blocking(move || dynamic_paging(pager)), task);
    res1.unwrap().unwrap();
    res2.unwrap();

}

Cargo.toml

[package]
name = "minus-bug"
version = "0.1.0"
edition = "2021"

[dependencies]
reqwest = { version = "0.11.10", features = ["stream"] }
minus = { version = "5", features = ["dynamic_output", "search"] }
tokio = { version = "1.17.0", features = ["full"] }
futures = "0.3.21"
anyhow = "1.0.56"
bytes = "1.1.0"
bstr = "0.2.17"

Screenshots

This is the immediate result:

As you can see, the line numbering is wrong and the content ins't correctly display. However, if I now resize the terminal everything is fine:

Desktop:

• OS: macOS 12.2.1
• Terminal: Iterm and the native terminal.app
• Shell: zsh
• minus Version: 5.0.1

Additional context

When I don't stream the text-chunks but instead using the text method from reqwest, which loads the complete text into a single string with a single write! it works like a charm.

[AMythicDev]

Thanks for filing up the issue. I am actually super busy right now but I will still try to get a fix ready. If you want to help, you can file a PR with the fix. Also if you need any help, you can hop on our Discord or Matrix room.

[Kinchkun]

Hi,

thank for your response!

I have at least a workaround:

while let Some(chunk) = stream.next().await {
    let bytes: Bytes = chunk.unwrap();
    let text = bytes.to_str_lossy().to_string();
    // only write one line at a time
    for line in text.lines() {
        writeln!(pager, "{}", line).unwrap();
    }
}

If I wrote one line at a time it works as expected. I assume the error occurs when writing long lines which contains \n. A wild guess would be that something at the wrapping is wrong.

[AMythicDev]

I have fixed the issue and did the test that you had initially performed.

[anewton1998]

I know this issue is closed, but I am experiencing the same problem. My program makes REST calls with reqwest, and there is always a blank line in the output. Because my program can cache, when data is pulled from the cache there is no blank line (reqwest is never called). I've tried all the tokio settings, and tried writing the data one line at a time but nothing fixes it. And, resizing the terminal causes the blank like to go away.

minus version is "5.3", tokio is "1.29" and reqwest is "0.11" (they are all the latest at this time).

Since the code is open source and on crates.io, you should be able reproduce it with the following:

cargo install icann-rdap-cli

# -N turns off the cache
rdap -N --log-level debug icann.org

# first run will put data in the cache, run again and the issue goes away
rdap --log-level debug icann.org

[AMythicDev]

I will look at it tomorrow.

[AMythicDev]

@anewton1998 So finally I got some information regarding the issue. I setted up logging to get more info and I discovered that line 7 of the output appears empty in the logs but gets displayed in the output. That's kinda strange and I don't see it with any other lines. I tried to take a look at the actual lines sent by the main program but for unknown reasons the program just suddenly stopped working. Maybe I have to compile your whole program again. (It takes a good amount of time to compile 😞)

[anewton1998]

Perhaps you are being rate-limited by the domain registry's server. Maybe try an RIR query:

rdap --log-level debug 199.43.135.53

Thanks for looking at this. It is a very hard problem to solve. I played around with all the Tokio features but nothing changes the behavior. You can also see that these blank lines do not show up when sending straight to the console. This can be demonstrated with the -P none option.

[AMythicDev]

The issue is being caused due to tracing::debug! () call that I am putting in the make_append() function. minus's default examples work fine but your program just doesn't get to the display. (tracing is little weird tbh). Guess I will have to run a debugger to get more details.

[anewton1998]

Would it help if I moved from the simplelog crate to the tracing crate? That also might explain why it appears when reqwest is used, because I believe it uses tracing as well.

[AMythicDev]

I am not sure cuz it is difficult to get any sensible information from all the info that I collect so far. There are several calls to tracing but only one call at the very start of append_text() function is causing the display to not load. You may try moving to simplelog and post any valuable info that you can extract.

[anewton1998]

When I attempt to use tracing-subscriber, the screen locks up. I suspect there is something going on between tracing-subscriber and StdoutLock

[AMythicDev]

This is kinda obvious as minus locks the Stdout so that other stuff cannot break the display.
BTW I am using the json feature along with tracing-appender to get the logs.

[AMythicDev]

So finally I fixed that. If you want to know more on why all the bug occurred, you can check the commit message.
I will get a patch release in a few days as the solution that I posted right now are no that efficient and can be optimized.
BTW The tracing call was blocking because rdap-cli sends data to minus before minus initializes the interface but after it has acquired the Stdout lock. So tracing just waits until stdout becomes free again (which it never gets).
Thanks ❤️ for raising the issue.

[anewton1998]

Thanks for chasing down the bug.

I just figured out a way to get tracing_subscriber to work using with_writer.

Is there anything I need to do to stop the behavior of sending data to minus before it is fully initialized? Doing so would mean I could get rid of my workarounds for tracing_subscriber and termimad.

[AMythicDev]

Well can we just move to a Discussion so that this issue doesn't become filled with unrelated topics. I hope you don't mind.