| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20070604095924.651d91c8@freepuppy>
Date: Mon, 4 Jun 2007 09:59:24 -0700
From: Stephen Hemminger <shemminger@...ux-foundation.org>
To: Thomas Gleixner <tglx@...utronix.de>,
Ulrich Drepper <drepper@...il.com>
Cc: Maximilian Engelhardt <maxi@...monizer.de>,
Michael Buesch <mb@...sch.de>,
linux-kernel <linux-kernel@...r.kernel.org>,
linux-wireless <linux-wireless@...r.kernel.org>,
Arnaldo Carvalho de Melo <acme@...stprotocols.net>,
Jeff Garzik <jgarzik@...ox.com>,
Gary Zambrano <zambrano@...adcom.com>, netdev@...r.kernel.org,
Andrew Morton <akpm@...ux-foundation.org>
Subject: iperf: performance regression (was b44 driver problem?)
On Mon, 04 Jun 2007 18:35:58 +0200
Thomas Gleixner <tglx@...utronix.de> wrote:
> On Mon, 2007-06-04 at 09:09 -0700, Stephen Hemminger wrote:
> > > > 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
>
> > 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) = ?
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists