¿Por qué se retrasa mi salida de un subproceso cuando se genera a partir de un hilo de Python?

Esta es una extensión de mi publicación de ayer, que aún no se ha resuelto: ¿por qué el subproceso de Python con el subproceso no funciona como se esperaba?

Mientras tanto, encontré algunos detalles interesantes, así que decidí crear una nueva publicación. Para llevarlo al punto: hay algunos problemas, cuando un subproceso se genera a partir de un hilo.

Plataforma: Windows 7 Enterprise, Python 3.6.1

En el siguiente código, quiero ejecutar un ejecutable C y obtener su salida a stdout en una cadena. Para fines de prueba, el ejecutable acepta dos parámetros: un retraso y un nombre de archivo (no se utilizan aquí). El progtwig escribe Sleep now en stdout , sleeps durante la cantidad dada de milisegundos y finalmente escribe after sleep y END .

Esta es la fuente C del ejecutable:

 int main(int argc, char *argv[]) { int sleep = 0; FILE * outfile = NULL; if (argc > 1) { sleep = atoi(argv[1]); } if (argc > 2) { outfile = fopen(argv[2], "w"); } printf("Sleep now...\n"); Sleep(sleep); if (outfile) fprintf(outfile, "output-1"); printf("after sleep\n"); printf("END\n"); if (outfile) fclose(outfile); fclose(stdout); exit (0); } 

Este es el código de Python:

 import subprocess import threading import time import os import sys def worker_nok(*args): exe, delay, filename = args proc = subprocess.Popen([exe, delay, filename], shell=False, stdout=subprocess.PIPE, stderr=subprocess.PIPE) out, err = proc.communicate() print("%s:" % (filename,), out) sys.stdout.flush() def worker(*args): exe, delay, filename = args flag = True proc = subprocess.Popen([exe, delay, filename], shell=False, stdout=subprocess.PIPE, stderr=subprocess.PIPE) while flag is True: str = proc.stdout.readline() if str == b"": print("%s: got EOF" % (filename,)) flag = False else: print("%s:" % (filename,), str) print ("%s: END" % (filename,)) sys.stdout.flush() all = [] """ # 4 seconds job_thread1 = threading.Thread(target = worker, args=(["../testapp.exe", "4000", "w4sec.txt"])) job_thread1.start() all.append(job_thread1) # 8 seconds job_thread2 = threading.Thread(target = worker, args=(["../testapp.exe", "8000", "w8sec.txt"])) job_thread2.start() all.append(job_thread1) """ # 4 seconds job_thread3 = threading.Thread(target = worker_nok, args=(["../testapp.exe", "4000", "w4sec.nok"])) job_thread3.start() all.append(job_thread3) # 8 seconds job_thread3 = threading.Thread(target = worker_nok, args=(["../testapp.exe", "8000", "w8sec.nok"])) job_thread3.start() all.append(job_thread3) for t in all: t.join() 

Los trabajos tienen retrasos de 4, 8 y 1 segundos, respectivamente.

worker_nok calls proc.communicate() – fue mi enfoque original, que no funciona: al ejecutar los dos trabajos, obtengo el siguiente resultado:

 w4sec.nok: b'Sleep now...\r\nafter sleep\r\nEND\r\n' w8sec.nok: b'Sleep now...\r\nafter sleep\r\nEND\r\n' 

Todo el grupo se recibe después de 8 segundos. En su lugar, esperaría

 ... 4 sec ... w4sec.nok: b'Sleep now...\r\nafter sleep\r\nEND\r\n' ... 4 sec ... w8sec.nok: b'Sleep now...\r\nafter sleep\r\nEND\r\n' 

Aunque el proceso con 4 segundos está definitivamente finalizado, su salida está disponible solo después de que el segundo trabajo también haya terminado.

Este fue el estado de mi última publicación.

Para averiguar qué es lo que está mal, traté de reemplazar la communicate() mediante la lectura directa de stdout, que se implementa en la función de worker . La condición EOF se identifica cuando la lectura devuelve una cadena vacía. Al llamarlo, me sale:

 ... 4 seconds ... w4sec.txt: b'Sleep now...\r\n' w4sec.txt: b'after sleep\r\n' w4sec.txt: b'END\r\n' ... 4 seconds ... w8sec.txt: b'Sleep now...\r\n' w8sec.txt: b'after sleep\r\n' w8sec.txt: b'END\r\n' w8sec.txt: got EOF w8sec.txt: END w4sec.txt: got EOF w4sec.txt: END 

Sin embargo yo esperaría:

 w4sec.txt: b'Sleep now...\r\n' w8sec.txt: b'Sleep now...\r\n' ... 4 seconds ... w4sec.txt: b'after sleep\r\n' w4sec.txt: b'END\r\n' w4sec.txt: got EOF w4sec.txt: END ... 4 seconds ... w8sec.txt: b'after sleep\r\n' w8sec.txt: b'END\r\n' w8sec.txt: got EOF w8sec.txt: END 

Las grandes preguntas son:

( 1 ) ¿Por qué hay un retraso antes de sleep now ? El ejecutable hace que esta salida esté disponible sin demora. ¿El stdout solo está disponible después de que el proceso haya terminado?

( 2 ) Más importante: ¿Por qué está disponible el EOF para los 4 segundos solo después de que la llamada de 8 segundos haya finalizado?

Espero que esta entrada quede clara, por qué la versión original mostró el comportamiento observado: la stdout está en la condición EOF demasiado tarde y deja la llamada para comunicarse () ¡bloqueando!

Aprecio cualquier entrada, ya que estoy trabajando en eso por más de 12 horas …