Re: vim testsuite: Test_keep_pty_open

[Zhaoming Luo]

On Mon, Feb 03, 2025 at 08:39:09AM +0100, Samuel Thibault wrote:
> Hello,
> 
> Zhaoming Luo, le lun. 03 févr. 2025 12:22:11 +0800, a ecrit:
> > It's still the case with different sleep times. I believe the issue is
> > related to:
> > 
> > ```
> >   5.800000 on 0: Closing channel because all readable fds are closed
> >   5.800000 on 0: Closing channel
> > ```
> 
> I'm not really surprised since it sets out_io and err_io to null. And it
> is indeed saying it's back to waiting, and should be then waiting for
> the process to actually finish. You can try to add printing debugging in
> the waiting function up to the one that would be supposed to actually
> wait.
> 
> Also, to rule out python implementation concerns, maybe replace the
> python script call with your own C program that does the wait and make
> it emit debugging stuff to a /tmp file, to make sure that it's really
> still alive after the sleep.

I did the experiments using my own C waiting program and `sleep` shell
command respectively. They gave me the same result. It seems the sleep
program was not executed at all.

The C program:
```
#include <unistd.h>
#include <stdio.h>

int
main ()
{
    FILE *log;
    log = fopen ("log", "w");
    fprintf (log, "Sleep!\n");
    sleep (3);
    fprintf (log, "Wake up!\n");
    return 0;
}
```

Invoke vim with `./vim --clean --log vimlog`.

Run it in vim:
```
let job = job_start('/bin/sh' . ' -c "/path/to/sleep-prog"', {'out_io': 'null', 
'err_io': 'null', 'pty': 1})
```

On my Arch GNU/Linux I can see the `log` generated by the sleep program,
but on Hurd I can't, so tracking job_start may be the direction.

Another interesting thing I found is the difference between the vim logs
in the cases.

Hurd (failed):
```
...
24.490000 : Starting job: /bin/sh  -c  /home/1speaker/my_sleep/main
24.500000 on 0: Created channel
24.500000 on 0: using pty /dev/ttyp3 on fd 4
24.500000 : SafeState: Start triggering
24.500000 : raw terminal output: "^[[?25l^[[1;1H^[[34h^[[?25h"
24.500000 : looking for messages on channels
24.500000 on 0: Closing channel because all readable fds are closed
24.500000 on 0: Closing channel
24.500000 : SafeState: back to waiting, triggering SafeStateAgain
24.500000 : closing logfile vimlog
24.510000 : looking for messages on channels
24.510000 on 0: Job ended
...
```

GNU/Linux (success):
```
...
8.807417131 : Starting job: /bin/sh  -c  /home/1speaker/my_sleep/main
8.807635262 on 0: Created channel
8.807640822 on 0: using pty /dev/pts/6 on fd 4
8.809397111 : SafeState: Start triggering
8.809395859 : closing logfile vimlog
8.809519562 : raw terminal output: "[?25l[1;1H[?12l[?25h"
8.809534540 : looking for messages on channels
8.809556542 : SafeState: back to waiting, triggering SafeStateAgain
....... (some key input terminal output Safestate stuff)
11.638185297 : looking for messages on channels
11.638224641 : SafeState: back to waiting, triggering SafeStateAgain
11.820336612 on 0: Job ended
11.820453161 : looking for messages on channels
11.820458742 on 0: Closing channel because all readable fds are closed
11.820463010 on 0: Closing channel
...
```

On the Hurd the channels are closed before 'Job ended', but on GNU/Linux
'Job ended' is before 'Closing channel'.

Zhaoming