From owner-freebsd-hackers@FreeBSD.ORG Tue Dec 30 00:34:06 2008 Return-Path: Delivered-To: freebsd-hackers@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 0DD021065680 for ; Tue, 30 Dec 2008 00:34:06 +0000 (UTC) (envelope-from artemb@gmail.com) Received: from mail-ew0-f21.google.com (mail-ew0-f21.google.com [209.85.219.21]) by mx1.freebsd.org (Postfix) with ESMTP id 64A398FC22 for ; Tue, 30 Dec 2008 00:34:05 +0000 (UTC) (envelope-from artemb@gmail.com) Received: by ewy14 with SMTP id 14so6039068ewy.19 for ; Mon, 29 Dec 2008 16:34:04 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from:sender :to:subject:cc:in-reply-to:mime-version:content-type :content-transfer-encoding:content-disposition:references :x-google-sender-auth; bh=J1G8RdZ8bnPPzuGJXVn47oJeYmGiRZs0/P9REn+yM2U=; b=mY5A77PE8W/LeZ/4YxgF6zKDEh4q5coQSKfassd/JDdmSlpu9VaUa3jTLfF+Vmv4mW wFGmUVQethztGADYr85bLWr3OwGfXja5sAd3yXGRlnejAJFdtF5A2NPC275/7tsgJwD9 MLJajrbr1YfQmi2s5WIxu9bST2gOsRfG1IWbw= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:sender:to:subject:cc:in-reply-to:mime-version :content-type:content-transfer-encoding:content-disposition :references:x-google-sender-auth; b=dB48/uv7CDhCAsSHEg8ymDMVVvhK5YDl5CV6hmr/MtEell6WaiG5U2hc+G6VE1mtjt s1Ujuo5ZI9F1Nx5sL+9tmf3RMDGZpskSlJtlMvDS8hR6sT2ROjYlcB0KJ+3nVyL6qTi/ y4yRQOf/CNZ3U0rkiz1aXlqWS0Wxt/knZ76ZU= Received: by 10.210.109.10 with SMTP id h10mr16602011ebc.110.1230595908263; Mon, 29 Dec 2008 16:11:48 -0800 (PST) Received: by 10.210.87.12 with HTTP; Mon, 29 Dec 2008 16:11:48 -0800 (PST) Message-ID: Date: Mon, 29 Dec 2008 16:11:48 -0800 From: "Artem Belevich" Sender: artemb@gmail.com To: "Nate Eldredge" In-Reply-To: MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-Disposition: inline References: X-Google-Sender-Auth: bbff1c951aa786a9 Cc: freebsd-hackers@freebsd.org, Christian Weisgerber Subject: Re: lzo2 shows insane speed gap X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 30 Dec 2008 00:34:06 -0000 I see this performance difference on my boxes. First one has Core2Duo(E5-something), 4GB and runs RELENG_7/i386. lzotest is very fast. Second box is Core2Quad (Q9450), 8GB RAM and runs -current as of about a week ago. lzo2 binary built from ports is *slow*. However, 32-bit binary from the first box runs very fast. The only interesting difference I can see in ktrace is that read and munmap take much much longer in case of 64-bit lzotest. Here are two excerpts from ktrace on the second box: ### 32-bit app - runs fast on both boxes. 59657 lzotest 0.000010 CALL open(0xffffd91b,O_RDONLY,0x1b6) 59657 lzotest 0.000007 NAMI "./src/lzo1_d.ch" 59657 lzotest 0.000012 RET open 3 59657 lzotest 0.000005 CALL fstat(0x3,0xffffd504) 59657 lzotest 0.000007 STRU struct stat {dev=102, ino=544718, mode=-rw-r--r-- , nlink=1, uid=0, gid=0, rdev=2169160, atime=1230595144, stime=1209559909, ctime=1230588212, birthtime=1209559909, size=4563, blksize=4096, blocks=12, flags=0x0 } 59657 lzotest 0.000005 RET fstat 0 59657 lzotest 0.000006 CALL lseek(0x3,0,SEEK_SET,0x1) 59657 lzotest 0.000005 RET lseek 0 59657 lzotest 0.000005 CALL lseek(0x3,0x4000000,SEEK_SET,0) 59657 lzotest 0.000005 RET lseek 67108864/0x4000000 59657 lzotest 0.000006 CALL lseek(0x3,0,SEEK_SET,0) 59657 lzotest 0.000005 RET lseek 0 59657 lzotest 0.000005 CALL mmap(0,0x4000000,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,0xffffffff,0,0) 59657 lzotest 0.000007 RET mmap 673185792/0x28200000 59657 lzotest 0.000006 CALL read(0x3,0x28196000,0x1000) 59657 lzotest 0.000010 GIO fd 3 read 4096 bytes 59657 lzotest 0.000029 RET read 4096/0x1000 59657 lzotest 0.000028 CALL read(0x3,0x28196000,0x1000) 59657 lzotest 0.000010 GIO fd 3 read 467 bytes 59657 lzotest 0.000005 RET read 467/0x1d3 59657 lzotest 0.000010 CALL read(0x3,0x28196000,0x1000) 59657 lzotest 0.000007 GIO fd 3 read 0 bytes 59657 lzotest 0.000006 RET read 0 59657 lzotest 0.000005 CALL close(0x3) 59657 lzotest 0.000010 RET close 0 59657 lzotest 0.000025 CALL getrusage(0,0xffffd60c) 59657 lzotest 0.000006 RET getrusage 0 59657 lzotest 0.000005 CALL getrusage(0,0xffffd628) 59657 lzotest 0.000006 RET getrusage 0 59657 lzotest 0.000005 CALL getrusage(0,0xffffd60c) 59657 lzotest 0.000006 RET getrusage 0 59657 lzotest 0.000064 CALL getrusage(0,0xffffd60c) 59657 lzotest 0.000006 RET getrusage 0 59657 lzotest 0.000005 CALL getrusage(0,0xffffd60c) 59657 lzotest 0.000006 RET getrusage 0 59657 lzotest 0.000029 CALL getrusage(0,0xffffd60c) 59657 lzotest 0.000006 RET getrusage 0 59657 lzotest 0.000012 CALL getrusage(0,0xffffd60c) 59657 lzotest 0.000036 RET getrusage 0 59657 lzotest 0.000010 CALL write(0x1,0x28194000,0x4f) 59657 lzotest 0.000010 GIO fd 1 wrote 79 bytes 59657 lzotest 0.000006 RET write 79/0x4f 59657 lzotest 0.000006 CALL munmap(0x28200000,0x4000000) 59657 lzotest 0.000017 RET munmap 0 ### same file. 64-bit app (slow). Look at read/munmap 59158 lzotest 0.000015 CALL open(0x7fffffffe760,O_RDONLY,0x1b6) 59158 lzotest 0.000014 NAMI "./src/lzo1_d.ch" 59158 lzotest 0.000024 RET open 3 59158 lzotest 0.000011 CALL fstat(0x3,0x7fffffffe2d0) 59158 lzotest 0.000011 STRU struct stat {dev=102, ino=544718, mode=-rw-r--r-- , nlink=1, uid=0, gid=0, rdev=2169160, atime=1230588427, stime=1209559909, ctime=1230588212, birthtime=1209559909, size=4563, blksize=4096, blocks=12, flags=0x0 } 59158 lzotest 0.000007 RET fstat 0 59158 lzotest 0.000015 CALL lseek(0x3,0,SEEK_CUR) 59158 lzotest 0.000007 RET lseek 0 59158 lzotest 0.000006 CALL lseek(0x3,0x4000000,SEEK_SET) 59158 lzotest 0.000007 RET lseek 67108864/0x4000000 59158 lzotest 0.000007 CALL lseek(0x3,0,SEEK_SET) 59158 lzotest 0.000006 RET lseek 0 59158 lzotest 0.000008 CALL mmap(0,0x4000000,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,0xffffffff,0) 59158 lzotest 0.000010 RET mmap 11534336/0x800b00000 59158 lzotest 0.074126 CALL read(0x3,0x800a9e000,0x1000) 59158 lzotest 0.000054 GIO fd 3 read 4096 bytes 59158 lzotest 0.000010 RET read 4096/0x1000 59158 lzotest 0.000007 CALL read(0x3,0x800a9e000,0x1000) 59158 lzotest 0.000012 GIO fd 3 read 467 bytes 59158 lzotest 0.000006 RET read 467/0x1d3 59158 lzotest 0.000007 CALL read(0x3,0x800a9e000,0x1000) 59158 lzotest 0.000009 GIO fd 3 read 0 bytes 59158 lzotest 0.000006 RET read 0 59158 lzotest 0.000008 CALL close(0x3) 59158 lzotest 0.000020 RET close 0 59158 lzotest 0.000029 CALL getrusage(0,0x7fffffffe3d0) 59158 lzotest 0.000010 RET getrusage 0 59158 lzotest 0.000007 CALL getrusage(0,0x7fffffffe3e0) 59158 lzotest 0.000007 RET getrusage 0 59158 lzotest 0.000007 CALL getrusage(0,0x7fffffffe3d0) 59158 lzotest 0.000007 RET getrusage 0 59158 lzotest 0.000069 CALL getrusage(0,0x7fffffffe3d0) 59158 lzotest 0.000007 RET getrusage 0 59158 lzotest 0.000006 CALL getrusage(0,0x7fffffffe3d0) 59158 lzotest 0.000007 RET getrusage 0 59158 lzotest 0.000030 CALL getrusage(0,0x7fffffffe3d0) 59158 lzotest 0.000006 RET getrusage 0 59158 lzotest 0.000014 CALL getrusage(0,0x7fffffffe3d0) 59158 lzotest 0.000006 RET getrusage 0 59158 lzotest 0.000024 CALL write(0x1,0x800a9c000,0x4f) 59158 lzotest 0.000030 GIO fd 1 wrote 79 bytes 59158 lzotest 0.000008 RET write 79/0x4f 59158 lzotest 0.015677 CALL munmap(0x800b00000,0x4000000) 59158 lzotest 0.005430 RET munmap 0 --Artem