Thread: simple update queries take a long time - postgres 8.3.1

is the query I am running , and it takes over 10 seconds to complete this query...


update users set number_recieved=number_recieved+1 where uid=738889333;

table has about 1.7 million rows.. i have an index on column uid and also on number_received. .. this is also slowing down the inserts that happen.
how to fix this?


i have totally 6 different database of similar size in the same machine..j
The hardware is dual quad core intel xeon5405 , and 32GB RAM, and following settings changed..
max_connections = 2000                  # (change requires restart)
shared_buffers = 4000MB                 # min 128kB or max_connections*16kB
effective_cache_size = 12000MB    



CREATE INDEX idx_uid
  ON users
  USING btree
  (uid);

CREATE INDEX number_rx
  ON users
  USING btree
  (number_recieved);



table

CREATE TABLE users
(
  id serial NOT NULL,
  username text,
  first_name text,
  last_name text,
  email text,
  "password" text,
  last_login timestamp without time zone,
  profilepic text,
  ip text,
  dob timestamp without time zone,
  created timestamp without time zone DEFAULT now(),
  rawpassword character varying(128),
  rating real DEFAULT 0,
  zip text,
  hash text,
  gender character(1),
  groups text,
  aim text,
  yahoo text,
  skype text,
  hotmail text,
  vanity text,
  number_comments integer DEFAULT 0,
  number_friends integer DEFAULT 0,
  number_posts integer DEFAULT 0,
  number_polls integer DEFAULT 0,
  city text,
  site text,
  number_pictures bigint DEFAULT 0,
  email_subscribe boolean DEFAULT true,
  number_userpics integer DEFAULT 0,
  htmlcodes text,
  pageviews integer DEFAULT 1,
  number_uservideos integer DEFAULT 0,
  number_useraudios integer DEFAULT 0,
  number_usermessages integer DEFAULT 0,
  number_usermessages_sent integer DEFAULT 0,
  myrand double precision NOT NULL DEFAULT random(),
  number_activities integer DEFAULT 0,
  number_pages integer DEFAULT 0,
  uid integer NOT NULL,
  number_invites integer DEFAULT 0,
  number_notifications integer DEFAULT 0,
  number_emailnotifications integer DEFAULT 0,
  number_pendingnotifications integer DEFAULT 0,
  total_number_invites integer DEFAULT 0,
  total_number_emailnotifications integer DEFAULT 0,
  last_invitation timestamp without time zone,
  last_emailnotification timestamp without time zone,
  session_key text,
  last_profilefbml timestamp without time zone,
  "name" text,
  number_sent integer DEFAULT 0,
  number_recieved integer DEFAULT 0,
  score integer DEFAULT 0,
  number_votes integer DEFAULT 0,
  CONSTRAINT users_pkey PRIMARY KEY (id),
  CONSTRAINT unique_uid UNIQUE (uid),
  CONSTRAINT uniquemail UNIQUE (email),
  CONSTRAINT uniquuser UNIQUE (username)
)
WITH (OIDS=FALSE);
ALTER TABLE users OWNER TO postgres;

On 31/03/2008 20:16, mark wrote:
> is the query I am running , and it takes over 10 seconds to complete
> this query...
>
>
> update users set number_recieved=number_recieved+1 where uid=738889333;
>
> table has about 1.7 million rows.. i have an index on column uid and
> also on number_received. .. this is also slowing down the inserts that
> happen.

Are you VACUUMing the table regularly?

Also, can you show us the EXPLAIN ANALYZE output from the query?

Ray.


---------------------------------------------------------------
Raymond O'Donnell, Director of Music, Galway Cathedral, Ireland
rod@iol.ie
---------------------------------------------------------------

EXPLAIN ANALYZE update users set number_recieved=number_recieved+1 where uid=738889333;
                                                    QUERY PLAN
------------------------------------------------------------------------------------------------------------------
 Index Scan using idx_uid on users  (cost=0.00..8.46 rows=1 width=1073) (actual time=0.094..0.161 rows=1 loops=1)
   Index Cond: (uid = 738889333)
 Total runtime: 11479.053 ms
(3 rows)

On 31/03/2008 20:38, mark wrote:

> EXPLAIN ANALYZE update users set number_recieved=number_recieved+1 where
> uid=738889333;
>                                                     QUERY PLAN
> ------------------------------------------------------------------------------------------------------------------
>  Index Scan using idx_uid on users  (cost=0.00..8.46 rows=1 width=1073)
> (actual time=0.094..0.161 rows=1 loops=1)
>    Index Cond: (uid = 738889333)
>  Total runtime: 11479.053 ms

