Bug 209509

Summary: EAGAIN on shell pipes / O_NONBLOCK error in kernel ?
Product: Base System Reporter: Poul-Henning Kamp <phk>
Component: kernAssignee: freebsd-bugs (Nobody) <bugs>
Status: Closed Works As Intended    
Severity: Affects Only Me CC: jilles, kib, truckman
Priority: ---    
Version: CURRENT   
Hardware: Any   
OS: Any   

Description Poul-Henning Kamp freebsd_committer freebsd_triage 2016-05-14 22:01:52 UTC 
I have a pretty trivial program here, which quite reliably will receive EAGAIN on stdout/stderr when these are a shell created pipe.

The command is run as:

 aardwarc stow |& tee /tmp/__

It does two popens, and chats with those two programs (ssh and mtree).

Here is from a ktrace:

First, checking that stderr & stdout are not O_NONBLOCK:

 16131 aardwarc CALL  fcntl(0x1,F_GETFL,0xffffe5bc)
 16131 aardwarc RET   fcntl 2
 [...]
 16131 aardwarc CALL  fcntl(0x2,F_GETFL,0xffffe5bc)
 16131 aardwarc RET   fcntl 2

Then after a lot of output on stdout/stderr:

 16131 aardwarc CALL  write(0x1,0x7fffffffdd80,0x7e)
 16131 aardwarc RET   write -1 errno 35 Resource temporarily unavailable
 [...]
 16131 aardwarc CALL  write(0x2,0x7fffffffde90,0x16)
 16131 aardwarc GIO   fd 2 wrote 22 bytes
 [...]
 16131 aardwarc CALL  write(0x2,0x7fffffffddb0,0x9)
 16131 aardwarc GIO   fd 2 wrote 9 bytes
 [...]
 16131 aardwarc CALL  write(0x2,0x7fffffffdd70,0x44)
 16131 aardwarc RET   write -1 errno 35 Resource temporarily unavailable

Presumably these are the same struct file, so it notable that stdout gets EAGAIN, the stderr manages two writes, then stderr also gets EAGAIN.

AMD64, CURRENT, r297556
Comment 1 Don Lewis freebsd_committer freebsd_triage 2016-05-14 22:57:09 UTC 
I don't see this with slightly older -CURRENT (r299612)  It may also be dependent on the write size with partial writes being the trigger.

This is how I did my test:

# truss -do /tmp/truss.out cat /usr/share/dict/web2 | & ( sleep 60 ; cat > /tmp/out )

The point at which the pipe file is visible here:

0.008018050 write(1,"\nalif\naliferous\naliform\nalig"...,4096) = 4096 (0x1000)
0.008089335 read(3,"oplasmatic\nalloplasmic\nallopla"...,4096) = 4096 (0x1000)
0.008183362 write(1,"oplasmatic\nalloplasmic\nallopla"...,4096) = 4096 (0x1000)
0.008255003 read(3,"\naltininck\naltiplano\naltiscop"...,4096) = 4096 (0x1000)
0.008353817 write(1,"\naltininck\naltiplano\naltiscop"...,4096) = 4096 (0x1000)
0.008425411 read(3,"ambrosiate\nambrosin\nambrosine"...,4096) = 4096 (0x1000)
60.037870962 write(1,"ambrosiate\nambrosin\nambrosine"...,4096) = 4096 (0x1000)
60.038272972 read(3,"n\nAmnionata\namnionate\namnioni"...,4096) = 4096 (0x1000)
60.038579389 write(1,"n\nAmnionata\namnionate\namnioni"...,4096) = 4096 (0x1000)

I just tried an odd-size write test and that works properly as well:

# truss -do /tmp/truss.out dd if=/usr/share/dict/web2 bs=111 | & ( sleep 60 ; cat > /tmp/out )

0.281516906 read(3,"\namboceptor\nAmbocoelia\nAmboin"...,111) = 111 (0x6f)
0.281774261 write(1,"\namboceptor\nAmbocoelia\nAmboin"...,111) = 111 (0x6f)
0.281966423 read(3,"n\nambrein\nambrette\nAmbrica\na"...,111) = 111 (0x6f)
0.282239613 write(1,"n\nambrein\nambrette\nAmbrica\na"...,111) = 111 (0x6f)
0.282433782 read(3,"ous\nambrosial\nambrosially\nAmb"...,111) = 111 (0x6f)
60.078868711 write(1,"ous\nambrosial\nambrosially\nAmb"...,111) = 111 (0x6f)
60.079279323 read(3,"y\nambsace\nambulacral\nambulacr"...,111) = 111 (0x6f)
60.079588632 write(1,"y\nambsace\nambulacral\nambulacr"...,111) = 111 (0x6f)
60.079823710 read(3,"ative\nambulator\nAmbulatoria\na"...,111) = 111 (0x6f)
60.080113161 write(1,"ative\nambulator\nAmbulatoria\na"...,111) = 111 (0x6f)
Comment 2 Konstantin Belousov freebsd_committer freebsd_triage 2016-05-14 23:12:37 UTC 
(In reply to Poul-Henning Kamp from comment #0)
Can you provide a minimal reproduction case ?
Comment 3 Jilles Tjoelker freebsd_committer freebsd_triage 2016-05-14 23:47:06 UTC 
The problem may be caused by ssh. When it starts, ssh sets fd 0, 1 and 2 to non-blocking mode if they are not TTYs, restoring them to their original state on exit. This causes breakage if you use the open files (pipes or sockets) for other things while ssh is running.

Unfortunately, fixing ssh requires adding threads or processes to do blocking reads and writes. On FreeBSD, although socket receives support MSG_DONTWAIT, socket sends do not (although their behaviour is affected by it slightly) and pipe reads and writes do not support anything like it. Performance of common use cases may be affected negatively.

As a workaround, try redirecting ssh's stderr through a 'cat'. For example,

{ ssh ... 2>&1 >&3 3>&- | cat >&2; } 3>&1

(Bug: this example loses ssh's exit status. Using fifos or doing pipe manipulations from C will avoid that.)
Comment 4 Poul-Henning Kamp freebsd_committer freebsd_triage 2016-05-15 07:27:35 UTC 
That would explain why things don't break left, right and center.

I'll test that theory later today.

Isn't this going to screw up programs like rsync or do they take special precautions ?
Comment 5 Poul-Henning Kamp freebsd_committer freebsd_triage 2016-05-15 07:45:23 UTC 
This was actually pretty trivial to test, and yes, ssh seems to be the culprit.

This might be a good thing to note in the ssh manual page, since the focus on encryption these days makes popen("ssh...") quite a logical thing to do.