shell output is truncated sometimes

shell output is truncated sometimes

Hi. I cannot reproduce this yet but I've seen it happen multiple times. When I can reproduce it(seems unlikely though), I'll submit a ticket to http://www.midnight-commander.org/report

From easy things like executing pwd and getting nothing output, to things like doing a long find and having a some hundreds of lines at the end not show up on the screen, both times when checking the screen with C-o (I didn't have pause after terminal output set to always, in the last case, but I checked first case with both "always" and "on dumb terminals" - same effect)

Tested with latest git version also.
Maybe something else is at fault here, not mc. Maybe it depends on my terminal which isn't flushing, sometimes, for some reason; no idea.

tested with xfce4-terminal 0.6.3 (Xfce 4.10) ($TERM reports xterm), libvte 0.28.2-4

EDIT: happened again with a relatively long git status:

...
    deleted:    texts/system/manjaro/random logs/acpidump/ssdt1.dat
    deleted:    texts/system/manjaro/random logs/acpidump/ssdt1.dsl
    deleted: Press any key to continue...

the "Press" part is from "Pause after run: Always" Configuration option. (but I guarantee this option doesn't affect the truncation, whether it's on or off - it just helps me not have to C-o to look)
I'll try to use rxvt because it doesn't use libvte, if it works, it may be vte or it may be xfce4-terminal, although the truncation doesn't happen anywhere else, other than with mc in the shell.
Back to xfce4-terminal, once that truncation above happened, doing git status again several times, doesn't make it happen, although sometimes a pause is noticed of about 0.5 sec in the output where it would've truncated but then it continues. Doing this like 10 times eventually causes the truncation again but in a different place:

...
    deleted:    texts/system/manjaro/bugs/radeon/black screen when radeon is module/logs/quirk_working.txt
    deletPress any key to continue...

and this time happened twice in a row:

    deleted:    system/manjaro/home/emacs/.vim/bundle/workflowish/t/convert_from_workflowy.vim
    deleted:    system/manjaro/home/emacs/.vPress any key to continue...

Hi again, I just managed to make the truncation (in OP in edit ^ ) happen with rxvt (and mc) also, which tells me it's not libvte doing it. (But correct me if I'm wrong.)

this is the last lines, with rxvt:

    deleted:    texts/system/manjaro/bugs/cpu/CPU1 not responding/when cpu cores fail/fails/3cores again 2/bootlog3cores.txt
    deleted:    texts/system/manjaro/bugs/cpu/CPU1 not responding/when cpu cores fail/fails/3corePress any key to continue...

at least now I can say more surely that it's probably mc doing it.

Doing git status again, worked, but doing it one more time, made it truncate output again, but in a different place:

    deleted:    texts/system/manjaro/bugs/kernel/3.15.4/system freeze textcursor frozen too/in 3.12 (stock manjaro but modified config) with this config still works/still works with this config/when both cards enabled in bios/dmesg31223_bothcards.txt
    delePress any key to continue...

the "Press any key to continue..." is from "Pause after run: Always" Configuration option.

I still haven't found a way to reproduce this. It seems to happen whenever, after a while, unsure about the conditions. Both with xfce4-terminal and rxvt now.

EDIT: here's a new one, with less than 1 screen of output happening:

atures/fglrx"&& git status
On branch master
Press any key to continue...

atures/fglrx"&& git status
On branch master
Your branch is ahead of 'origin/master' by 3 commits.
  (use "git push" to publish your local commits)

Changes not staged for commit:
  (use "git add <file>..." to update what will be committed)
  (use "git checkout -- <file>..." to discard changes in working directory)

    modified:   ../../../filesystem now/home/emacs/.bashrc
    modified:   ati_state.txt

no changes added to commit (use "git add" and/or "git commit -a")
Press any key to continue...

the atures/fglrx"&& part is my bash prompt (imagine it's just current folder and $)
I Executed the same command twice git status but the first time only the first line from the output was shown (C-o to see the shell screen, from within mc) and the second time it just worked.

Here's what I found out about this thus far:
1. reproduce this issue 100% of the time by inserting a sleep 1 after pwd and before kill in this line:
https://github.com/MidnightCommander/mc/blob/cd737f8956f8d8915063cd38923b4c0fcb5d5be8/src/subshell.c#L877
so it looks like:
" PROMPT_COMMAND='pwd>&%d;sleep 1;kill -STOP $$'\n", subshell_pipe[WRITE]);

