Re: onstat -g iof
Question about interpreting `onstat -g iof` on IDS 11.50.FC4 (AIX, cooked files with CIO): why "page reads/writes" don't match kaio_reads/writes, and what the io/s column actually means. Fernando explained each I/O operation can transfer more than one page, so page counts exceed operation counts. For io/s, the manual's wording was disputed; Art and ultimately John Miller (IBM) clarified that the server times every I/O per device and reports total I/O time divided by number of operations since boot or onstat -z, i.e. the real response time Informix sees (influenced by OS/hardware caches). The poster was satisfied.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Please check because I'm talking without looking at any documentation:
kaio_reads/writes are I/O operations. Each operation can read/write more
than one page.
I/Os per second is a nasty number... Why? As far as I remember it's the
number of I/Os done divided by the time the instance is up (or the time
elapsed since the counters were reset with onstat -z). So this number will
decrease with time if the instance becomes idle..
hmmmm... checking again you say it doesn't match... did you reset the stats?
Regards.
On Thu, May 27, 2010 at 1:32 PM, ROBERT CLOW <robert@clow.biz> wrote:
> Can someone please advise what the following fields in this command
> actually
> show? (I have looked at the ids 11.50 info center and it does not clarify
> these to me)
> I am using 11.50.FC4 and cooked filesystem using concurrent io under aix
> 6.1.
>
> AIO global files:
> gfd pathname bytes read page reads bytes write page writes io/s
> 3 root_01 3874009088 945803 480342016 117271 371.2
>
> op type count avg. time
>
> seeks 0 N/A
>
> reads 0 N/A
>
> writes 0 N/A
>
> kaio_reads 443254 0.0024
>
> kaio_writes 8999 0.0181
>
> Page reads does not equal kaio_reads... eg 945,803 <> 443,254
>
> Why? and the same for writes... eg 117,271 <> 8,999 (I could understand
> this
> if page writes were buffer writes - but the words don't say that)
>
> Additionally: io/s are shown as 371.2 but this does not equate to either
> kaioxxx or pagexxx divided by time (34 hours 10 minutes)
> IO/s has increased and decreased over time... so not a maximum or minimum.
> I
> have an 11.50.fc3 engine on a very similar platform (san different) that is
> showing 25,000 io/s
> What is this metric?
>
> I believe that avg. time is correct ie the time from asking the aix kernal
> to
> service an io request til the time it returns... then averaged over the
> count
> but would like confirmation as the other fields are not what they seem
>
> Thanks
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--
Fernando Nunes
Portugal
http://informix-technology.blogspot.com
My email works... but I don't check it frequently...
--0016e65a085ce0ac11048792b30b
Thanks for replying Fernando.
>kaio_reads/writes are I/O operations. Each operation can read/write more than
one page.
Ah that makes 100% sense...
>I/Os per second is a nasty number...
No - no reset of the stats... (onstat -z - I thought of that too)
I have some hard questions I have to answer around this... And one is why I
can get high numbers 25,000 on a cooked filesystem using DIRECT_IO 1 when I
can not get the same number on this site - even when I used DIRECT_IO 2.
The only difference I can see as significant is the 25,000 is sitting on a
Hitachi array (I won't mention the other vendor, sucficient to say a well
known specialist SAN vendor that predated Hitachi arrays)
Robert,
From the fine manual:
io/s Number of I/O operations that can be performed per second. This value
represents the I/O performance of the chunk or file.
So... I'd say I was wrong and that this is not a nasty number. Apparently it
measures the number of I/Os per second that the system was able to reach.
Several things could impact this:
1- raw disk performance
2- hardware cache being used
3- available cpu
2) can really make a difference. I could provide some more info about this
regarding this topic. Basically sometimes you're asking to read a page, but
possibly that page is walready in the hardware cache (disk arrray,
disk....). So there is no seek time involved etc.
There were some discussions that lead to this point in the last months here.
Don't ignore this factor in your analysis!
Regards.
On Thu, May 27, 2010 at 3:30 PM, ROBERT CLOW <robert@clow.biz> wrote:
> Thanks for replying Fernando.
>
> >kaio_reads/writes are I/O operations. Each operation can read/write more
> than
> one page.
> Ah that makes 100% sense...
>
> >I/Os per second is a nasty number...
> No - no reset of the stats... (onstat -z - I thought of that too)
>
> I have some hard questions I have to answer around this... And one is why I
> can get high numbers 25,000 on a cooked filesystem using DIRECT_IO 1 when I
> can not get the same number on this site - even when I used DIRECT_IO 2.
>
> The only difference I can see as significant is the 25,000 is sitting on a
> Hitachi array (I won't mention the other vendor, sucficient to say a well
> known specialist SAN vendor that predated Hitachi arrays)
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--
Fernando Nunes
Portugal
http://informix-technology.blogspot.com
My email works... but I don't check it frequently...
--0016e6d7e9a39e1a3e048794c96e
Thanks again but I do not believe that the manual is correct
onstat taken at 04:00
32 data_part_02_02 3899850752 952112 52940800 12925 660.4
op type count avg. time
seeks 0 N/A
reads 0 N/A
writes 0 N/A
kaio_reads 259790 0.0013
kaio_writes 921 0.0605
And at 08:00
32 data_part_02_02 3931705344 959889 69881856 17061 643.1
op type count avg. time
seeks 0 N/A
reads 0 N/A
writes 0 N/A
kaio_reads 260172 0.0013
kaio_writes 1192 0.0530
as can be seen 660.4 io/s at 04:00 and 643.1 at 08:00 This looks like it is
the io/s during some time window - don't know if maximum or average - looks
like maximum..
So still trying to fully understand what I am seeing
That was I was trying to say... That should be the number of I/Os per second
that it can do.
Let's imagine something like, the number of I/Os done divided by the time
spent on I/O.
And I now have a doubt... If it understands that an I/O can read 1 page or
more... This means that an instance that's doing lots of Read Ahead would
have less I/Os per second if everything else was the same...
I will try to gather more info, but a ping from one of the gurus would be
nice :)
Regards.
On Thu, May 27, 2010 at 10:26 PM, ROBERT CLOW <robert@clow.biz> wrote:
> Thanks again but I do not believe that the manual is correct
>
> onstat taken at 04:00
>
> 32 data_part_02_02 3899850752 952112 52940800 12925 660.4
>
> op type count avg. time
>
> seeks 0 N/A
>
> reads 0 N/A
>
> writes 0 N/A
>
> kaio_reads 259790 0.0013
>
> kaio_writes 921 0.0605
>
> And at 08:00
>
> 32 data_part_02_02 3931705344 959889 69881856 17061 643.1
>
> op type count avg. time
>
> seeks 0 N/A
>
> reads 0 N/A
>
> writes 0 N/A
>
> kaio_reads 260172 0.0013
>
> kaio_writes 1192 0.0530
>
> as can be seen 660.4 io/s at 04:00 and 643.1 at 08:00 This looks like it is
> the io/s during some time window - don't know if maximum or average - looks
> like maximum..
>
> So still trying to fully understand what I am seeing
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--
Fernando Nunes
Portugal
http://informix-technology.blogspot.com
My email works... but I don't check it frequently...
--0016367fb711359a2804879a471e
Someone from the Labs (maybe Scott Lashley, maybe John Miller III) told me
once that the io/s is calculated as a rolling value that's only updated when
there is actual IO being performed. The exact mechanics of how the engine
implements that calculation I don't know, but it would be something like
storing the total time spent performing IO divided in to the number of IOs
not elapsed clock time since startup or since stats were zero'd.
Art
Art S. Kagel
Advanced DataTools (www.advancedatatools.com)
IIUG Board of Directors (art@iiug.org)
Disclaimer: Please keep in mind that my own opinions are my own opinions and
do not reflect on my employer, Advanced DataTools, the IIUG, nor any other
organization with which I am associated either explicitly, implicitly, or by
inference. Neither do those opinions reflect those of other individuals
affiliated with any entity with which I am affiliated nor those of the
entities themselves.
On Thu, May 27, 2010 at 5:26 PM, ROBERT CLOW <robert@clow.biz> wrote:
> Thanks again but I do not believe that the manual is correct
>
> onstat taken at 04:00
>
> 32 data_part_02_02 3899850752 952112 52940800 12925 660.4
>
> op type count avg. time
>
> seeks 0 N/A
>
> reads 0 N/A
>
> writes 0 N/A
>
> kaio_reads 259790 0.0013
>
> kaio_writes 921 0.0605
>
> And at 08:00
>
> 32 data_part_02_02 3931705344 959889 69881856 17061 643.1
>
> op type count avg. time
>
> seeks 0 N/A
>
> reads 0 N/A
>
> writes 0 N/A
>
> kaio_reads 260172 0.0013
>
> kaio_writes 1192 0.0530
>
> as can be seen 660.4 io/s at 04:00 and 643.1 at 08:00 This looks like it is
> the io/s during some time window - don't know if maximum or average - looks
> like maximum..
>
> So still trying to fully understand what I am seeing
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--00504502cc915bd0c304879b33d4
Which is what I understand from the manual, although it's not very explicit.
Again, this is I/O operations, and it can be greatly influenced by hardware
caches.
Regards.
On Thu, May 27, 2010 at 11:49 PM, Art Kagel <art.kagel@gmail.com> wrote:
> Someone from the Labs (maybe Scott Lashley, maybe John Miller III) told me
> once that the io/s is calculated as a rolling value that's only updated
> when
> there is actual IO being performed. The exact mechanics of how the engine
> implements that calculation I don't know, but it would be something like
> storing the total time spent performing IO divided in to the number of IOs
> not elapsed clock time since startup or since stats were zero'd.
>
> Art
>
> Art S. Kagel
> Advanced DataTools (www.advancedatatools.com)
> IIUG Board of Directors (art@iiug.org)
>
> Disclaimer: Please keep in mind that my own opinions are my own opinions
> and
> do not reflect on my employer, Advanced DataTools, the IIUG, nor any other
> organization with which I am associated either explicitly, implicitly, or
> by
> inference. Neither do those opinions reflect those of other individuals
> affiliated with any entity with which I am affiliated nor those of the
> entities themselves.
>
> On Thu, May 27, 2010 at 5:26 PM, ROBERT CLOW <robert@clow.biz> wrote:
>
> > Thanks again but I do not believe that the manual is correct
> >
> > onstat taken at 04:00
> >
> > 32 data_part_02_02 3899850752 952112 52940800 12925 660.4
> >
> > op type count avg. time
> >
> > seeks 0 N/A
> >
> > reads 0 N/A
> >
> > writes 0 N/A
> >
> > kaio_reads 259790 0.0013
> >
> > kaio_writes 921 0.0605
> >
> > And at 08:00
> >
> > 32 data_part_02_02 3931705344 959889 69881856 17061 643.1
> >
> > op type count avg. time
> >
> > seeks 0 N/A
> >
> > reads 0 N/A
> >
> > writes 0 N/A
> >
> > kaio_reads 260172 0.0013
> >
> > kaio_writes 1192 0.0530
> >
> > as can be seen 660.4 io/s at 04:00 and 643.1 at 08:00 This looks like it
> is
> > the io/s during some time window - don't know if maximum or average -
> looks
> > like maximum..
> >
> > So still trying to fully understand what I am seeing
> >
> >
> >
> >
>
>
*******************************************************************************
> > Forum Note: Use "Reply" to post a response in the discussion forum.
> >
> >
>
> --00504502cc915bd0c304879b33d4
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--
Fernando Nunes
Portugal
http://informix-technology.blogspot.com
My email works... but I don't check it frequently...
--0016367f9eee53ab0004879ba4a5
In short the server times every single I/O operation performed along with
how many I/O operations
have occurred by device. The reports average time per device is just the
time for all I/O operations
divide by the number of operations. While I understand that this can be
influenced by OS caches and
other OS and hardware performance aids. This is the true response time
that Informix is seeing.
This is formation is calculated since the server booted or an onstat -z
whichever is more recent.
John F. Miller III
STSM, Support Architect
miller3@us.ibm.com
503-578-5645
IBM Informix Dynamic Server (IDS)
ids-bounces@iiug.org wrote on 05/27/2010 04:20:58 PM:
> [image removed]
>
> Re: onstat -g iof [20250]
>
> Fernando Nunes
>
> to:
>
> ids
>
> 05/27/2010 04:21 PM
>
> Sent by:
>
> ids-bounces@iiug.org
>
> Please respond to ids
>
> Which is what I understand from the manual, although it's not very
explicit.
> Again, this is I/O operations, and it can be greatly influenced by
hardware
> caches.
>
> Regards.
>
> On Thu, May 27, 2010 at 11:49 PM, Art Kagel <art.kagel@gmail.com> wrote:
>
> > Someone from the Labs (maybe Scott Lashley, maybe John Miller III) told
me
> > once that the io/s is calculated as a rolling value that's only updated
> > when
> > there is actual IO being performed. The exact mechanics of how the
engine
> > implements that calculation I don't know, but it would be something
like
> > storing the total time spent performing IO divided in to the number of
IOs
> > not elapsed clock time since startup or since stats were zero'd.
> >
> > Art
> >
> > Art S. Kagel
> > Advanced DataTools (www.advancedatatools.com)
> > IIUG Board of Directors (art@iiug.org)
> >
> > Disclaimer: Please keep in mind that my own opinions are my own
opinions
> > and
> > do not reflect on my employer, Advanced DataTools, the IIUG, nor any
other
> > organization with which I am associated either explicitly, implicitly,
or
> > by
> > inference. Neither do those opinions reflect those of other individuals
> > affiliated with any entity with which I am affiliated nor those of the
> > entities themselves.
> >
> > On Thu, May 27, 2010 at 5:26 PM, ROBERT CLOW <robert@clow.biz> wrote:
> >
> > > Thanks again but I do not believe that the manual is correct
> > >
> > > onstat taken at 04:00
> > >
> > > 32 data_part_02_02 3899850752 952112 52940800 12925 660.4
> > >
> > > op type count avg. time
> > >
> > > seeks 0 N/A
> > >
> > > reads 0 N/A
> > >
> > > writes 0 N/A
> > >
> > > kaio_reads 259790 0.0013
> > >
> > > kaio_writes 921 0.0605
> > >
> > > And at 08:00
> > >
> > > 32 data_part_02_02 3931705344 959889 69881856 17061 643.1
> > >
> > > op type count avg. time
> > >
> > > seeks 0 N/A
> > >
> > > reads 0 N/A
> > >
> > > writes 0 N/A
> > >
> > > kaio_reads 260172 0.0013
> > >
> > > kaio_writes 1192 0.0530
> > >
> > > as can be seen 660.4 io/s at 04:00 and 643.1 at 08:00 This looks like
it
> > is
> > > the io/s during some time window - don't know if maximum or average -
> > looks
> > > like maximum..
> > >
> > > So still trying to fully understand what I am seeing
> > >
> > >
> > >
> > >
> >
> >
>
*******************************************************************************
> > > Forum Note: Use "Reply" to post a response in the discussion forum.
> > >
> > >
> >
> > --00504502cc915bd0c304879b33d4
> >
> >
> >
> >
>
*******************************************************************************
> > Forum Note: Use "Reply" to post a response in the discussion forum.
> >
> >
>
> --
> Fernando Nunes
> Portugal
>
> http://informix-technology.blogspot.com
> My email works... but I don't check it frequently...
>
> --0016367f9eee53ab0004879ba4a5
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
Thanks John (and Art and Fernando) I believe you have answered my question
Related threads
- IDS not writing to online.log
- Help!!! syntax error
- installclientsdk bug?
- RamDisk tempdbs boot script for Linux