From owner-freebsd-performance@FreeBSD.ORG Thu Apr 6 07:01:34 2006 Return-Path: X-Original-To: freebsd-performance@freebsd.org Delivered-To: freebsd-performance@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id E3EBC16A422 for ; Thu, 6 Apr 2006 07:01:34 +0000 (UTC) (envelope-from joseph.koshy@gmail.com) Received: from xproxy.gmail.com (xproxy.gmail.com [66.249.82.198]) by mx1.FreeBSD.org (Postfix) with ESMTP id 5FAD143D48 for ; Thu, 6 Apr 2006 07:01:34 +0000 (GMT) (envelope-from joseph.koshy@gmail.com) Received: by xproxy.gmail.com with SMTP id s9so60404wxc for ; Thu, 06 Apr 2006 00:01:33 -0700 (PDT) DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=beta; d=gmail.com; h=received:message-id:date:from:to:subject:cc:in-reply-to:mime-version:content-type:content-transfer-encoding:content-disposition:references; b=oWxpUxVDur/s5Lx75rix8qGYs2WWdhyckxs50tcgNc6tB3jOqyB19uKeXxCWRNigq0ipfx1VycYdNBgCosVVbeOUREy8TPeV3swWhLVw1QpMdWavu9mrEkD4kpmcDdFmcAiGBjhYjY3lveJJhqcgG4CjHl+LYVjMHhz+cRwZxZg= Received: by 10.70.76.18 with SMTP id y18mr786688wxa; Thu, 06 Apr 2006 00:01:33 -0700 (PDT) Received: by 10.70.117.3 with HTTP; Thu, 6 Apr 2006 00:01:33 -0700 (PDT) Message-ID: <84dead720604060001k38cef1f3p7fbb13e3e6c3c662@mail.gmail.com> Date: Thu, 6 Apr 2006 12:31:33 +0530 From: "Joseph Koshy" To: "Sven Petai" In-Reply-To: <200604060339.31800.hadara@bsd.ee> MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Content-Disposition: inline References: <20060405134919.T16926@odysseus.silby.com> <200604060339.31800.hadara@bsd.ee> Cc: freebsd-performance@freebsd.org, Ganbold , Mike Silbersack Subject: Re: mysql tests - one more thing to try X-BeenThere: freebsd-performance@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Performance/tuning List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 06 Apr 2006 07:01:35 -0000 > here are ktrace results for supersmack and mysqld from a dualcore opteron= box > running select smack with 100 threads and 10000 queries > os: fbsd 6.1 prerelease > > =3D=3D=3D=3D syscall stats for supersmack =3D=3D=3D=3D > number of syscalls captured: 42575687 > individual syscalls counts: > read 32914539 77.31% > gettimeofday 3865508 9.08% > fcntl 3862708 9.07% > write 1930922 4.54% > break 325 0.00% > close 301 0.00% > setsockopt 202 0.00% > select 192 0.00% > semop 184 0.00% > connect 101 0.00% > wait4 101 0.00% > socket 101 0.00% > getpid 100 0.00% > fork 100 0.00% > exit 97 0.00% > shutdown 96 0.00% > mmap 27 0.00% > access 15 0.00% > mprotect 12 0.00% > open 12 0.00% > fstat 10 0.00% > munmap 8 0.00% > execve 7 0.00% > ioctl 4 0.00% > stat 3 0.00% > sigprocmask 2 0.00% > issetugid 2 0.00% > lseek 1 0.00% > sysarch 1 0.00% > __sysctl 1 0.00% > semget 1 0.00% > readlink 1 0.00% > sigaction 1 0.00% > pipe 1 0.00% > __semctl 1 0.00% > > request sizes for syscall read > size count % > --------------------------- > 4 15489977 47.06% > 50 3982797 12.10% > 1 3873493 11.77% > 52 2654645 8.07% > 60 1937753 5.89% > 5 1933249 5.87% > 8192 1931176 5.87% > 53 790179 2.40% > 51 274285 0.83% > 49 23467 0.07% > 48 12943 0.04% > 1023 5301 0.02% > 47 2543 0.01% > 46 2497 0.01% > 7 101 0.00% > 24 99 0.00% > 4096 29 0.00% > 128 1 0.00% > 6 1 0.00% > 17796 1 0.00% > 30 1 0.00% > 66 1 0.00% > > request sizes for syscall write > size count % > --------------------------- > 65 1716567 88.90% > 64 193387 10.02% > 63 20584 1.07% > 47 101 0.01% > 5 94 0.00% > 4 92 0.00% > 26 92 0.00% > 34 1 0.00% > 35 1 0.00% > 40 1 0.00% > 49 1 0.00% > 55 1 0.00% > > =3D=3D=3D=3D syscall stats for mysqld =3D=3D=3D=3D > > number of syscalls captured: 20743045 > individual syscalls counts: > _umtx_op 7657825 36.92% > gettimeofday 4308736 20.77% > read 4306035 20.76% > write 1942882 9.37% > sigprocmask 1680724 8.10% > fcntl 838247 4.04% > thr_kill 2827 0.01% > sigwait 2403 0.01% > setitimer 1669 0.01% > select 698 0.00% > setsockopt 202 0.00% > access 101 0.00% > accept 101 0.00% > getsockname 101 0.00% > open 101 0.00% > shutdown 96 0.00% > close 96 0.00% > thr_new 92 0.00% > thr_exit 87 0.00% > break 22 0.00% > > request sizes for syscall write > size count % > --------------------------- > 304 794935 40.92% > 303 720255 37.07% > 302 274534 14.13% > 301 111278 5.73% > 300 23412 1.21% > 299 13079 0.67% > 297 2615 0.13% > 298 2571 0.13% > 11 101 0.01% > 56 101 0.01% > 63 1 0.00% > request sizes for syscall read > size count % > --------------------------- > 4 2362079 54.86% > 61 1728044 40.13% > 60 194721 4.52% > 59 20993 0.49% > 43 101 0.00% > 1 96 0.00% > 31 1 0.00% Ganbold was kind enough to run a hwpmc profiling session while running super-smack. The kernel profile can be seen here: http://www.mnbsd.org/ftp/kernel_gprof.txt Excerpt: granularity: each sample hit covers 4 byte(s) for 0.00% of 111655.00 secon= ds time is in ticks, not seconds % cumulative self self total time seconds seconds calls ms/call ms/call name 6.0 6664.00 6664.00 0 100.00% syscall [1] 4.1 11215.00 4551.00 0 100.00% soreceive [2] 4.1 15743.00 4528.00 0 100.00% binuptime [3] 3.1 19217.00 3474.00 0 100.00% generic_copyout [4] 2.7 22230.00 3013.00 0 100.00% generic_copyin [5] The profile for libmysql (http://www.mnbsd.org/ftp/libmysql_gprof.txt) looked like: time is in ticks, not seconds granularity: each sample hit covers 4 byte(s) for 0.00% of 23377.00 second= s % cumulative self self total time seconds seconds calls ms/call ms/call name 12.2 2850.00 2850.00 0 100.00% MD5Transform [1] 11.3 5503.00 2653.00 0 100.00% sha1_result [2] 9.6 7752.00 2249.00 0 100.00% my_once_alloc [3] 7.7 9561.00 1809.00 0 100.00% my_compress [4] 6.8 11150.00 1589.00 0 100.00% load_defaults [5] 3.2 11904.00 754.00 0 100.00% my_once_strdup [6] These profiles are consistent with there being lots of short-lived system calls. Due to a shortcoming in the profiling toolset, Ganbold's run could not capture what mysqld was doing. -- FreeBSD Volunteer, http://people.freebsd.org/~jkoshy