Selecting an item from a long-running command before it completes causes an error

[pfmoore]

If I select an item from the output of a long running command, before the command completes, then the command terminates with an error and dumps a traceback on the screen.

As a demonstration, try the following Python script:

import time

for i in range(1000):
    print(f"Item {i}",flush=True)
    time.sleep(1)

This generates one line of output per second. Run py .\ex.py | invoke-fzf and select item 3 when it appears. The output is displayed, but then an error appears, along with some traceback output from Python.

>py .\ex.py | invoke-fzf
Item 3
ResourceUnavailable: Program 'py.exe' failed to run: Stopped fzf pipeline inputAt line:1 char:1
+ py .\ex.py | invoke-fzf
+ ~~~~~~~~~~.
PS 20:36 {00:05.139} D:\Work\Scratch
>Traceback (most recent call last):
  File ".\ex.py", line 4, in <module>
    print(f"Item {i}",flush=True)
OSError: [Errno 22] Invalid argument
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='cp1252'>
OSError: [Errno 22] Invalid argument

Note that the prompt is part-way through the output, and if you start typing, what you types overwrites the output just after the > of the prompt.

[kelleyma49]

Thank you for the repo instructions. I could recreate this on my local machine.

In order to stop the process loop, PSFzf has to throw an exception when it sees that fzf.exe has exited. This doesn't seem to work well with Python. I'm not sure how to handle this as there's not a error free way to stop a PowerShell process loop. I'm open to suggestions!

One possible work around: at the top level of python script, catch an exception when standard output is closed and cleanly exit. I haven't tested this, so it might or might not work.

[pfmoore]

I tried

import sys
import time

for i in range(1000):
    if sys.stdout.closed:
        break
    print(f"Item {i}",flush=True)
    time.sleep(1)

but it didn't help.

I'm not sure how to handle this as there's not a error free way to stop a PowerShell process loop. I'm open to suggestions!

I'm happy to offer suggestions if I can, but I'm not sure I follow what you're saying. Can you give an example of what you mean by this?

[kelleyma49]

I experimented with a different way of closing the pipeline, and I was able to get rid of the first error (ResourceUnavailable: Program 'py.exe' failed to run: Stopped fzf pipeline inputAt line:1 char:1). However, I still get the OSError: [Errno 22] Invalid argument error. I tried checking if stdout is closed as well, but Python doesn't seem to see that standard error is closed - my guess it's keeping it's own state for stdout?

[kelleyma49]

If I use pyw.exe, and my new pipeline close change, I get no errors. 🤷‍♂️

[pfmoore]

Hmm, that's weird. I see why pyw works (it's a GUI program, so doesn't connect to the console at all) but it's totally the wrong way to run a Python program like this.

I'll do some experimenting to see what's going on here.

Can you point me at the bit of the PSfzf code that handles the pipeline, so I can set up a test case that works the same way as your code does? Thanks.

[kelleyma49]

Apologies for the delay - I needed to cleanup the code. You can see the code in Pull Request #78 .

[pfmoore]

Thanks - I've not been able to reproduce the issue outside of PSFzf yet, but looking at the code a bit further, I suspect that the problem is not so much with the way the subprocess is terminated, but it's rather related to how the stdio handles to the Python process are being managed. I'll need to look into that into a bit more detail, and see if I can come up with a simple test case.

[kelleyma49]

FYI, Select-Object will cause python to show the same error, so this issue isn't specific to PSFzf. See below:

PS > py ex.py | Select-Object -First 10
Item 0
Item 1
Item 2
Item 3
Item 4
Item 5
Item 6
Item 7
Item 8
Item 9
PS C:\Users\mickelley> Traceback (most recent call last):
  File "ex.py", line 4, in <module>
    print(f"Item {i}",flush=True)
OSError: [Errno 22] Invalid argument
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='cp1252'>
OSError: [Errno 22] Invalid argument

[pfmoore]

Ah, cool. That's a much easier reproducer. And as it doesn't involve PSFzf, that suggests it's an issue with Powershell and/or Python. So I probably need to take it elsewhere. Thanks for the help here 🙂

And in fact I can demonstrate it in cmd.exe, using git's tail executable:

C:\Work\Scratch>py ex.py | C:\Users\Gustav\scoop\apps\git\current\usr\bin\head.exe -5
Item 0
Item 1
Item 2
Item 3
Item 4
Traceback (most recent call last):
  File "C:\Work\Scratch\ex.py", line 7, in <module>
    print(f"Item {i}",flush=True)
OSError: [Errno 22] Invalid argument
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='utf-8'>
OSError: [Errno 22] Invalid argument

So I need to report it to Python (as a Python core dev, I'm now embarrassed that I didn't check this first!) Thanks again.

[pfmoore]

A further update, in case anyone else comes across this thread. It's not directly a Python issue, C code has the same problem, but behaves differently.

The root issue is that if the program on the RHS of the pipe terminates, the program on the LHS no longer has a valid stdout. Further writes to stdout will cause an error. In Python, that error is reported as a traceback on stderr, and the program terminates. In C, the write just returns an error code, and if the application doesn't expect printf to fail, it will continue running until it terminates normally, dumping its output into the ether.

I just did a test on Unix, and the behaviour there is the same:

gustav@Teemo:/mnt/c/Work/Scratch$ python3 ex.py | head -3
Item 0
Item 1
Item 2
Traceback (most recent call last):
  File "ex.py", line 7, in <module>
    print(f"Item {i}",flush=True)
BrokenPipeError: [Errno 32] Broken pipe
Exception ignored in: <_io.TextIOWrapper name='<stdout>' mode='w' encoding='utf-8'>
BrokenPipeError: [Errno 32] Broken pipe

I guess the answer is "don't write your code like that if you expect it to be used in a pipe that terminates early"...