Is there anything going on that might affect the time taken? - triggers,
loads of indices to be updated, etc? From the docs[1]:

"For INSERT, UPDATE, and DELETE commands, the total run time might be
considerably larger, because it includes the time spent processing the
result rows. In these commands, the time for the top plan node
essentially is the time spent computing the new rows and/or locating the
old ones, but it doesn't include the time spent applying the changes.
Time spent firing triggers, if any, is also outside the top plan node,
and is shown separately for each trigger."

Ray.

[1] http://www.postgresql.org/docs/8.3/static/using-explain.html

---------------------------------------------------------------
Raymond O'Donnell, Director of Music, Galway Cathedral, Ireland
rod@iol.ie
---------------------------------------------------------------

On 31/03/2008 20:38, mark wrote:

> I dont manually do vaccum..

It might be worth doing one and seeing if it makes a difference.

Ray.

---------------------------------------------------------------
Raymond O'Donnell, Director of Music, Galway Cathedral, Ireland
rod@iol.ie
---------------------------------------------------------------

On Mon, Mar 31, 2008 at 12:48 PM, Raymond O'Donnell <rod@iol.ie> wrote:
(cost=0.00..8.46 rows=1 width=1073)  (actual time=0.094..0.161 rows=1 loops=1)
thanks

On 31/03/2008 20:51, mark wrote:

> can you explain what the numbers mean in the EXPLAIN ANALYZE?
> (cost=0.00..8.46 rows=1 width=1073)  (actual time=0.094..0.161 rows=1
> loops=1)

It's worth reading through the docs at that reference in my previous
email - it's well explained there.

As I understand it, "cost" signifies the planner's estimate of how long
the query will take, in terms of disk page fetches. The "actual time" is
in milliseconds.

Ray.

---------------------------------------------------------------
Raymond O'Donnell, Director of Music, Galway Cathedral, Ireland
rod@iol.ie
---------------------------------------------------------------

On Mon, Mar 31, 2008 at 12:59 PM, Raymond O'Donnell <rod@iol.ie> wrote:

the IO wait is most of the times 10-30%

top - 13:02:35 up 33 days,  4:05,  3 users,  load average: 2.65, 2.82, 2.61
Tasks: 1040 total,   1 running, 1039 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.7%us,  0.6%sy,  0.0%ni, 85.3%id, 13.2%wa,  0.0%hi,  0.0%si,  0.0%st

>  Index Scan using idx_uid on users  (cost=0.00..8.46 rows=1 width=1073)
> (actual time=0.094..0.161 rows=1 loops=1)
>    Index Cond: (uid = 738889333)
>  Total runtime: 11479.053 ms

On 31/03/2008 21:11, mark wrote:

> it says actual time is 0.161 seconds or milliseconds.. but the total run
> time is 11 seconds.. any ideas why this discrepancy?

Well, I interpret the docs as implying that the difference between the
time quoted in the top line of EXPLAIN ANALYZE's output and the time in
"Total runtime" if effectively the time taken to apply the update.
Beyond that, I'm guessing.....

Ray.

---------------------------------------------------------------
Raymond O'Donnell, Director of Music, Galway Cathedral, Ireland
rod@iol.ie
---------------------------------------------------------------

I am developing an application where I will have a default table and/or
view for a select statement for my application.  If a client has a special
requirement I would like to have a alternate table of the same name in a
different schema with the change structure.

Schema A
   Default table - coretable.foo

Schema B
   Client specific table client.foo

How can I check if a table or alternate view exists in schema B.

ie

if client.foo exists // check for a view or table
  // my code will use client.foo table
else
  // my code will use coretable.foo
endif

Also is it possible to check via function/via in postgress and not have to
rely on my application to do the check.  If so how.

Em Monday 31 March 2008 22:35:01 Jeff Williams escreveu:
> I am developing an application where I will have a default table and/or
> view for a select statement for my application.  If a client has a special
> requirement I would like to have a alternate table of the same name in a
> different schema with the change structure.
>
> Schema A
>    Default table - coretable.foo
>
> Schema B
>    Client specific table client.foo
>
> How can I check if a table or alternate view exists in schema B.
>
> ie
>
> if client.foo exists // check for a view or table
>   // my code will use client.foo table
> else
>   // my code will use coretable.foo
> endif
>
> Also is it possible to check via function/via in postgress and not have to
> rely on my application to do the check.  If so how.

I'd give both the same name and make the client schema first in the search
path.  Then, you should just call the function and it would follow the search
path order and give you what you want without having to check anything.

--
Jorge Godoy      <jgodoy@gmail.com>

On 2008-03-31 21:16, mark wrote:

> is the query I am running , and it takes over 10 seconds to complete
> this query...
> update users set number_recieved=number_recieved+1 where
> uid=738889333;

Every time or only sometimes?

If it is sometimes then I think this query is waiting for a checkpoint.
If I'm right then you'll have to tune Postgres to do them more often, so
that there is less work to do each time. You use 4GB of shared buffers
so write-busy database can write gigabytes of data on each checkpoint,
which can take seconds.

Upgrade to 8.3 will help as checkpoint writing algorithms were optimized
there for lots of RAM.

Read this for more info and tuning tips:
http://www.westnet.com/~gsmith/content/postgresql/chkp-bgw-83.htm

Regards
Tometzky
--
...although Eating Honey was a very good thing to do, there was a
moment just before you began to eat it which was better than when you
were...
                                                      Winnie the Pooh

On Mon, Mar 31, 2008 at 11:18 PM, Tomasz Ostrowski <tometzky@batory.org.pl> wrote:

On 2008-04-01 09:44, mark wrote:

> I already am running 8.3.1 [ i mentioned in subject].

Missed that, sorry.

I'd first try to set the following on a write-busy 8.3 server to smooth
checkpoint spikes:
    checkpoint_segments = 16
    checkpoint_timeout = 20min
    checkpoint_completion_target = 0.8

I'd also set
    log_checkpoints=on
to get an idea how it behaves.

But I have no experience on anything with more than 1GB of RAM...

Regards
Tometzky
--
...although Eating Honey was a very good thing to do, there was a
moment just before you began to eat it which was better than when you
were...
                                                      Winnie the Pooh

On Tue, Apr 1, 2008 at 1:48 AM, Tomasz Ostrowski <tometzky@batory.org.pl> wrote:

Tomasz Ostrowski <tometzky@batory.org.pl> writes:
> I'd also set
>     log_checkpoints=on
> to get an idea how it behaves.

Yeah, that's really the *first* thing to do.  You need to determine
whether the episodes of slowness are correlated with checkpoints
or not; there's no point fooling with the checkpoint parameters if
not.

Another thing you could try in order to get a handle on what's
happening is to watch the output of "vmstat 1" or a similar tool,
and see if there are spikes in CPU or I/O load when things are
slow.  If not, I'd next look into PG's pg_locks view to see if
queries are getting blocked on locks.

            regards, tom lane

On Tue, Apr 1, 2008 at 7:27 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:

mark <markkicks@gmail.com> writes:
> I set this on,
> log_checkpoints = on

> and started postgres using this command

> pg_ctl -D /mnt/work/database -l /mnt/work/logs/pgsql.log start

> nothing is getting logged in the logfile. should I turn on some other
> settings?

You're probably looking in the wrong logfile.  Depending on what your
log destination settings are, the file mentioned in pg_ctl -l is likely
to see only early-postmaster-startup messages (before it's read the
configuration file and adopted those settings).

            regards, tom lane

On Tue, 1 Apr 2008, mark wrote:

>> current settings all default
>> #checkpoint_segments = 3
>> #checkpoint_timeout = 5min
>> #checkpoint_completion_target = 0.5
>> #checkpoint_warning = 30s
>
> this is what I have on pg_stat_bgwriter ; how much should I increase
> checkpoint_segment & checkpoint_completion_target to? thanks a lot!
>
> postgres=# select * from pg_stat_bgwriter;
> checkpoints_timed | checkpoints_req | buffers_checkpoint | buffers_clean |
>                42 |            1051 |            8035125 |         21954 |
> maxwritten_clean | buffers_backend | buffers_alloc
>               42 |          241519 |      10394696

That means that 96% of the time, you are hitting a checkpoint because of
activity in less than 5 minutes after the previous one.  And 97% of the
dirty buffers written out are being done by the checkpoint process.  Your
system is spending its entire life doing checkpoint work and it's no
wonder response time is slow quite regularly.

Increasing checkpoint_segments uses up more disk space for the WAL files
and increases the amount of time it will take to recover from a crash.
If neither of those two things matter to you, you can easily bump that
parameter up to 100 or more.  I'd suggest starting with an order of
magnitude change and increase from 3 to 30.  You have to restart the
server to make that change stick.  It's impossible to predict how much
that will change your situation, to know if that's enough or you really
need to increase it further.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD

On Tue, Apr 1, 2008 at 5:31 PM, Greg Smith <gsmith@gregsmith.com> wrote:

On 2008-04-02 09:30, mark wrote:

