How to intercept "pipenv install" spinner-like output messages with subprocess?

user_1815047 0
Viewed 530

I'm trying to read the output of the "pipenv install" (pipenv==2018.11.26, Python 3.6.0) command run via subprocess.Popen as the output is produced, i.e. not when the whole process has ended, because depending on the amount of data it has to download, on the connection speed, etc it might take a long time.

I'm printing all stdout and stderr messages and adding a prefix to them, but I still can't understand where this sort of "spinner" message: "[== ] Creating virtual environment..." is coming from.

Here's the complete code I'm running

import subprocess
import threading

cmd = ['pipenv', 'install','--ignore-pipfile']
cwd = 'test'

def run_cmd(cmd,cwd):
    popen = subprocess.Popen(cmd, cwd=cwd, stdout=subprocess.PIPE, stderr=subprocess.PIPE,bufsize=1)

    a = threading.Thread(target=printTh,args=("stdout",iter(popen.stdout.readline, b"")))
    a.start()

    b = threading.Thread(target=printTh,args=("stderr",iter(popen.stderr.readline, b"")))
    b.start()

    while popen.poll() is not None:
        a.join()
        b.join()

def printTh(pipe_name,iter):
    for line in iter:
        print(pipe_name+"->"+line.rstrip().decode("utf-8"), end = "\r\n",flush =True)


run_cmd(cmd,cwd)

On my gui console I can see that everything has a prefix except the spinner "[ ===] Creating virtual environment.." message that doesn't belong to neither stderr not stdout:

Console print:

stderr->Creating a virtualenv for this project…
stderr->Pipfile: C:\Users\ahadu\test\Pipfile
stderr->Using C:/Program Files (x86)/Anaconda3/python.exe (3.6.0) to create virtualenv…
[ ===] Creating virtual environment...Running virtualenv with interpreter C:/Program Files (x86)/Anaconda3/python.exe
stderr->Already using interpreter C:\Program Files (x86)\Anaconda3\python.exe
stderr->Using base prefix 'C:\\Program Files (x86)\\Anaconda3'
stderr->  No LICENSE.txt / LICENSE found in source
stderr->New python executable in C:\Users\ahadu\test\.venv\Scripts\python.exe
stderr->Installing setuptools, pip, wheel...
stderr->done.
stderr->
stderr-Successfully created virtual environment!
stderr->Virtualenv location: C:\Users\ahadu\test\.venv
stdout->Installing dependencies from Pipfile.lock (d34422)…
stdout->To activate this project's virtualenv, run pipenv shell.
stdout->Alternatively, run a command inside the virtualenv with pipenv run.

Process finished with exit code 0

Where does this message come from? This is also where it might take some time, so not being able to read this message as it gets produced, undermines the whole work.

In other words, what I expect is to see the following print on the console:

some-source->[= ] Creating virtual environment...
some-source->[ =] Creating virtual environment...
some-source->[= ] Creating virtual environment...
some-source->[ =] Creating virtual environment...

until it has finished.

Does anyone know the reason for this issue and how to address it?

pipenv popen subprocess python
1 Answers

I believe it's because, for those spinner-ed outputs, pipenv resets the stream (stdout/stderr) back to the beginning of the line before writing the next line. So, your prefix gets cleared.

