From owner-freebsd-questions@FreeBSD.ORG Mon May 28 07:08:10 2007 Return-Path: X-Original-To: freebsd-questions@freebsd.org Delivered-To: freebsd-questions@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id D277716A400 for ; Mon, 28 May 2007 07:08:10 +0000 (UTC) (envelope-from kayama@personal-media.co.jp) Received: from net1.personal-media.co.jp (net1.personal-media.co.jp [61.197.224.164]) by mx1.freebsd.org (Postfix) with ESMTP id A41C913C458 for ; Mon, 28 May 2007 07:08:10 +0000 (UTC) (envelope-from kayama@personal-media.co.jp) Received: from pcsv1.personal-media.co.jp (net2 [192.168.201.168]) by net1.personal-media.co.jp (Postfix) with ESMTP id E1E27AE013 for ; Mon, 28 May 2007 15:47:53 +0900 (JST) Received: from localhost (r53 [192.9.200.153]) by pcsv1.personal-media.co.jp (Postfix) with ESMTP id D0D713598A for ; Mon, 28 May 2007 15:47:53 +0900 (JST) Date: Mon, 28 May 2007 15:47:53 +0900 (GMT-9) Message-Id: <20070528.154753.32719103.kayama@personal-media.co.jp> To: freebsd-questions@freebsd.org From: Akihiro KAYAMA X-Mailer: Mew version 3.3 on Emacs 21.2 / Mule 5.0 (SAKAKI) Mime-Version: 1.0 Content-Type: Text/Plain; charset=us-ascii Content-Transfer-Encoding: 7bit Subject: wall-clock time profiling X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 28 May 2007 07:08:10 -0000 Hi all. What is the right way to measure wall-clock time in profiling on FreeBSD? Standard profiling method in UNIX like 'gprof' measures CPU time, but it doesn't always offer a good indication for tuning if application is not CPU bound. For example, the below simple program spend most of the time for disk I/O, but gprof doesn't tell me that fsync(2) in output() is the hot-spot which should be removed at first. ------------------------------------------------------------ #include #include #include #include char calc() { int i; char c; for (i = 0; i < 10000; i++) { c = c * i; } return c; } void output(int fd, char c) { write(fd, &c, 1); fsync(fd); /* XXX time consuming system call */ } int main() { int fd; int i; char c; fd = open("testfile", O_CREAT | O_WRONLY); for (i = 0; i < 10000; i++) { c = calc(i); output(fd, c); } return 0; } ------------------------------------------------------------ gprof's output: % cumulative self self total time seconds seconds calls ms/call ms/call name 84.2 0.56 0.56 10000 0.06 0.06 calc [3] 13.6 0.65 0.09 10000 0.01 0.01 _fsync [5] 1.4 0.66 0.01 10000 0.00 0.00 write [6] 0.7 0.66 0.00 .mcount (12) 0.2 0.66 0.00 10000 0.00 0.01 output [4] ------------------------------------------------------------ Measuring CPU time has been proper for traditional UNIX as TSS, but I think wall-clock time is also useful in these days. It is affected by system load, but it is easy to arrange some dedicated system for profiling purpose. Wall-clock time profiling itself could be implemented by simple kernel hack (i386/i386/trap.c:syscall() and kern/subr_trap.c:userret()), but if both CPU and wall-clock time profiling are available, I don't know how users should change the method. sysctl(8) may be inappropriate. Although I'm not familiar with another analysis tools, like DTrace for FreeBSD, is there something help for me? Thanks. -- Akihiro KAYAMA