> Based on what Tomasz suggested a day ago, I had changed settings to
>        checkpoint_segments = 16
>        checkpoint_timeout = 20min
>        checkpoint_completion_target = 0.8
> but i still do get statements that take over 2 or 3 seconds to execute
> sometimes... should I increase checkpoint_segments to 30 now?

Go for it. Even 64 (I like round numbers) would not be too much. This
would make 1GB of data in WALs.

> Should I change checkpoint_timeout & checkpoint_completion_target too??

I'd recommend not. Too much and your recovery time would be in hours.
And too big checkpoint_completion_target could make your original
problem even worse.

Regards
Tometzky
--
...although Eating Honey was a very good thing to do, there was a
moment just before you began to eat it which was better than when you
were...
                                                      Winnie the Pooh

On Wed, 2 Apr 2008, mark wrote:

> this really clear! Thannks!!

This is the first time someone new to this has ever said that about
checkpoint tuning, which is quite the victory for all of us who worked
toward the 8.3 functional and monitoring improvements in this area.
Please keep posting the results after each change, this will make a great
example for others to follow.

> Based on what Tomasz suggested a day ago, I had changed settings to
>       checkpoint_segments = 16
>       checkpoint_timeout = 20min
>       checkpoint_completion_target = 0.8
>
> checkpoints_timed | checkpoints_req | buffers_checkpoint | buffers_clean |
>                21 |              46 |            2218439 |         34158 |
>
> maxwritten_clean | buffers_backend | buffers_alloc
>              145 |           60447 |       2707259

That's near the upper limit for checkpoint_completion_target; you could
bump that to 0.9 perhaps but I'd save that until after you get the
segments tuned right.  It's very good that you're now getting a decent
balance of timed checkpoints in here, but as you can see from the
buffers_* numbers the checkpoint activity is still almost all the writes
on your system.

The nice place to be here is to where buffers_checkpoint is similar in
size to buffers_clean+buffers_backend, that's how you know you've spread
the checkpoint out enough that it's not swamping normal operation with its
overhead.

Small tuning bit:  based on the maxwritten_clean figures you're seeing
here I would increase bgwriter_lru_maxpages from the default of 100 to
200.

> i am fine with both WAL disk usage increasing and increase in time to
> recover from crash...

In that case, I'd say stop fooling around and just go to 100 segments or
so based on how much things improved with the jump to 16.  If that makes
things get to where you want, then you can explore dropping down to a
smaller setting one day.  If it doesn't, you may need to consider other
options here.

Increasing to 100 is approximately a 6X increase, so what you'd like to
see is that instead of the current 96% checkpoint writes/4% other you'd
end up with something 76% checkpoint/24% other.  You may need to push to
200 or more segments to get even a true 50/50 balance, but we'll see; the
way this works isn't completely linear.  100 is a pretty big setting for
normal use.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD

On Wed, 2 Apr 2008, Tomasz Ostrowski wrote:

> Even 64 (I like round numbers) would not be too much. This
> would make 1GB of data in WALs.

It's much worse than that.  Assume the system starts a checkpoint after
checkpoint_segments worth of WAL files have been used.  It may take that
long before the checkpoint is finished, which means twice that many will
be active (the old ones that haven't been reconciled yet and the new ones
that have been written while processing the checkpoint).  The formula in
8.2 and earlier versions was that you can expect up to
2*checkpoint_segments+1 worth of them around because of this.  For
checkpoint_segments=64, that makes 129*16MB=2GB.

The situation is more complicated in 8.3 because of how
checkpoint_completion_target is implemented.  There you can expect up to
3*checkpoint_segments + 1 files, worst-case.  To be more exact, the usual
expectation is that you'll have up to (2 + checkpoint_completion_target) *
checkpoint_segments + 1, which as you can see approaches
3*checkpoint_segments for large target values.  This is all covered at
http://www.postgresql.org/docs/8.3/static/wal-configuration.html

The numbers aren't so round here anymore with this change.  I threw out
100 as a suggested setting, which might result in up to 4.8GB of WAL
files.  The recovery time from a crash with this many around will be
painful, but if that's the only way to smooth regular system response
you're stuck with it.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD

On Wed, Apr 2, 2008 at 1:19 AM, Greg Smith <gsmith@gregsmith.com> wrote:

On Wednesday 2. April 2008, Tomasz Ostrowski wrote:

>Go for it. Even 64 (I like round numbers) would not be too much.

Geek test: Do you find the above statement odd?

Yes: 0, No: +10.

(Sorry for being massively off-topic :-))
--
Leif Biberg Kristensen | Registered Linux User #338009
http://solumslekt.org/ | Cruising with Gentoo/KDE
My Jazz Jukebox: http://www.last.fm/user/leifbk/

