From owner-freebsd-fs@FreeBSD.ORG Wed Oct 12 20:48:30 2011 Return-Path: Delivered-To: freebsd-fs@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 7E0B8106566C for ; Wed, 12 Oct 2011 20:48:30 +0000 (UTC) (envelope-from to.my.trociny@gmail.com) Received: from mail-ey0-f182.google.com (mail-ey0-f182.google.com [209.85.215.182]) by mx1.freebsd.org (Postfix) with ESMTP id BAF0B8FC13 for ; Wed, 12 Oct 2011 20:48:29 +0000 (UTC) Received: by eyd10 with SMTP id 10so1520271eyd.13 for ; Wed, 12 Oct 2011 13:48:28 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=from:to:cc:subject:references:x-comment-to:sender:date:in-reply-to :message-id:user-agent:mime-version:content-type :content-transfer-encoding; bh=nQazewpLk7sLXXeN7gJjtt36bK4Ojj3Tu8KNhVoLzpA=; b=oLJLS5k9mZlNFt9oFI5h91i4/Lz45V6Dg652aboad4opRS8c8/bBWrTOnyv5YTKe1o AbLE412NkKvnf/E5wJuTDOID3WtnTlv5OEcUoMO4HcGbT1q9Ap7q/DLYyQFL0IEIn3UJ RhMIQxDodTcOJ6ZBsnp26cKqwC1+MFFiAW+r0= Received: by 10.223.17.11 with SMTP id q11mr1084336faa.13.1318452508374; Wed, 12 Oct 2011 13:48:28 -0700 (PDT) Received: from localhost ([95.69.173.122]) by mx.google.com with ESMTPS id u6sm5688421faf.3.2011.10.12.13.48.26 (version=TLSv1/SSLv3 cipher=OTHER); Wed, 12 Oct 2011 13:48:27 -0700 (PDT) From: Mikolaj Golub To: Wiktor Niesiobedzki References: <20110915120007.F41FF10656E1@hub.freebsd.org> <4B8C8026-1E12-4C32-88E3-9B34A3E58A91@patpro.net> <86ipnwg1s0.fsf@kopusha.home.net> <94455706-B90D-4DBD-A7DE-E9A38F118D35@patpro.net> X-Comment-To: Wiktor Niesiobedzki Sender: Mikolaj Golub Date: Wed, 12 Oct 2011 23:48:24 +0300 In-Reply-To: (Wiktor Niesiobedzki's message of "Wed, 12 Oct 2011 21:06:32 +0200") Message-ID: <86d3e2lyw7.fsf@kopusha.home.net> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/23.2 (berkeley-unix) MIME-Version: 1.0 Content-Type: text/plain; charset=koi8-r Content-Transfer-Encoding: 8bit Cc: freebsd-fs@freebsd.org, Patrick Proniewski Subject: Re: measuring IO asynchronously X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 12 Oct 2011 20:48:30 -0000 On Wed, 12 Oct 2011 21:06:32 +0200 Wiktor Niesiobedzki wrote: WN> 2011/10/12 Patrick Proniewski >> >> On 10 oct. 2011, at 20:05, Mikolaj Golub wrote: >> >> > On Mon, 10 Oct 2011 16:33:11 +0200 Patrick Proniewski wrote: >> > PP> I would like to monitor the storage on various FreeBSD servers, >> > PP> especially I/O per seconds. Is there any way to gather statistics >> > PP> about I/O via asynchronous request, lets say, for example, using a >> > PP> munin plugin? š`iostat -w 1` and `zpool iostat tank 1` are >> > PP> interesting, but not useable asynchronously. >> > >> > I use for this a simple program that I wrote some time ago. It uses devstat(9) >> > kernel interface and outputs counters, like below >> > >> > kopusha:~% devstat ada0 >> > ada0: >> > š š š š1339552256 bytes read >> > ../.. >> > You can find it in ports (sysutils/devstat). >> >> Thank you Mikolaj, I'm going to give it a try! >> WN> What's wrong about iostat? (and how it is used by munin plugin) WN> %iostat -I -x WN> extended device statistics WN> device r/i w/i kr/i WN> kw/i wait svc_t %b WN> ada0 26756321.0 77603114.0 411881657.5 1192108987.0 0 3.2 1 WN> ada1 13483063.0 1131450.0 943635180.5 43584216.0 0 5.7 0 WN> ada2 13831313.0 1131763.0 943961104.5 43587768.0 0 5.5 0 Well, may be nothing wrong and I just don't well understand all its capabilities. But taking your example above, usually I am very interested in busy %. Running the following: kopusha:~% iostat -I -x ada0 ; devstat ada0; sleep 60; iostat -I -x ada0 ; devstat ada0 extended device statistics device r/i w/i kr/i kw/i qlen svc_t %b ada0 343745.0 105155.0 1321490.0 2021456.5 0 3.5 10 ada0: 1353218560 bytes read 2069971456 bytes written 0 bytes freed 343746 reads 105155 writes 0 frees 32 other duration: 1273 9857428529740234978/2^64 sec reads 300 1686376179659773404/2^64 sec writes 0 0/2^64 sec frees 1125 13002965656490398846/2^64 sec busy time 5 18135162071037186601/2^64 sec creation time 512 block size tags sent: 448933 simple 0 ordered 0 head of queue supported statistics measurements flags: 0 device type: 32 devstat list insert priority: 272 extended device statistics device r/i w/i kr/i kw/i qlen svc_t %b ada0 361949.0 106292.0 1342183.5 2060756.0 1 3.5 10 ada0: 1374395904 bytes read 2110214144 bytes written 0 bytes freed 361949 reads 106292 writes 0 frees 32 other duration: 1313 2389256899477793268/2^64 sec reads 308 8013777376704320252/2^64 sec writes 0 0/2^64 sec frees 1163 13731036726762718640/2^64 sec busy time 5 18135162071037186601/2^64 sec creation time 512 block size tags sent: 468273 simple 0 ordered 0 head of queue supported statistics measurements flags: 0 device type: 32 devstat list insert priority: 272 read/write counters are the same so I could calculate e.g average writes per sec for that minute. But %b column from iostat output not very useful while taking busy time from devstat output I can calculate that I had for that minute (1163 - 1125) / 60 * 100 = 63% disk busy. Also, there are "sec reads/writes", which actually give results that look a little confusing for me, but at least they tell if the disk was mostly busy reading or writing. And running this with my gather utility (can be found in ports, advertisement again :-) I can look at disk busy % at any interesting for me time: kopusha:~% gather show -t 10m grep 'ada0.*busy time' devstat | awk '{if (old) print $0 "\t", 100.0*($4-old)/60; old=$4}' 2011-10-12 23:34: ada0: 1293 14987467510083879798/2^64 sec busy time 1.66667 2011-10-12 23:35: ada0: 1293 16332874492165216024/2^64 sec busy time 0 2011-10-12 23:36: ada0: 1294 8579604187790414908/2^64 sec busy time 1.66667 2011-10-12 23:37: ada0: 1295 3568670710727311468/2^64 sec busy time 1.66667 2011-10-12 23:38: ada0: 1327 9449174491988114920/2^64 sec busy time 53.3333 2011-10-12 23:39: ada0: 1328 291265921399568052/2^64 sec busy time 1.66667 2011-10-12 23:40: ada0: 1328 17998157209099769080/2^64 sec busy time 0 2011-10-12 23:41: ada0: 1329 8166685340768241914/2^64 sec busy time 1.66667 2011-10-12 23:42: ada0: 1330 18381582750921335228/2^64 sec busy time 1.66667 2011-10-12 23:43: ada0: 1331 7748302105755174350/2^64 sec busy time 1.66667 On the other hand on some problem productions I have been running permanently something like below :-) iostat $IOSTATOPTIONS $IOSTATINTERVAL $IOSTATCOUNT | perl -MPOSIX -ne 'print strftime("%F %H:%M:%S: ", gmtime), $_;' > "$statdir/$IOSTATOUT" which outputs 2011-10-12 12:00:01: extended device statistics 2011-10-12 12:00:01: device r/s w/s kr/s kw/s wait svc_t %b 2011-10-12 12:00:01: mfid0 5.0 33.4 435.2 1132.4 0 78.4 7 2011-10-12 12:00:07: extended device statistics 2011-10-12 12:00:07: device r/s w/s kr/s kw/s wait svc_t %b 2011-10-12 12:00:07: mfid0 3.3 19.5 44.5 311.4 0 0.9 2 2011-10-12 12:00:12: extended device statistics 2011-10-12 12:00:12: device r/s w/s kr/s kw/s wait svc_t %b 2011-10-12 12:00:12: mfid0 0.4 0.6 2.7 9.3 0 2.7 0 2011-10-12 12:00:17: extended device statistics 2011-10-12 12:00:17: device r/s w/s kr/s kw/s wait svc_t %b 2011-10-12 12:00:17: mfid0 0.2 1.8 2.8 115.1 0 0.7 0 ... -- Mikolaj Golub