FileHandle's readabilityHandler not called when detached from debugger

Hello,

I am facing an issue with NSTask (Process), NSPipe (Pipe) and NSFileHandle (FileHandle).
I have an app that executes a child process (command line utility) and gets its output via Pipe instances set as standardI/O of Process instance.

I can observe two logic flows:
  1. Once the child process exits, -[Process readabilityHandler] gets called where I gather the $0.availableData.

  2. Once the child process generates output (i.e. print() is executed by the child process), -[Process readabilityHandler] also gets called which makes sense. This is the case when exit() is not called by the child process (i.e. continuous execution).

However, when LLDB is detached, #2 is false, i.e. -[Process readabilityHandler] is not called.
Wrong behaviour also happens if I don't rely on readabilityHandler, but instead use Notification to receive changes in data availability. In such case, notification gets called continuously with empty data (even though child process does generate the output).
If I don't create Pipe instance for standardI/O of the Process, then readabilityHandler does get called, but with an empty data continuously.

I have created a DTS #756462540, since this doesn't make any sense.
  • Prerequisites*

  • app is not sandboxed

  • Big Sur 11.0.1 (20B29)

  • Xcode 12.3 (12C33)

Answered by ruslan.alikhamov in 653974022
Hi @brennanAMZN thank you for your response!
Unfortunately I did everything I found online, including checking out blog posts from 2009.

What is actually happening is that due to stdout buffering, data is not being written to that stdout. What helped was to add fflush() calls right after the Swift.print() calls in the child process.

I am writing down a series of blog posts related to this, however, what actually helped was a TSI response from an Apple Engineer.
I came across this question because I was running instances of Process and connecting Pipe to the FileHandle and found it was using an excessive amount of CPU due to many calls to the handleInput function. The readabilityHandler property is set to this function to handle the data. What I found is that I needed to call waitForDataInBackgroundAndNotify which prevented the handler functions from being called frequently with no data.

With your process make sure you call launch and waitUntilExit so that your function does not finish early. And if you are running a Command Line Tool you may want to add a call to dispatchMain() to prevent the process from terminating until the code calls exit.

Code Block swift
let outPipe = Pipe()
let errPipe = Pipe()
task.standardOutput = outPipe
task.standardError = errPipe
outPipe.fileHandleForReading.readabilityHandler = handleInput(fileHandle:)
errPipe.fileHandleForReading.readabilityHandler = handleError(fileHandle:)
outPipe.fileHandleForReading.waitForDataInBackgroundAndNotify()
errPipe.fileHandleForReading.waitForDataInBackgroundAndNotify()


Accepted Answer
Hi @brennanAMZN thank you for your response!
Unfortunately I did everything I found online, including checking out blog posts from 2009.

What is actually happening is that due to stdout buffering, data is not being written to that stdout. What helped was to add fflush() calls right after the Swift.print() calls in the child process.

I am writing down a series of blog posts related to this, however, what actually helped was a TSI response from an Apple Engineer.

Running a child process and capturing its output is way more complex than it seems at first. I’ve researched this extensively as part of a DTS tech support incident and posted a summary of my results in Running a Child Process with Standard Input and Output.


As to your specific question:

I notice that you mentioned you added flush(stdout) in your code. Did it work?

This is fundamental to the way that the standard I/O library works on Unix-y systems. Consider this simple Swift script:

% cat test.swift 
#! env swift
import Foundation

for _ in 0..<5 {
    print(Date.now)
    Thread.sleep(forTimeInterval: 1.0)
}

First run it directly from the command line:

% ./test.swift 
2022-03-03 10:20:53 +0000
2022-03-03 10:20:54 +0000
2022-03-03 10:20:55 +0000
2022-03-03 10:20:56 +0000
2022-03-03 10:20:57 +0000

This does what you’d expect: You see each line as it’s printed. Now run it like this:

% ./test.swift | cat

Now you see nothing for 5 seconds, and then all the output. Note how the timestamps are different, so the output was generated at the right time, it was just buffered until the process terminated.

Now tweak the script to add an fflush:

% cat test-flush.swift 
#! env swift
import Foundation

for _ in 0..<5 {
    print(Date.now)
    fflush(stdout)
    Thread.sleep(forTimeInterval: 1.0)
}

And repeat your test:

% ./test-flush.swift | cat

With this script you see the same output but it arrives one line at a time. That’s the effect of the fflush.

There are two factoids in play here:

  • Swift’s print statement is wired up to the Unix-y standard I/O library, that is, printf and friends.

  • The standard I/O library may or may not buffer by default, depending on the target file descriptor. Specifically:

    • If the file descriptor is connected to a terminal, it defaults to being lined buffer.

    • Otherwise it defaults to block buffering.

This explains the behaviour shown above:

  • In the first example (test.swift output to a terminal) stdout was connected to a terminal and thus line buffered.

  • In the second example (test.swift piped to cat) it was connected to a pipe and thus block buffered.

  • In the third example (test-flush.swift) the script overrode that decision using fflush.

To learn more about this, read the setvbuf man page.


So, what can you do about this? If you control the code of the child process, either add the appropriate fflush calls or reconfigure the buffering using setvbuf. If not, things get more complex. Let me know if that’s the case and I can assist you with the next step on this path.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

@eskimo

Sorry to ressurect an old thread. I was just faced with this very issue trying to run a shell script using Process(). My program was waiting 10 seconds for enough data to fill the buffer before the 1 second updates from the script were presented to my read handler. On reading man setbuf, I saw a reference to setting the environment variable STDBUF.

Inserting

export STDBUF="U"

into the script seems to have solved the problem and my program now receives each message as it is output from the shell script.

I was unable to find reference to this environment variable anywhere else and am just asking for reassurance that it won't suddenly disappear.

On reading man setbuf, I saw a reference to setting the environment variable STDBUF.

Oh, that’s cool. I did not know about that.

I … am just asking for reassurance that it won't suddenly disappear.

Given that it’s documented in the man page, you can be reasonably assured that it’ll continue working in the future. As to the past, AFAICT it was added in macOS 10.14.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

FileHandle's readabilityHandler not called when detached from debugger
 
 
Q