Dear UNIX diary,

today, I had fun with file descriptor flags at work.

I had a Python script that failed with `EAGAIN` while doing a `print()` on `stdout`. Say what?

Looking at `write(2)`, we can see this:


You can trigger the error using the following snippet of C code:


Just run it in a terminal, maybe under `strace` to see what’s going on. It goes something like this:


libc does some buffering and then eventually tries to write chunks of 1024 bytes. Since we set the file descriptor to nonblocking, the syscall immediately returns and doesn’t wait for the data to be actually written to its final destination. So, I guess, there’s another kernel-internal buffer. When that one is full, we get EAGAIN.

My original Python script was indeed writing lots of data. So, somehow, my `stdout` must have been set to nonblocking mode. I checked the code, but I couldn’t find anything that did this. But okay, maybe Python does this internally for some weird reason? I tried to reproduce this in isolated test cases, but nope, I couldn’t see Python doing an `fcntl()`.

Alright, what else does my script do? It forks and runs ssh. Mhm. But I used Python’s `check_output()`, so ssh’s `stdout` was a newly created pipe. At first, I couldn’t see how ssh could possibly botch my `stdout`?!

Then another idea: This script was being run as a systemd service. Meaning, the `stdout` we’re talking about is actually a socket which is connected to journald. So maybe systemd screws up and sets this socket to nonblocking for whatever reason … ? But I couldn’t verify that theory, either.

And then it dawned on me: systemd connects the same socket to both `stdout` and `stderr`. So, if ssh did something to its `stderr`, that could affect my Python script’s `stdout`.

Let’s give this a shot:


And here’s the glorious output, `stdout` and `stderr` in the parent being the same pipe:

The child process did close its original `stdout` (got reopened from /dev/null), but `stdout` in the parent process still got changed.

Now, the original environment uses ssh multiplexing, so I used that in my now isolated test case as well. I reproduced it without multiplexing as well, I put that case at the end of the posting.

The ssh process I’ve spawned transfers the three standard file descriptors to the main multiplexing process:


And that process, in turn, does this:


There you have it. It sets fd 8, which is the `stderr` it received, to nonblocking. Since that is the same pipe as the parent process’s `stdout`, both are changed.

Duplicated file descriptors share some things, but not everything. `dup(2)` says:


And “file status flags” are those set by `fcntl(..., F_SETFL, ...)`, but “file descriptor flags” are something else:


Now the funny thing is, you might say: “Well, just don’t spawn processes and let them inherit your file descriptors. Of course they can do nasty things.” Yeah, but this was actually done intentionally: My Python script spawned ssh and left its `stderr` untouched in an effort to automatically have ssh’s error messages end up at the same destination (i.e., systemd journal) as my Python logs. I now have to manually collect and handle ssh’s `stderr`, which is more code and more error prone.

Alright, so let’s quickly look at the case where we don’t use ssh multiplexing. At first, I thought this didn’t trigger the “bug”, but it indeed does, it’s just a little harder to spot. Here’s a partial strace log:


In other words, ssh resets the flags in this case. My ssh command finished very quickly, so I didn’t see a “NONblocking” line at first.

All this is heavy usage of strace. I love this tool. I haven’t read ssh’s source code, though, that might be interesting as well. But that’s something for another day.