Re: Execution variability

Hi all.
I understand this can be a ridiculous question for most you.

The very same query on the very same db shows very variable timings.
I'm the only one client on an unpupolated server so I'd expect a
rather constant timing.

INstead for a while the query become very slooow and the CPU reached
60 to 70% and the time needed is about 1.5 minutes0.
Again with just me on it.
Normally the same query rises the usage to a mere 5% to 7% with timing
with the tenth of a second.

I have disable both the autovacuum and the "stats_start_collector" in
the
attempt to disable possibe reasons for slow down. No luck in this.

Do you have any hint?

--
Vincenzo Romano
--
Maybe Computer will never become as intelligent as Humans.
For sure they won't ever become so stupid. [VR-1988]

On Wednesday 27 June 2007 23:46:25 Vincenzo Romano wrote:
> Hi all.
> I understand this can be a ridiculous question for most you.
>
> The very same query on the very same db shows very variable
> timings. I'm the only one client on an unpupolated server so I'd
> expect a rather constant timing.
>
> INstead for a while the query become very slooow and the CPU
> reached 60 to 70% and the time needed is about 1.5 minutes0.
> Again with just me on it.
> Normally the same query rises the usage to a mere 5% to 7% with
> timing with the tenth of a second.
>
> I have disable both the autovacuum and the "stats_start_collector"
> in the
> attempt to disable possibe reasons for slow down. No luck in this.
>
> Do you have any hint?

What's really weird is that after some time the timings get back to
normal. With no explicit action. Then, later, timings get worse again.

I fear it can be a "DBA problem" but but still have no clue.

--
Vincenzo Romano
--
Maybe Computer will never become as intelligent as Humans.
For sure they won't ever become so stupid. [VR-1988]

Vincenzo Romano wrote:
> On Wednesday 27 June 2007 23:46:25 Vincenzo Romano wrote:
>> Hi all.
>> I understand this can be a ridiculous question for most you.
>>
>> The very same query on the very same db shows very variable
>> timings. I'm the only one client on an unpupolated server so I'd
>> expect a rather constant timing.

> What's really weird is that after some time the timings get back to
> normal. With no explicit action. Then, later, timings get worse again.
>
> I fear it can be a "DBA problem" but but still have no clue.

So what's the computer doing? If it is the "very same" query on the
"very same" data then something else must be happening in the
background. Check the output of top/vmstat (or Windows equivalents) when
this happens and see if there's a clue.

--
Richard Huxton
Archonet Ltd

On Thursday 28 June 2007 12:00:40 Richard Huxton wrote:
> Vincenzo Romano wrote:
> > On Wednesday 27 June 2007 23:46:25 Vincenzo Romano wrote:
> >> Hi all.
> >> I understand this can be a ridiculous question for most you.
> >>
> >> The very same query on the very same db shows very variable
> >> timings. I'm the only one client on an unpupolated server so I'd
> >> expect a rather constant timing.
> >
> > What's really weird is that after some time the timings get back
> > to normal. With no explicit action. Then, later, timings get
> > worse again.
> >
> > I fear it can be a "DBA problem" but but still have no clue.
>
> So what's the computer doing? If it is the "very same" query on the
> "very same" data then something else must be happening in the
> background. Check the output of top/vmstat (or Windows equivalents)
> when this happens and see if there's a clue.

