On Mon, 04 Jun 2007 18:35:58 +0200
Thomas Gleixner [off-list ref] wrote:

On Mon, 2007-06-04 at 09:09 -0700, Stephen Hemminger wrote:

quoted

quoted

quoted

I did the test with an 2.6.22-rc3-git4 kernel and the p54 driver built 
external as module. 

Can you look at iperf to figure out, whether it does some weird timer
stuff (high frequency interval timer or such) ? Either check the code or
strace it.

It is the receiver doing a tight loop doing gettimeofday/recv calls.


sendto(-1227715616, 0xc, 3085438964, 0, {...}, 3067249832) = 0
gettimeofday({1180973726, 981615}, NULL) = 0
gettimeofday({1180973726, 981751}, NULL) = 0
futex(0x8055c64, 0x5 /* FUTEX_??? */, 1) = 1
futex(0x8055c90, FUTEX_WAKE, 1) = 0
recv(4, "\0\0\0\0\0\0\0\1\0\0\23\211\0\0\0\0\0\0\0\0\377\377\364"..., 8192, 0) = 8192
gettimeofday({1180973726, 982754}, NULL) = 0
recv(4, "\0\0\0\0\0\0\0\1\0\0\23\211\0\0\0\0\0\0\0\0\377\377\364"..., 8192, 0) = 8192
gettimeofday({1180973726, 983790}, NULL) = 0

Well, gettimeofday() is not affected by the highres code, but

quoted

nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0

is. The nanosleep call with a relative timeout of 0 returns immediately
with highres enabled, while it sleeps at least until the next tick
arrives when highres is off. Are there more of those stupid sleeps in
the code ?

GLIBC pthread_mutex does it, YES it is a problem!
Looks like the old behavior is required for ABI compatibility.

iperf server has several threads. One thread is using pthread_mutex_lock
to wait for the other thread.  It looks like pthread_mutex_lock is using
nanosleep as yield().

Multi-thread strace shows how this could kill performance.
These are with old 2.6.20 kernel that doesn't have the problem:

sendto(-1210930208, 0xc, 3085438964, 0, {...}, 3084035240) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 3
setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4)         = 0
bind(3, {sa_family=AF_INET, sin_port=htons(5001), sin_addr=inet_addr("0.0.0.0")}, 16)   = 0
listen(3, 5)                            = 0
futex(0x8055c64, 0x5 /* FUTEX_??? */, 1) = 1
accept(3, {sa_family=AF_INET, sin_port=htons(49973), sin_addr=inet_addr("192.168.0.14")}, [16]) = 4
getsockname(4, {sa_family=AF_INET, sin_port=htons(5001), sin_addr=inet_addr("192.168.0.12")}, [16]) = 0
recv(4, "\0\0\0\0\0\0\0\1\0\0\23\211\0\0\0\0\0\0\0\0\377\377\364"..., 24, 0) = 24
mmap2(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6528000
mprotect(0xb6528000, 4096, PROT_NONE)   = 0
clone(child_stack=0xb6d284a4, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID|CLONE_DETACHED, parent_tidptr=0xb6d28bd8, {entry_number:6, base_addr:0xb6d28b90, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}, child_tidptr=0xb6d28bd8) = 5622
accept(3, 0x8058b98, [128]) = ? ERESTARTSYS (To be restarted)

==============

sendto(-1219322912, 0xc, 3085438964, 0, {...}, 3075642536) = 0
futex(0x8055d04, 0x5 /* FUTEX_??? */, 1) = 1
futex(0x8055d30, FUTEX_WAKE, 1) = 1
futex(0x8055c64, FUTEX_WAIT, 1, NULL) = 0
futex(0x8055d04, 0x5 /* FUTEX_??? */, 1) = 1
futex(0x8055d30, FUTEX_WAKE, 1)         = 1
futex(0x8055c90, FUTEX_WAKE, 1)         = 0
getsockopt(3, SOL_SOCKET, SO_RCVBUF, [87380], [4]) = 0
fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fb0000
write(1, "--------------------------------"..., 61) = 61
write(1, "Server listening on TCP port 500"..., 34) = 34
write(1, "TCP window size: 85.3 KByte (def"..., 38) = 38
write(1, "--------------------------------"..., 61) = 61
nanosleep({0, 0}, NULL)                 = 0
futex(0x8055d04, 0x5 /* FUTEX_??? */, 1) = 1
futex(0x8055d30, FUTEX_WAKE, 1)         = 1
futex(0x8055c64, FUTEX_WAIT, 3, NULL) = 0
futex(0x8055c90, FUTEX_WAIT, 2, NULL)         = -1 EAGAIN (Resource temporarily unavailable)
futex(0x8055d04, 0x5 /* FUTEX_??? */, 1)                               = 1
futex(0x8055d30, FUTEX_WAKE, 1)                          = 0
futex(0x8055c90, FUTEX_WAKE, 1)                               = 0
write(1, "[  4] local 192.168.0.12 port 50"..., 74)                          = 74
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL)                      = 0
nanosleep({0, 0}, NULL)                           = 0
nanosleep({0, 0}, NULL) = 0

