Bug 73811

Summary:	wine's kernel32/pipe test fails on 3.10-rc6+
Product:	Networking	Reporter:	austinenglish (austinenglish)
Component:	Other	Assignee:	Stephen Hemminger (stephen)
Status:	RESOLVED WILL_NOT_FIX
Severity:	normal	CC:	alan, daniel
Priority:	P1
Hardware:	All
OS:	Linux
Kernel Version:	3.12	Subsystem:
Regression:	Yes	Bisected commit-id:
Attachments:	git bisect log

Description austinenglish@gmail.com 2014-04-11 02:04:43 UTC

Regression is introduced by:
commit eea86af6b1e18d6fa8dc959e3ddc0100f27aff9f
Author: Daniel Borkmann <dborkman@redhat.com>
Date:   Wed Jun 19 12:51:20 2013 +0200

After this commit, the test fails:

pipe.c:1853: Test failed: WaitForSingleObject returned 102
pipe.c:1855: Test failed: completion routine not called

See https://bugs.winehq.org/show_bug.cgi?id=35781 for the original bug report.

I bisected this in a qemu-kvm running debian testing. The failure is consistent (not a race condition).

I attempted to verify this in 3.14 / HEAD (4ba85265790ba3681deeaf73f018c0eb829a7341), but those both kernel panic for me on bootup.

Comment 1 austinenglish@gmail.com 2014-04-11 18:38:53 UTC

Created attachment 131941 [details]
git bisect log

Comment 2 Daniel Borkmann 2014-04-13 10:07:15 UTC

Hi thanks for the report, where can I find the source of this test case? [Feel free to also contact me via email.] Thanks!

Comment 3 Daniel Borkmann 2014-04-18 09:30:12 UTC

Summary from our internal email discussions: the kernel is free to enforce a minimum SO_{SND,RCV}BUF value, without any notice, which is what the commit is doing. It's _advisory_ only. The reason that the minimum value is not set in stone forever and its concrete *value* not part of the ABI contract is that we allow to switch kernel allocator for skbs to whatever granularity we want in the future. The value the current kernel is using can be queried via getsockopt(2), set via setsockopt(2). A conformant application would autodiscover what is the _current_ minimum value if it really cares. Thus, it is not a kernel bug.

Summary from Austin's email report:

good:
[austin@localhost kernel_73811]$ grep setsockopt strace_pipe_good.txt |
cut -d " " -f 4-
setsockopt(4, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(4, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(10, SOL_SOCKET, SO_PASSCRED, [1], 4) = 0
setsockopt(10, SOL_SOCKET, SO_PASSCRED, [0], 4) = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [1], 4) = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [0], 4) = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(18, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(18, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(46, SOL_SOCKET, SO_RCVBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(52, SOL_SOCKET, SO_RCVBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(46, SOL_SOCKET, SO_SNDBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(52, SOL_SOCKET, SO_SNDBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(59, SOL_SOCKET, SO_RCVBUF, [256], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(60, SOL_SOCKET, SO_RCVBUF, [256], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(59, SOL_SOCKET, SO_SNDBUF, [256], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(60, SOL_SOCKET, SO_SNDBUF, [256], 4) = 0
setsockopt(28, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(28, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(67, SOL_SOCKET, SO_RCVBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(76, SOL_SOCKET, SO_RCVBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(67, SOL_SOCKET, SO_SNDBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(76, SOL_SOCKET, SO_SNDBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(80, SOL_SOCKET, SO_RCVBUF, [256], 4) = 0
setsockopt(81, SOL_SOCKET, SO_RCVBUF, [256], 4) = 0
setsockopt(80, SOL_SOCKET, SO_SNDBUF, [256], 4) = 0
setsockopt(81, SOL_SOCKET, SO_SNDBUF, [256], 4) = 0
setsockopt(10, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(10, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(28, SOL_SOCKET, SO_RCVBUF, [1024], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(29, SOL_SOCKET, SO_RCVBUF, [1024], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(28, SOL_SOCKET, SO_SNDBUF, [1024], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(29, SOL_SOCKET, SO_SNDBUF, [1024], 4 <unfinished ...>
<... setsockopt resumed> )  = 0

bad:
[austin@localhost kernel_73811]$ grep setsockopt strace_pipe_bad.txt |
cut -d " " -f 4-
setsockopt(4, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(4, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(10, SOL_SOCKET, SO_PASSCRED, [1], 4) = 0
setsockopt(10, SOL_SOCKET, SO_PASSCRED, [0], 4) = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [1], 4) = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [0], 4) = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(18, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(18, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(46, SOL_SOCKET, SO_RCVBUF, [5840], 4) = 0
setsockopt(52, SOL_SOCKET, SO_RCVBUF, [5840], 4) = 0
setsockopt(46, SOL_SOCKET, SO_SNDBUF, [5840], 4) = 0
setsockopt(52, SOL_SOCKET, SO_SNDBUF, [5840], 4) = 0
setsockopt(59, SOL_SOCKET, SO_RCVBUF, [256], 4) = 0
setsockopt(60, SOL_SOCKET, SO_RCVBUF, [256], 4) = 0
setsockopt(59, SOL_SOCKET, SO_SNDBUF, [256], 4) = 0
setsockopt(60, SOL_SOCKET, SO_SNDBUF, [256], 4) = 0
setsockopt(28, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(28, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(67, SOL_SOCKET, SO_RCVBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(76, SOL_SOCKET, SO_RCVBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(67, SOL_SOCKET, SO_SNDBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(76, SOL_SOCKET, SO_SNDBUF, [5840], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(80, SOL_SOCKET, SO_RCVBUF, [256], 4) = 0
setsockopt(81, SOL_SOCKET, SO_RCVBUF, [256], 4) = 0
setsockopt(80, SOL_SOCKET, SO_SNDBUF, [256], 4) = 0
setsockopt(81, SOL_SOCKET, SO_SNDBUF, [256], 4) = 0
setsockopt(10, SOL_SOCKET, SO_PASSCRED, [1], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(10, SOL_SOCKET, SO_PASSCRED, [0], 4 <unfinished ...>
<... setsockopt resumed> )  = 0
setsockopt(26, SOL_SOCKET, SO_RCVBUF, [1024], 4) = 0
setsockopt(28, SOL_SOCKET, SO_RCVBUF, [1024], 4) = 0
setsockopt(26, SOL_SOCKET, SO_SNDBUF, [1024], 4) = 0
setsockopt(28, SOL_SOCKET, SO_SNDBUF, [1024], 4) = 0