[vim/vim] Vim doesn't preserve the order of messages when callbacks are defined for job_start() or term_start() (Issue #16354)

[bfrg]

Steps to reproduce

Run the following script with vim --clean -S test.vim:

vim9script

const script: list<string> =<< trim EOF
    #!/bin/sh
    printf >&2 '1 stderr\n2 stderr\n'
    printf '3 stdout\n'
EOF

const cmd = '/tmp/test.sh'
writefile(script, cmd)
setfperm(cmd, 'rwxr-xr-x')

const ptybuf = term_start(cmd, {
    err_cb: (ch: channel, msg: string) => {
        echowindow 'stderr:' msg
    },
    out_cb: (ch: channel, msg: string) => {
        echowindow 'stdout:' msg
    },
})

Result: The order of the output of test.sh is not preserved when out_cb and err_cb are set. There's also some weird indentation that's not supposed to be there:

screenshot-2024-12-31_150231.png (view on web)

Also notice the output of :messages:

stdout: 3 stdout^M
stderr: 1 stderr^@2 stderr

There's an extra ^M character for some reasons.

The same behavior can be observed when job_start() is used instead of term_start().

I've looked into the source code and it seems like Vim saves the output (stderr and stdout) from a job but it won't save the order they are received in. Then in the main event loop it just checks if there are messages from a job and if so, it will invoke its callbacks. It looks like out_cb is always invoked before err_cb. And because the shell script prints to stderr and stdout almost simultaneously, the stdout part is processed first.

When adding a short sleep command between the two printf command, the output is processed in the right order, but for some reasons there are unexpected indentations:

#!/bin/sh
printf >&2 '1 stderr\n2 stderr\n'
sleep 0.1
printf '3 stdout\n'

screenshot-2024-12-31_152329.png (view on web)

Expected behaviour

I would have expected the following output in the terminal buffer:

1 stderr
2 stderr
3 stdout

Version of Vim

9.1.954

Environment

Linux, any terminal.

—
Reply to this email directly, view it on GitHub.
You are receiving this because you are subscribed to this thread.Message ID: <vim/vim/issues/16354@github.com>

[Ben Jackson]

stdout and stderr are both synchronised streams at an OS level. This is not solvable and it’s not a vim problem.

This could happen with any program attempting to read stdout and stderr of some subprocess from different streams.

The only solution is to redirect stderr to stdout so they are synchronised at source.

—
Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <vim/vim/issues/16354/2566577602@github.com>

[bfrg]

Then why does it work as expected when both callbacks are removed?

—
Reply to this email directly, view it on GitHub.

You are receiving this because you are subscribed to this thread.Message ID: <vim/vim/issues/16354/2566629041@github.com>

[Christian Brabandt]

Closed #16354 as completed via 9e55474.

—
Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <vim/vim/issue/16354/issue_event/23792657432@github.com>

[bfrg]

bfrg left a comment (vim/vim#16354)

@h-east Thank you for the fix! The indentation issue is definitively fixed.

But for some reasons the order is still not always preserved.

Running

1. vim --clean -S test.vim: order is preserved. Output:

1. 1 stderr
   2 stderr
   3 stdout
   

2. vim --clean -S test.vim test.vim: order is not preserved. Output:

   3 stdout
   1 stderr
   2 stderr
   

3. vim -u NONE -S test.vim test.vim order is preserved. Output:

1. 1 stderr
   2 stderr
   3 stdout
   

I'm not sure why sourcing and editing test.vim is causing an issue in vim --clean.

Tested on Linux.

—
Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <vim/vim/issues/16354/4165612334@github.com>