`console` port to tokio: AsyncWrite flush issue

[azriel91]

heya,

I'm trying to port console::Term to use tokio::io::{AsyncRead, AsyncWrite},
While I've gotten it to compile, I get unexpected / undesirable output:

# original
❯ cargo run -q --example term                                                                                         
Going to do some counting now
Done counting!
Hello World!
To edit: default

default

on the tokio port

# many weird variations of
Going to do some counting now
Done counting!
Counting 4/10 Hello World!

                        # ^ caret is here, on the next line

One can try it out by running:

git clone git@github.com:azriel91/console.git --branch spike/tokio-async
cd console
cargo run -q --example term

I know it looks like a flushing issue, but I've tried flushing after every write, and still see the same symptoms.

Would anyone be able to help solve it? I've been on this for a number of hours, but can't figure it out.

[azriel91]

Adding a \r to Term::write_line narrows the issue down. Some output variants:

One:

Done counting!me counting now

Hello World!
To edit: default

Two:

Going to do some counting now

Hello World!g!
To edit: default

default

Is it possible for two separate tasks that both use tokio::io::stdout() to be scheduled in reverse order, even if they were sequentially submitted?

[alice]

@azriel91

Is it possible for two separate tasks that both use tokio::io::stdout() to be scheduled in reverse order, even if they were sequentially submitted?

Yes. Tokio provides no guarantees about how tasks are scheduled, other than that all ready tasks are eventually scheduled.

[azriel91]

Hm, thanks for that, and given the following (cut down) version of the code that produced that:

term.write_line("Going to do some counting now").await?;
term.write_line(&format!("Counting {}/10", style(10).cyan())).await?;
term.clear_last_lines(1).await?;
term.write_line("Done counting!").await?;
term.write_line("Hello World!").await?;
term.write_str("To edit: ").await?;

Every method ends with a .flush().await at the end of the method call.

all ready tasks are eventually scheduled.

I'm guessing the non-sequential scheduling shouldn't be the cause of the non-sequential output in this case right?

Since the tasks are sequentially awaited, then it should be sequential (even with the non-sequential scheduler, since the tasks are sent one at a time).

Other observations:

• In One, Done counting! (code line 4) is written over code line 1.

  The clear_last_lines(1) terminal control character must be output twice, even if the code only writes it once. Perhaps this is, stdout internally has its own buffer, and flush()ing twice writes the same buffered bytes out.

• In Two, code line 5 is written over code line 4

  Done counting! is meant to be in output line 2, but it is in output line 3, and the \r brings the caret back to the beginning of the line for Hello World! to write over it. Somehow two \ns got written for Done counting! to move down an extra line. Possibly same explanation as the previous point.

One thing that may be relevant is, the flush() runs tokio::io::stdout().flush().await, instead of tokio::io::Stdout being held on the Term type. Maybe I'll try that.

[alice]

If you're creating a new stdout on each write, then that is why. You have to flush on each write if you do that.