Python3.5 subprocess not writing on terminal while writing print logs in file

December 26, 2017 1.5k views
Python Logging CentOS

Below is my script which calls another script using below example and produces entire output after execution is completed while expectation is that it should produce live output as well as write in file at the same time.

My_Tests.py :

from subprocess import Popen, PIPE, STDOUT
with Popen("./tests.py", stdout=PIPE, stderr=STDOUT, bufsize=1, universal_newlines=True) as p, \  
    open('tests.log', 'ab') as file:  
    for line in p.stdout: # b'\n'-separated lines  
        print(line, end='') #new addition  
        sys.stdout.buffer.write(line)  
        file.write(line)

Results:

./My_Tests.py ALL
TC 1 : PASSED
TC 2 : PASSED
Tatal Passed Tests : 2
Tatal Failed Tests : 0 

Issue: Execution of script is not producing output line by line and printing entire output in the end while expectation is terminal logging and saving logs in file shall happen simultaniously.

2 Answers

You may want to question your expectations.

Popen() will not call "tests.py" to run and then continue with the execution of "My_Tests.py".
This is called "blocking", what you want is a "non-blocking" way to call a new process from a python script.

From the "subprocess" documentation (https://docs.python.org/3/library/subprocess.html):
Run the command described by args. Wait for command to complete, then return a CompletedProcess instance.

You can read in the middle of the process stdout, stderr and you can write to stdin.
The problem are always the buffers.

First where you have to deactivate the buffers from tests.py.
The -u option deactivates all buffers, so the output is directly written to stdout.
No program change in your tests.py.

cmd = ['python', '-u', './tests.py']
proc = Popen(cmd, stdout=PIPE) 

The second buffer "problem" is with writing to an open file. When you open a file, even in binary mode, fd.write(data) does not immediately write to disk.

But you can control the buffer:

fd = open('tests.log', 'ab', buffering=0)

You can only deactivate the buffer only in binary mode.

Additionally you can read always one byte. This is only interesting, when the output of one line takes veeeery long or if you handle with real binary data.

Have another answer? Share your knowledge.