Bug 73811 - wine's kernel32/pipe test fails on 3.10-rc6+
Summary: wine's kernel32/pipe test fails on 3.10-rc6+
Status: RESOLVED WILL_NOT_FIX
Alias: None
Product: Networking
Classification: Unclassified
Component: Other (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Stephen Hemminger
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-04-11 02:04 UTC by austinenglish@gmail.com
Modified: 2014-04-22 16:47 UTC (History)
2 users (show)

See Also:
Kernel Version: 3.12
Subsystem:
Regression: Yes
Bisected commit-id:


Attachments
git bisect log (3.51 KB, text/plain)
2014-04-11 18:38 UTC, austinenglish@gmail.com
Details

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

Note You need to log in before you can comment on or make changes to this bug.