IDS 11.5 Procedures slow at seemningly random time
George reported that two SPL procedures called every 10 minutes from a Perl script occasionally (3-7 times a day, at random) took minutes instead of seconds, with even the time from script start to the first statement in the procedure stretching to 8-14 seconds. His server was IDS 11.50.UC5DE on Linux RHEL4 x86_64. Art Kagel listed possible causes: B-tree cleaner activity, unrelated batch jobs competing for I/O, cooked chunks sharing the system buffer cache, cache-flushing by other jobs, and especially UPDATE STATISTICS forcing SPL plans to auto-recompile (suggesting recompiling procedures after stats runs, e.g. via his dostats utility). He then asked for ONCONFIG and various onstat outputs. The thread ends there with no resolution recorded.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Hello all,
I have been spending a bit of time investigating a problem I have with
a couple of my SPL procedures. To give you some background. I have
two SPLs that are invoked through a Perl script every 10 min. Three
to seven times every 24 hour period (at seemingly random times) these
procedures run slowly, some times they take a few minutes to complete,
when all the other times it takes 10 seconds or less. I went into a
search to find out whether exclusive locks exist the cause the
slowdown--I was not able to find much and I was able to see that all
our DB work is started with
SET ISOLATION TO DIRTY READ;
SET LOCK MODE TO WAIT 5;which seems reasonable.
What has attracted my attention is that execution from the script in
the slow runs take 8+ seconds, sometimes even 14 seconds when in the
normal cases it takes less than a second. So I am thinking whether
this is a more general problem of DB load for one reason or another at
those times.
Has anyone of you experienced similar slowdowns? Any hints, ideas
will be appreciated.
TIA,
George
Let me correct that last paragraph so it makes sense :).
What has attracted my attention is that execution from the script and
into the first line of execution of the SPL procedure during the slow
runs take 8+ seconds, sometimes even 14 seconds while in the normal
cases it takes less than a second. So I am thinking whether this is a
more general problem of DB load for one reason or another at those
times.
George
On Thu, Dec 17, 2009 at 7:52 AM, George Karabotsos <karabot@gmail.com> wrote:
> Hello all,
>
> I have been spending a bit of time investigating a problem I have with
> a couple of my SPL procedures. To give you some background. I have
> two SPLs that are invoked through a Perl script every 10 min. Three
> to seven times every 24 hour period (at seemingly random times) these
> procedures run slowly, some times they take a few minutes to complete,
> when all the other times it takes 10 seconds or less. I went into a
> search to find out whether exclusive locks exist the cause the
> slowdown--I was not able to find much and I was able to see that all
> our DB work is started with
> SET ISOLATION TO DIRTY READ;
> SET LOCK MODE TO WAIT 5;> which seems reasonable.
>
> What has attracted my attention is that execution from the script in
> the slow runs take 8+ seconds, sometimes even 14 seconds when in the
> normal cases it takes less than a second. So I am thinking whether
> this is a more general problem of DB load for one reason or another at
> those times.
>
> Has anyone of you experienced similar slowdowns? Any hints, ideas
> will be appreciated.
>
> TIA,
> George
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
PLEASE PLEASE PLEASE ALWAYS post your IDS version and platform information
when you post!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
There's not much to go on here. It could be something as common but
esoteric as the Btree Cleaners/Scanners (depending on IDS version - SEE WHY
YOU HAVE TO POST VERSION INFO?) waking up with lots of work to do, or under
or inefficiently configured or it could be as simple as there's a batch job
that's completely unrelated to the database but it shares IO resources
(disks, controllers, channels, low level SAN cache) with the IDS instance,
or your IDS chunks are COOKED and such system load is sharing the system
buffer cache. It could be as weird as your release of IDS has some old bug
that we know about, but without version info we couldn't say. Could be that
another periodic large database task is flushing the data that this
procedure needs out of the cache sometimes but other times the Perl script
you are concerned about runs before the batch job. Or perhaps the script
NEEDS the data that some other batch process loads into the cache and
sometimes its not there. It could be lots of things.
Art
Art S. Kagel
Oninit (www.oninit.com)
IIUG Board of Directors (art@iiug.org)
See you at the 2010 IIUG Informix Conference
April 25-28, 2010
Overland Park (Kansas City), KS
www.iiug.org/conf
Disclaimer: Please keep in mind that my own opinions are my own opinions and
do not reflect on my employer, Oninit, the IIUG, nor any other organization
with which I am associated either explicitly or implicitly. 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, Dec 17, 2009 at 10:52 AM, George Karabotsos <karabot@gmail.com>wrote:
> Hello all,
>
> I have been spending a bit of time investigating a problem I have with
> a couple of my SPL procedures. To give you some background. I have
> two SPLs that are invoked through a Perl script every 10 min. Three
> to seven times every 24 hour period (at seemingly random times) these
> procedures run slowly, some times they take a few minutes to complete,
> when all the other times it takes 10 seconds or less. I went into a
> search to find out whether exclusive locks exist the cause the
> slowdown--I was not able to find much and I was able to see that all
> our DB work is started with
> SET ISOLATION TO DIRTY READ;
> SET LOCK MODE TO WAIT 5;> which seems reasonable.
>
> What has attracted my attention is that execution from the script in
> the slow runs take 8+ seconds, sometimes even 14 seconds when in the
> normal cases it takes less than a second. So I am thinking whether
> this is a more general problem of DB load for one reason or another at
> those times.
>
> Has anyone of you experienced similar slowdowns? Any hints, ideas
> will be appreciated.
>
> TIA,
> George
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--0023545bd494ca357a047aeec0ee
My apologies for the ommission :).
DB version: IDS 11.5
System info:
$ uname -a
Linux xxxx 2.6.9-42.ELlargesmp #1 SMP Wed Jul 12 23:46:39 EDT 2006
x86_64 x86_64 x86_64 GNU/Linux
George
On Thu, Dec 17, 2009 at 8:02 AM, Art Kagel <art.kagel@gmail.com> wrote:
> PLEASE PLEASE PLEASE ALWAYS post your IDS version and platform information
> when you post!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
>
> There's not much to go on here. It could be something as common but
> esoteric as the Btree Cleaners/Scanners (depending on IDS version - SEE WHY
> YOU HAVE TO POST VERSION INFO?) waking up with lots of work to do, or under
> or inefficiently configured or it could be as simple as there's a batch job
> that's completely unrelated to the database but it shares IO resources
> (disks, controllers, channels, low level SAN cache) with the IDS instance,
> or your IDS chunks are COOKED and such system load is sharing the system
> buffer cache. It could be as weird as your release of IDS has some old bug
> that we know about, but without version info we couldn't say. Could be that
> another periodic large database task is flushing the data that this
> procedure needs out of the cache sometimes but other times the Perl script
> you are concerned about runs before the batch job. Or perhaps the script
> NEEDS the data that some other batch process loads into the cache and
> sometimes its not there. It could be lots of things.
>
> Art
>
> Art S. Kagel
> Oninit (www.oninit.com)
> IIUG Board of Directors (art@iiug.org)
>
> See you at the 2010 IIUG Informix Conference
> April 25-28, 2010
> Overland Park (Kansas City), KS
> www.iiug.org/conf
>
> Disclaimer: Please keep in mind that my own opinions are my own opinions and
> do not reflect on my employer, Oninit, the IIUG, nor any other organization
> with which I am associated either explicitly or implicitly. 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, Dec 17, 2009 at 10:52 AM, George Karabotsos <karabot@gmail.com>wrote:
>
>> Hello all,
>>
>> I have been spending a bit of time investigating a problem I have with
>> a couple of my SPL procedures. To give you some background. I have
>> two SPLs that are invoked through a Perl script every 10 min. Three
>> to seven times every 24 hour period (at seemingly random times) these
>> procedures run slowly, some times they take a few minutes to complete,
>> when all the other times it takes 10 seconds or less. I went into a
>> search to find out whether exclusive locks exist the cause the
>> slowdown--I was not able to find much and I was able to see that all
>> our DB work is started with
>> SET ISOLATION TO DIRTY READ;
>> SET LOCK MODE TO WAIT 5;>> which seems reasonable.
>>
>> What has attracted my attention is that execution from the script in
>> the slow runs take 8+ seconds, sometimes even 14 seconds when in the
>> normal cases it takes less than a second. So I am thinking whether
>> this is a more general problem of DB load for one reason or another at
>> those times.
>>
>> Has anyone of you experienced similar slowdowns? Any hints, ideas
>> will be appreciated.
>>
>> TIA,
>> George
>>
>>
>>
>>
>
*******************************************************************************
>> Forum Note: Use "Reply" to post a response in the discussion forum.
>>
>>
>
> --0023545bd494ca357a047aeec0ee
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
You're talking about the time it takes to connect to the server? the time
it takes after connecting to execute the procedure?
Either could be several things also, some are again version dependent.
Here's one: if it is the time after connection to execute the procedure,
then it may have to do with running update statistics. If you update
statistics before a run of that SPL routine and do not recompile the routine
first, then it must auto-recompile itself the first time it is run after the
update statistics run. Prior to 11.10 this would usually return a -710error or another error indicating that the sysprocplan table was locked for
that first execution, even though it was auto-recompiling, from 11.10 on the
recompile succeeds silently and the procedure runs afterward. If this is
what's happening, then you have to modify your update statistics runs to
recompile every SPL routine (by running update statistics against the
procedure) after it is finished updating the tables' stats.
You can use my dostats utility which takes care of this detail for you
automatically as well as updating stats to the recommended levels and
providing lots of scheduling features not available elsewhere currently.
Dostats is part of the package utils2_ak which you can download for free
from the NEW Oninit Web site (www.oninit.com/utils) or from the IIUG
Software Repository (www.iiug.org/software).
Art
Art S. Kagel
Oninit (www.oninit.com)
IIUG Board of Directors (art@iiug.org)
See you at the 2010 IIUG Informix Conference
April 25-28, 2010
Overland Park (Kansas City), KS
www.iiug.org/conf
Disclaimer: Please keep in mind that my own opinions are my own opinions and
do not reflect on my employer, Oninit, the IIUG, nor any other organization
with which I am associated either explicitly or implicitly. 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, Dec 17, 2009 at 10:56 AM, George Karabotsos <karabot@gmail.com>wrote:
> Let me correct that last paragraph so it makes sense :).
>
> What has attracted my attention is that execution from the script and
> into the first line of execution of the SPL procedure during the slow
> runs take 8+ seconds, sometimes even 14 seconds while in the normal
> cases it takes less than a second. So I am thinking whether this is a
> more general problem of DB load for one reason or another at those
> times.
>
> George
>
> On Thu, Dec 17, 2009 at 7:52 AM, George Karabotsos <karabot@gmail.com>
> wrote:
> > Hello all,
> >
> > I have been spending a bit of time investigating a problem I have with
> > a couple of my SPL procedures. To give you some background. I have
> > two SPLs that are invoked through a Perl script every 10 min. Three
> > to seven times every 24 hour period (at seemingly random times) these
> > procedures run slowly, some times they take a few minutes to complete,
> > when all the other times it takes 10 seconds or less. I went into a
> > search to find out whether exclusive locks exist the cause the
> > slowdown--I was not able to find much and I was able to see that all
> > our DB work is started with
> > SET ISOLATION TO DIRTY READ;
> > SET LOCK MODE TO WAIT 5;> > which seems reasonable.
> >
> > What has attracted my attention is that execution from the script in
> > the slow runs take 8+ seconds, sometimes even 14 seconds when in the
> > normal cases it takes less than a second. So I am thinking whether
> > this is a more general problem of DB load for one reason or another at
> > those times.
> >
> > Has anyone of you experienced similar slowdowns? Any hints, ideas
> > will be appreciated.
> >
> > TIA,
> > George
> >
> >
> >
>
>
*******************************************************************************
> > Forum Note: Use "Reply" to post a response in the discussion forum.
> >
> >
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--00151747bfe2f9c5dd047aeee06d
Thank you very much Art for taking the time to answer my post! Next
off my apologies for my noobness :).
I believe this is the version you were looking for
iif.11.50.UC5DE.Linux-RHEL4 (thank you David).
> You're talking about the time it takes to connect to the server? the time
> it takes after connecting to execute the procedure?
>
I am talking about the time the perl script is invoked until I obtain
a DB connection and the first statement is executed in the SPL (which
happens to be an insert, hence I know its timestamp).
George
On Thu, Dec 17, 2009 at 8:11 AM, Art Kagel <art.kagel@gmail.com> wrote:
> You're talking about the time it takes to connect to the server? the time
> it takes after connecting to execute the procedure?
>
> Either could be several things also, some are again version dependent.
> Here's one: if it is the time after connection to execute the procedure,
> then it may have to do with running update statistics. If you update
> statistics before a run of that SPL routine and do not recompile the routine
> first, then it must auto-recompile itself the first time it is run after the
> update statistics run. Prior to 11.10 this would usually return a -710> error or another error indicating that the sysprocplan table was locked for
> that first execution, even though it was auto-recompiling, from 11.10 on the
> recompile succeeds silently and the procedure runs afterward. If this is
> what's happening, then you have to modify your update statistics runs to
> recompile every SPL routine (by running update statistics against the
> procedure) after it is finished updating the tables' stats.
>
> You can use my dostats utility which takes care of this detail for you
> automatically as well as updating stats to the recommended levels and
> providing lots of scheduling features not available elsewhere currently.
> Dostats is part of the package utils2_ak which you can download for free
> from the NEW Oninit Web site (www.oninit.com/utils) or from the IIUG
> Software Repository (www.iiug.org/software).
>
> Art
>
> Art S. Kagel
> Oninit (www.oninit.com)
> IIUG Board of Directors (art@iiug.org)
>
> See you at the 2010 IIUG Informix Conference
> April 25-28, 2010
> Overland Park (Kansas City), KS
> www.iiug.org/conf
>
> Disclaimer: Please keep in mind that my own opinions are my own opinions and
> do not reflect on my employer, Oninit, the IIUG, nor any other organization
> with which I am associated either explicitly or implicitly. 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, Dec 17, 2009 at 10:56 AM, George Karabotsos <karabot@gmail.com>wrote:
>
>> Let me correct that last paragraph so it makes sense :).
>>
>> What has attracted my attention is that execution from the script and
>> into the first line of execution of the SPL procedure during the slow
>> runs take 8+ seconds, sometimes even 14 seconds while in the normal
>> cases it takes less than a second. So I am thinking whether this is a
>> more general problem of DB load for one reason or another at those
>> times.
>>
>> George
>>
>> On Thu, Dec 17, 2009 at 7:52 AM, George Karabotsos <karabot@gmail.com>
>> wrote:
>> > Hello all,
>> >
>> > I have been spending a bit of time investigating a problem I have with
>> > a couple of my SPL procedures. To give you some background. I have
>> > two SPLs that are invoked through a Perl script every 10 min. Three
>> > to seven times every 24 hour period (at seemingly random times) these
>> > procedures run slowly, some times they take a few minutes to complete,
>> > when all the other times it takes 10 seconds or less. I went into a
>> > search to find out whether exclusive locks exist the cause the
>> > slowdown--I was not able to find much and I was able to see that all
>> > our DB work is started with
>> > SET ISOLATION TO DIRTY READ;
>> > SET LOCK MODE TO WAIT 5;>> > which seems reasonable.
>> >
>> > What has attracted my attention is that execution from the script in
>> > the slow runs take 8+ seconds, sometimes even 14 seconds when in the
>> > normal cases it takes less than a second. So I am thinking whether
>> > this is a more general problem of DB load for one reason or another at
>> > those times.
>> >
>> > Has anyone of you experienced similar slowdowns? Any hints, ideas
>> > will be appreciated.
>> >
>> > TIA,
>> > George
>> >
>> >
>> >
>>
>>
>
*******************************************************************************
>> > Forum Note: Use "Reply" to post a response in the discussion forum.
>> >
>> >
>>
>>
>>
>>
>
*******************************************************************************
>> Forum Note: Use "Reply" to post a response in the discussion forum.
>>
>>
>
> --00151747bfe2f9c5dd047aeee06d
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
Post your ONCONFIG file contents (or the output from onstat -c) and the
following output and we'll try to help:
onstat -p
onstat -g glo
onstat -u (just the tail end)
onstat -P (tail end)
onstat -C
Art
Art S. Kagel
Oninit (www.oninit.com)
IIUG Board of Directors (art@iiug.org)
See you at the 2010 IIUG Informix Conference
April 25-28, 2010
Overland Park (Kansas City), KS
www.iiug.org/conf
Disclaimer: Please keep in mind that my own opinions are my own opinions and
do not reflect on my employer, Oninit, the IIUG, nor any other organization
with which I am associated either explicitly or implicitly. 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, Dec 17, 2009 at 11:30 AM, George Karabotsos <karabot@gmail.com>wrote:
> Thank you very much Art for taking the time to answer my post! Next
> off my apologies for my noobness :).
>
> I believe this is the version you were looking for
> iif.11.50.UC5DE.Linux-RHEL4 (thank you David).
>
> > You're talking about the time it takes to connect to the server? the time
> > it takes after connecting to execute the procedure?
> >
> I am talking about the time the perl script is invoked until I obtain
> a DB connection and the first statement is executed in the SPL (which
> happens to be an insert, hence I know its timestamp).
>
> George
>
> On Thu, Dec 17, 2009 at 8:11 AM, Art Kagel <art.kagel@gmail.com> wrote:
> > You're talking about the time it takes to connect to the server? the time
> > it takes after connecting to execute the procedure?
> >
> > Either could be several things also, some are again version dependent.
> > Here's one: if it is the time after connection to execute the procedure,
> > then it may have to do with running update statistics. If you update
> > statistics before a run of that SPL routine and do not recompile the
> routine
> > first, then it must auto-recompile itself the first time it is run after
> the
> > update statistics run. Prior to 11.10 this would usually return a -710> > error or another error indicating that the sysprocplan table was locked
> for
> > that first execution, even though it was auto-recompiling, from 11.10 on
> the
> > recompile succeeds silently and the procedure runs afterward. If this is
> > what's happening, then you have to modify your update statistics runs to
> > recompile every SPL routine (by running update statistics against the
> > procedure) after it is finished updating the tables' stats.
> >
> > You can use my dostats utility which takes care of this detail for you
> > automatically as well as updating stats to the recommended levels and
> > providing lots of scheduling features not available elsewhere currently.
> > Dostats is part of the package utils2_ak which you can download for free
> > from the NEW Oninit Web site (www.oninit.com/utils) or from the IIUG
> > Software Repository (www.iiug.org/software).
> >
> > Art
> >
> > Art S. Kagel
> > Oninit (www.oninit.com)
> > IIUG Board of Directors (art@iiug.org)
> >
> > See you at the 2010 IIUG Informix Conference
> > April 25-28, 2010
> > Overland Park (Kansas City), KS
> > www.iiug.org/conf
> >
> > Disclaimer: Please keep in mind that my own opinions are my own opinions
> and
> > do not reflect on my employer, Oninit, the IIUG, nor any other
> organization
> > with which I am associated either explicitly or implicitly. 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, Dec 17, 2009 at 10:56 AM, George Karabotsos
> <karabot@gmail.com>wrote:
> >
> >> Let me correct that last paragraph so it makes sense :).
> >>
> >> What has attracted my attention is that execution from the script and
> >> into the first line of execution of the SPL procedure during the slow
> >> runs take 8+ seconds, sometimes even 14 seconds while in the normal
> >> cases it takes less than a second. So I am thinking whether this is a
> >> more general problem of DB load for one reason or another at those
> >> times.
> >>
> >> George
> >>
> >> On Thu, Dec 17, 2009 at 7:52 AM, George Karabotsos <karabot@gmail.com>
> >> wrote:
> >> > Hello all,
> >> >
> >> > I have been spending a bit of time investigating a problem I have with
> >> > a couple of my SPL procedures. To give you some background. I have
> >> > two SPLs that are invoked through a Perl script every 10 min. Three
> >> > to seven times every 24 hour period (at seemingly random times) these
> >> > procedures run slowly, some times they take a few minutes to complete,
> >> > when all the other times it takes 10 seconds or less. I went into a
> >> > search to find out whether exclusive locks exist the cause the
> >> > slowdown--I was not able to find much and I was able to see that all
> >> > our DB work is started with
> >> > SET ISOLATION TO DIRTY READ;
> >> > SET LOCK MODE TO WAIT 5;> >> > which seems reasonable.
> >> >
> >> > What has attracted my attention is that execution from the script in
> >> > the slow runs take 8+ seconds, sometimes even 14 seconds when in the
> >> > normal cases it takes less than a second. So I am thinking whether
> >> > this is a more general problem of DB load for one reason or another at
> >> > those times.
> >> >
> >> > Has anyone of you experienced similar slowdowns? Any hints, ideas
> >> > will be appreciated.
> >> >
> >> > TIA,
> >> > George
> >> >
> >> >
> >> >
> >>
> >>
> >
>
>
*******************************************************************************
> >> > Forum Note: Use "Reply" to post a response in the discussion forum.
> >> >
> >> >
> >>
> >>
> >>
> >>
> >
>
>
*******************************************************************************
> >> Forum Note: Use "Reply" to post a response in the discussion forum.
> >>
> >>
> >
> > --00151747bfe2f9c5dd047aeee06d
> >
> >
> >
>
>
*******************************************************************************
> > Forum Note: Use "Reply" to post a response in the discussion forum.
> >
> >
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--0015174792d62b504f047aeffd86