On Thu, Apr 3, 2008 at 9:18 AM, Leif B. Kristensen <leif@solumslekt.org> wrote:
> On Wednesday 2. April 2008, Tomasz Ostrowski wrote:
>
>  >Go for it. Even 64 (I like round numbers) would not be too much.
>
>  Geek test: Do you find the above statement odd?

Sadly, no.

--
Dave Page
EnterpriseDB UK Ltd: http://www.enterprisedb.com
PostgreSQL UK 2008 Conference: http://www.postgresql.org.uk

Leif B. Kristensen wrote:
> On Wednesday 2. April 2008, Tomasz Ostrowski wrote:
>
>> Go for it. Even 64 (I like round numbers) would not be too much.
>
> Geek test: Do you find the above statement odd?
>
> Yes: 0, No: +10.
>
> (Sorry for being massively off-topic :-))

I had the same thought. ;)

Colin

On Wed, 2 Apr 2008, mark wrote:

> with no clients connected to the database when I try to shutdown the
> database [to apply new settings], it says database cant be shutdown..
> for a long time both in smart and normal mode... then i had to go to
> immediate mode to shut down.. but then when i start it again.. it goes
> into recovery mode and runs for a while..is this the long recover time
> you are talking about?

Exactly; doing an immediate shutdown is one way (probably the safest way
in fact) to force the database into recovery mode when it starts back up
again to see how long a recovery will take.  As you increase
checkpoint_segments, the amount of time it will take to process all the
segments before the database comes up will increase about linearly.
Double checkpoint_segments and you will double the expected startup delay
after crash (and a bad shutdown qualifies as a crash of sorts).  You need
to make sure you're not making that time unacceptable for your application
before going too crazy increasing the segments.

You should certainly look into how to get your database to shutdown
cleanly though.  There's three modes here pg_ctl will use:  smart, fast,
immediate.  I consider smart just about useless because I always have
somebody connected.  Immediate has the problem you already noticed,
recovery after startup.  So fast is the most useful of the three modes.

You said "smart and normal mode"...the default is smart, so if you meant
"without specifying a mode" when you said normal then you just tried smart
twice--that matches your comment that it took "a long time" in both cases
(fast won't).  If I'm right about that, try fast next time.

If you couldn't shutdown using fast, that's something that deserves some
investigation. That shouldn't happen unless there's a bad situation.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD

On Thu, Apr 3, 2008 at 10:02 PM, Greg Smith <gsmith@gregsmith.com> wrote:
that is what I intended to write. I tried both smart and fast mode. and it says 'database wont shutdown', and immediate is the only mode that shutsdown the database.
 -> is shutting down in immediate mode a safe thing to do?
 -> how do i investigate why fast mode doesnt work?

stats with new settings are below..
  -> but even with this sometimes update queries take more than coupla seconds sometimes... 
  -> now i have a few '<IDLE> in transaction' statements which I did not have before.. is this OK?
  -> sometimes INSERT statements are also slow. is there any settings I can tweak to make INSERT statements fast?

bgwriter_lru_maxpages = 200             # 0-1000 max buffers written/round
checkpoint_segments = 96                # in logfile segments, min 1, 16MB each
checkpoint_timeout = 20min              # range 30s-1h
checkpoint_completion_target = 0.8      # checkpoint target duration, 0.0 - 1.0

postgres=# select * from pg_stat_bgwriter;
 checkpoints_timed | checkpoints_req | buffers_checkpoint | buffers_clean | maxwritten_clean | buffers_backend | buffers_alloc
-------------------+-----------------+--------------------+---------------+------------------+-----------------+---------------
                67 |               0 |            4012010 |        330679 |              570 |          184569 |       5379667
(1 row)

On 04/04/2008 05:43 PM, mark wrote:

> stats with new settings are below..

These stats look good for me.

> but even with this sometimes update queries take more than coupla
> seconds sometimes...

> checkpoint_completion_target = 0.8

It looks like that this is set too high for your workload. If you have
spikes of activity then it would be possible that checkpoint will not
end it's work before the next one should be started - I think it would
then halt everything until finished. Try to set it back to 0.5 and observe.

Did you turn on log_checkpoints as recommended? Could you quote your log
lines about checkpoints? Do they correlate with long running queries?

> sometimes INSERT statements are also slow. is there any settings
> can tweak to make INSERT statements fast?

For postgresql update in table data is the same as delete+insert, so the
same optimizations apply.

Regards
Tometzky
--
...although Eating Honey was a very good thing to do, there was a
moment just before you began to eat it which was better than when you
were...
                                                       Winnie the Pooh