Initially I thought you just need to set the PIPENV_NOSPIN and PIPENV_HIDE_EMOJIS environment variables before running the script. While that disables the spinner and emojis, some lines are still not prefixed. (Plus you won't get to see any progress for operations that take time):

temp$ export PIPENV_NOSPIN=1
temp$ export PIPENV_HIDE_EMOJIS=1
temp$ python3.8 test.py
...
stderr>>>>>Pipfile.lock not found, creating...
stderr>>>>>Locking [dev-packages] dependencies...
stderr>>>>>Locking [packages] dependencies...
Building requirements...
Resolving dependencies...
Success!>>>
stderr>>>>>Updated Pipfile.lock (49bf85)!
stdout>>>>>Installing dependencies from Pipfile.lock (49bf85)...
stdout>>>>>To activate this project's virtualenv, run pipenv shell.
stdout>>>>>Alternatively, run a command inside the virtualenv with pipenv run.

If we follow the "Resolving dependencies..." log to the venv_resolve_deps function in utils.py, then follow the write method in spin.py, we'll see some lines like this:

stdout.write(decode_output(u"\r", target_stream=stdout))

Now that writing of "\r" could result to something like this:

>>> print('abc\rdef')
def

where the previous outputs are cleared. Since your prefix is at the beginning, that gets cleared too. Note that I might be wrong here that this is the cause, can't really follow how the lines are being printed out, but it's the only explanation I can find/think of.

Now, I've managed to make your script work by simply passing in text=True to the Popen call, which means:

stdin, stdout and stderr will be opened in text mode using the encoding and errors specified in the call or the defaults for io.TextIOWrapper

def run_cmd(cmd, cwd):
    popen = subprocess.Popen(
        cmd, cwd=cwd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, bufsize=1,
        text=True)  # <==== add param here

    a = threading.Thread(
        target=printTh,
        args=("stdout", iter(popen.stdout.readline, "")))  # <===== remove 'b'
    a.start()

    b = threading.Thread(
        target=printTh,
        args=("stderr", iter(popen.stderr.readline, "")))  # <===== remove 'b'
    b.start()

    while popen.poll() is not None:
        a.join()
        b.join()

def printTh(pipe_name, iter):
    for line in iter:
        #      =================== remove .decode ==============
        print(pipe_name + ">>>>>" + line.rstrip(), end="\r\n", flush=True)

run_cmd(cmd, cwd)

The result seems to be what you wanted:

stderr>>>>>⠋ Creating virtual environment...
stderr>>>>>⠙ Creating virtual environment...
stderr>>>>>⠹ Creating virtual environment...
stderr>>>>>⠸ Creating virtual environment...
stderr>>>>>⠼ Creating virtual environment...
...
stderr>>>>>
stderr>>>>✔ Successfully created virtual environment!
stderr>>>>>Virtualenv location: /Users/me/.venvs/temp-9JdZcEvf
stderr>>>>>Creating a Pipfile for this project...
stdout>>>>>Installing flask...
stderr>>>>>
stderr>>>>>⠋ Installing...
stderr>>>>>⠙ Installing flask...
stderr>>>>>⠹ Installing flask...
stderr>>>>>⠋ Installing flask...
stderr>>>>>⠙ Installing flask...
stderr>>>>>⠹ Installing flask...
stderr>>>>>⠸ Installing flask...
stderr>>>>>⠼ Installing flask...
stderr>>>>>Adding flask to Pipfile's [packages]...
stderr>>>>✔ Installation Succeeded
stderr>>>>>Pipfile.lock not found, creating...
stderr>>>>>Locking [dev-packages] dependencies...
stderr>>>>>Locking [packages] dependencies...
stderr>>>>>
stderr>>>>>⠋ Locking...
stderr>>>>>Building requirements...
stderr>>>>>
stderr>>>>>Resolving dependencies...
stderr>>>>>
stderr>>>>>⠙ Locking...
stderr>>>>>⠹ Locking...
stderr>>>>>⠸ Locking...
stderr>>>>>⠙ Locking...
stderr>>>>>⠦ Locking...
stderr>>>>>⠧ Locking...
stderr>>>>>⠇ Locking..✔ Success!
stderr>>>>>Updated Pipfile.lock (9536c4)!
stdout>>>>>Installing dependencies from Pipfile.lock (9536c4)...
stdout>>>>>To activate this project's virtualenv, run pipenv shell.
stdout>>>>>Alternatively, run a command inside the virtualenv with pipenv run.

Tested with:

  • pipenv, version 2020.11.15
  • Python 3.8
  • macOS 10.15.7, Terminal with bash 5.x
user_27454950
Related