To test just run echo a repeatedly while in mc with the subshell option enabled (and I've also the option to Always Pause after run which is in Options-Configuration ) and observe the subshell output (there's no need to use C-o).

2. avoid this issue 100% of the time by inserting a sleep 1 before pwd on the same line, so it looks like this:
" PROMPT_COMMAND='sleep 1;pwd>&%d;kill -STOP $$'\n", subshell_pipe[WRITE]);
(inserting an echo 1 for example won't work, the issue remains unaffected)

3. what seems to be happening is that the output from the shell is apparently not flushed(or something similar to this effect), but the output from the pwd to that pipe is being received even though it happens afterwards. https://github.com/MidnightCommander/mc/blob/cd737f8956f8d8915063cd38923b4c0fcb5d5be8/src/subshell.c#L493
Basically https://github.com/MidnightCommander/mc/blob/cd737f8956f8d8915063cd38923b4c0fcb5d5be8/src/subshell.c#L517 usually gets executed before https://github.com/MidnightCommander/mc/blob/cd737f8956f8d8915063cd38923b4c0fcb5d5be8/src/subshell.c#L537 and when the issue happens, only the latter gets executed (and that while block usually runs twice when everything is ok triggering L517 and then L537 ; but when the issue is in effect it only runs once triggering only L537)

It may be possible that the kill -STOP is possibly killing bash too soon to allow it to flush? but then again that doesn't explain why the position of the sleep 1 acts in completely opposing ways, even though both are before the kill.
I've also tried zsh and the same issue seems to be in effect but I haven't tried the fix from 2. with zsh.

I've run these tests on what is currently the latest commit: MidnightCommander/mc@c7ff7b3 even though the links above (to lines) are referring an older commit (latest commit for that specified file though) just so that the links are persistent and don't point to lines in master which will change in the future.

Here's what seems to be happening, as far as I can tell:

1. the output from pwd from here https://github.com/MidnightCommander/mc/blob/cd737f8956f8d8915063cd38923b4c0fcb5d5be8/src/subshell.c#L877 triggers the select from here https://github.com/MidnightCommander/mc/blob/cd737f8956f8d8915063cd38923b4c0fcb5d5be8/src/subshell.c#L493 before the output from the shell does. And the way that function feed_subshell is coded seems to assume that they happen in order: that is, the output from the shell triggers the select until it's emptied and then the output from the pwd triggers that select last. But this doesn't happen all the time (and it's easily reproducibile to not-happen by 1. in my previous comment). So since feed_subshell bails out with a return TRUE here https://github.com/MidnightCommander/mc/blob/cd737f8956f8d8915063cd38923b4c0fcb5d5be8/src/subshell.c#L554 when the pwd input is received, it then forgets the output from the shell, since this one will sometimes be after the pwd one, even though it was assumed they would be in order (which happens most of the time, but not always). Therefore the shell output(or at least some (last)part of it) is missed and not shown. (with my echo a example, the entire command and its output is missed)
   I'll explore a solution, but if anyone has any, feel free to say so and/or maybe implement it - otherwise, I may find one, given some time.

I'm using this hacky patch: EDIT: replaced patch to fix whitespace in order to allow it to be applied(and also removed comments): https://github.com/emanueLczirai/coostomhuston/blob/23876a61ff836276b438cfdf7ca4040c72e7759c/system/lenovo%20z575/OS/manjaro/filesystem%20now/home/emacs/build/mc-git/fix_the_sometimes_truncated_shell_output_in_mc.patch

(ignore this unless you want to read the comments which are lacking from the above ^ patch)
The old patch with broken whitespace(but with some comments): https://github.com/emanueLczirai/coostomhuston/blob/3d536afc839353911be726bdc349c56ba25449ef/system/lenovo%20z575/OS/manjaro/filesystem%20now/home/emacs/build/mc-git/flush_issue_official_patch/fix_the_sometimes_truncated_shell_output_in_mc.patch

I've tested it for a while to make sure it fixes this issue. It's good enough for me and therefore I will stop any further work on this.

---

Here's the (same)patch with debugging code still in and some comments(but the debugging defines aren't defined, at top of file): https://github.com/emanueLczirai/coostomhuston/blob/3d536afc839353911be726bdc349c56ba25449ef/system/lenovo%20z575/OS/manjaro/filesystem%20now/home/emacs/build/mc-git/debug_flush_issue/mc-git_debug_the_subshell_flush_issue.patch
(EDIT2: note that you can't apply this patch right away due to whitespace issue)