...

nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL)                 = 0
write(1, "[  4]  0.0-30.2 sec    336 MByte"..., 50)                     = 50
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
futex(0x8055d04, 0x5 /* FUTEX_??? */, 1) = 1
futex(0x8055d30, FUTEX_WAKE, 1) = 0
futex(0x8055c64, FUTEX_WAIT, 5, NULL) = -1 EINTR (Interrupted system call)

===============

sendto(-1227715616, 0xc, 3085438964, 0, {...}, 3067249832) = 0
gettimeofday({1180973726, 981615}, NULL) = 0
gettimeofday({1180973726, 981751}, NULL) = 0
futex(0x8055c64, 0x5 /* FUTEX_??? */, 1) = 1
futex(0x8055c90, FUTEX_WAKE, 1) = 0
recv(4, "\0\0\0\0\0\0\0\1\0\0\23\211\0\0\0\0\0\0\0\0\377\377\364"..., 8192, 0) = 8192
gettimeofday({1180973726, 982754}, NULL) = 0
recv(4, "\0\0\0\0\0\0\0\1\0\0\23\211\0\0\0\0\0\0\0\0\377\377\364"..., 8192, 0) = 8192
gettimeofday({1180973726, 983790}, NULL) = 0
recv(4, "\0\0\0\0\0\0\0\1\0\0\23\211\0\0\0\0\0\0\0\0\377\377\364"..., 8192, 0) = 8192
gettimeofday({1180973726, 984355}, NULL) = 0
recv(4, "\0\0\0\0\0\0\0\1\0\0\23\211\0\0\0\0\0\0\0\0\377\377\364"..., 8192, 0) = 8192

...

gettimeofday({1180973757, 172338}, NULL) = 0
recv(4, "45678901234567890123456789012345"..., 8192, 0) = 1448
gettimeofday({1180973757, 172437}, NULL) = 0
recv(4, "23456789012345678901234567890123"..., 8192, 0) = 1448
gettimeofday({1180973757, 172576}, NULL) = 0
recv(4, "01234567890123456789012345678901"..., 8192, 0) = 1632
gettimeofday({1180973757, 172752}, NULL) = 0
recv(4, "", 8192, 0)                    = 0
gettimeofday({1180973757, 172797}, NULL) = 0
gettimeofday({1180973757, 172817}, NULL) = 0
nanosleep({0, 0}, NULL) = 0
nanosleep({0, 0}, NULL)                 = 0
close(4)                     = 0
futex(0x8055d04, 0x5 /* FUTEX_??? */, 1) = 1
futex(0x8055d30, FUTEX_WAKE, 1) = 0
_exit(0)                                = ?