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