From the "top" command (I'm running Linux) the only process that jumps
high with the load is just the postrgres instance managing the SQL
connection.
I agree about "something else must be happening in the background".
All rthe available RAM gets used as well as some swap.
During "fast" operations the used RAM remains low and no swap
happens.
I would exclude any other "system" process.

How can I log what the PGSQL is actually doing?

--
Vincenzo Romano
--
Maybe Computer will never become as intelligent as Humans.
For sure they won't ever become so stupid. [VR-1988]

Vincenzo Romano wrote:
>>>> The very same query on the very same db shows very variable
>>>> timings. I'm the only one client on an unpupolated server so I'd
>>>> expect a rather constant timing.
>>> What's really weird is that after some time the timings get back
>>> to normal. With no explicit action. Then, later, timings get
>>> worse again.

> From the "top" command (I'm running Linux) the only process that jumps
> high with the load is just the postrgres instance managing the SQL
> connection.
> I agree about "something else must be happening in the background".
> All rthe available RAM gets used as well as some swap.
> During "fast" operations the used RAM remains low and no swap
> happens.

That suggests it's not the "same query" that's causing problems. If
you're going into swap then performance will vary wildly. You may have
allocated more memory to PostgreSQL than is available on the machine.

> I would exclude any other "system" process.
>
> How can I log what the PGSQL is actually doing?

See the "when to log" and "what to log" parts of this:
http://www.postgresql.org/docs/8.2/static/runtime-config.html

As postgres (or other superuser) you can do:
ALTER DATABASE <db> SET log_min_duration_statement = 1000;
That will log all statements that take longer than 1 second.

Alternatively log_statement = 'all' will show all queries executed.

You probably want to read the section on "Resource Consumption" linked
above too. In particular work_mem is *per sort*, which means one query
can use several times the amount set.

If you post the values for the settings listed in chapter 17.4.1 of the
manuals and a description of what your machine is like, what else it is
doing then we might be able to suggest some changes.

--
Richard Huxton
Archonet Ltd

Hi.

The test system has 1GB Ram.
The main table has 20+ million rows.
All the other ones account for less than 10K rows.

The values are here below. I suppose that the "hashed"
ones imply a default value.

shared_buffers = 24MB
#temp_buffers = 8MB
#max_prepared_transactions = 5
work_mem = 16MB
#maintenance_work_mem = 16MB
#max_stack_depth = 2MB
max_fsm_pages = 153600
#max_fsm_relations = 1000
max_files_per_process = 1000
#shared_preload_libraries = ''

By the way, it seems that the problem arises with only one query,
while the other ones behave almost the same all the time.

I thank you very much for your attention and help.

On Thursday 28 June 2007 13:17:54 Richard Huxton wrote:
> Vincenzo Romano wrote:
> >>>> The very same query on the very same db shows very variable
> >>>> timings. I'm the only one client on an unpupolated server so
> >>>> I'd expect a rather constant timing.
> >>>
> >>> What's really weird is that after some time the timings get
> >>> back to normal. With no explicit action. Then, later, timings
> >>> get worse again.
> >
> > From the "top" command (I'm running Linux) the only process that
> > jumps high with the load is just the postrgres instance managing
> > the SQL connection.
> > I agree about "something else must be happening in the
> > background". All rthe available RAM gets used as well as some
> > swap.
> > During "fast" operations the used RAM remains low and no swap
> > happens.
>
> That suggests it's not the "same query" that's causing problems. If
> you're going into swap then performance will vary wildly. You may
> have allocated more memory to PostgreSQL than is available on the
> machine.
>
> > I would exclude any other "system" process.
> >
> > How can I log what the PGSQL is actually doing?
>
> See the "when to log" and "what to log" parts of this:
> http://www.postgresql.org/docs/8.2/static/runtime-config.html
>
> As postgres (or other superuser) you can do:
> ALTER DATABASE <db> SET log_min_duration_statement = 1000;
> That will log all statements that take longer than 1 second.
>
> Alternatively log_statement = 'all' will show all queries executed.
>
> You probably want to read the section on "Resource Consumption"
> linked above too. In particular work_mem is *per sort*, which means
> one query can use several times the amount set.
>
> If you post the values for the settings listed in chapter 17.4.1 of
> the manuals and a description of what your machine is like, what
> else it is doing then we might be able to suggest some changes.

--
Vincenzo Romano
--
Maybe Computer will never become as intelligent as Humans.
For sure they won't ever become so stupid. [VR-1988]

Vincenzo Romano escribió:

> The values are here below. I suppose that the "hashed"
> ones imply a default value.

Correct (widely known as "commented out")

> By the way, it seems that the problem arises with only one query,
> while the other ones behave almost the same all the time.

Let's see the EXPLAIN ANALYZE. Does it involve the big table?

--
Alvaro Herrera Valdivia, Chile ICBM: S 39º 49' 18.1", W 73º 13' 56.4"
"There is evil in the world. There are dark, awful things. Occasionally, we get
a glimpse of them. But there are dark corners; horrors almost impossible to
imagine... even in our worst nightmares." (Van Helsing, Dracula A.D. 1972)

On Thursday 28 June 2007 16:08:06 Alvaro Herrera wrote:
> Vincenzo Romano escribió:
> > The values are here below. I suppose that the "hashed"
> > ones imply a default value.
>
> Correct (widely known as "commented out")
>
> > By the way, it seems that the problem arises with only one query,
> > while the other ones behave almost the same all the time.
>
> Let's see the EXPLAIN ANALYZE. Does it involve the big table?

I need to check.
The "bad guy" is a function and I have to get the body out in order to
make the PG explain it.

--
Vincenzo Romano
--
Maybe Computer will never become as intelligent as Humans.
For sure they won't ever become so stupid. [VR-1988]