Thread: Periodically slow inserts
Hello, We are using PostgreSQL for storing data and full-text search indexes for the webiste of a daily newspaper. We are very happy overall with the results, but we have one "weird" behaviour that we would like to solve. The problem is when we index objects into the full-text search part of the database (which a DELETE and then an INSERT into a specific table), the INSERT sometimes take a long time (from 10s to 20s), but the same insert (and many other similar ones) are fast (below 0.2s). This slowness comes regularly, about every 200 objects indexed, regardless of the frequency of the inserts. If I reindex one object every 5 seconds for one hour, or one object every second for 10 minutes, I've the same kind of results : around 0.5% of the time, indexing took more than 10s. The positive point is that this slowness doesn't block the rest of queries to the database, but it's still painful to have to wait (even if only once in a while) for 10s or 20s when the end-user hits the "save" button. This slowness is associated with very high IO load on the operating system. I tried playing with checkpoint parameters (making them more frequent or less frequent, but I didn't notice any siginificant difference). Do you have any hint on how to smooth the process, so we don't have this regular huge slowdown ? If you want more details about the setup : - server is a Xen virtual machine with 8Gb of memory, disks being 15000 rpm SAS disks on RAID 1, and CPU being one core of a Nehalem processor (but CPU load is low anyway). - the database schema is like : CREATE TABLE sesql_index ( classname varchar(255), id integer, created_at timestamp, modified_at timestamp, created_by integer, modified_by integer, workflow_state integer, site_id integer, title_text text, title_tsv tsvector, subtitle_text text, subtitle_tsv tsvector, fulltext_text text, fulltext_tsv tsvector, authors integer[], folders integer[], [...] indexed_at timestamp DEFAULT NOW(), PRIMARY KEY (classname, id) ); CREATE TABLE sesql_author (CHECK (classname = 'Author'), PRIMARY KEY (classname, id)) INHERITS (sesql_index); CREATE TABLE sesql_program (CHECK (classname = 'Program'), PRIMARY KEY (classname, id)) INHERITS (sesql_index); CREATE TABLE sesql_default (CHECK (classname = 'Slideshow' OR classname = 'Book' OR classname = 'Article' OR classname = 'Publication' OR classname = 'Forum'), PRIMARY KEY (classname, id)) INHERITS (sesql_index); (with a few other similar tables for different objects). Inserts/deletes are done directly into the child tables, searches are done either on the master table (sesql_index) or on the child tables depending of the use case (but search works fine anyway). In addition to that we have several indexes, created on each child tables : CREATE INDEX sesql_default_classname_index ON sesql_default (classname); CREATE INDEX sesql_default_id_index ON sesql_default (id); CREATE INDEX sesql_default_created_at_index ON sesql_default (created_at); CREATE INDEX sesql_default_modified_at_index ON sesql_default (modified_at); CREATE INDEX sesql_default_created_by_index ON sesql_default (created_by); CREATE INDEX sesql_default_modified_by_index ON sesql_default (modified_by); CREATE INDEX sesql_default_workflow_state_index ON sesql_default (workflow_state); CREATE INDEX sesql_default_site_id_index ON sesql_default (site_id); CREATE INDEX sesql_default_publication_date_index ON sesql_default (publication_date); CREATE INDEX sesql_default_authors_index ON sesql_default USING GIN (authors); CREATE INDEX sesql_default_folders_index ON sesql_default USING GIN (folders); And the heavy ones, for each fulltext field, we have two columns, the text and the tsv, with an index on the tsv, and the tsv itself is updated via a trigger : CREATE INDEX sesql_default_fulltext_index ON sesql_default USING GIN (fulltext_tsv); CREATE TRIGGER sesql_default_fulltext_update BEFORE INSERT OR UPDATE ON sesql_default FOR EACH ROW EXECUTE PROCEDURE tsvector_update_trigger(fulltext_tsv, 'public.lem_french', fulltext_text); Thanks a lot for reading me until here ;) Regards, -- Gaël Le Mignot - gael@pilotsystems.net Pilot Systems - 9, rue Desargues - 75011 Paris Tel : +33 1 44 53 05 55 - www.pilotsystems.net Gérez vos contacts et vos newsletters : www.cockpit-mailing.com
Hi, There are a lot of details missing about your system: http://wiki.postgresql.org/wiki/SlowQueryQuestions Cheers, Ken On Thu, Oct 21, 2010 at 02:25:44PM +0200, Gael Le Mignot wrote: > > Hello, > > We are using PostgreSQL for storing data and full-text search indexes > for the webiste of a daily newspaper. We are very happy overall with the > results, but we have one "weird" behaviour that we would like to solve. > > ...
> We are using PostgreSQL for storing data and full-text search indexes > for the webiste of a daily newspaper. We are very happy overall with the > results, but we have one "weird" behaviour that we would like to solve. I think there's a lot of missing info worth knowing: 1) checkpoints logs? Enable them, maybe the "slowness" happens at checkpoints: log_checkpoints=true 2) How many rows does each table contain? 3) HW: how many discs you have, and which controller you're using (and: does it use a BBU?) The more you tell the list, the better help you'll get...
Gael Le Mignot <gael@pilotsystems.net> writes: > The problem is when we index objects into the full-text search part of > the database (which a DELETE and then an INSERT into a specific table), > the INSERT sometimes take a long time (from 10s to 20s), but the same > insert (and many other similar ones) are fast (below 0.2s). > This slowness comes regularly, about every 200 objects indexed, > regardless of the frequency of the inserts. Hm. You didn't say which PG version you're using, but if it's >= 8.4, I think this may be caused by GIN's habit of queuing index insertions until it's accumulated a reasonable-size batch: http://www.postgresql.org/docs/9.0/static/gin-implementation.html#GIN-FAST-UPDATE While you can turn that off, I think that doing so will reduce the index's search efficiency over time. It might be better to schedule regular vacuums on the table so that the work is done by vacuum rather than foreground queries. regards, tom lane
Hello Leonardo! Thu, 21 Oct 2010 14:15:40 +0100 (BST), you wrote: >> We are using PostgreSQL for storing data and full-text search indexes >> for the webiste of a daily newspaper. We are very happy overall with the >> results, but we have one "weird" behaviour that we would like to solve. > I think there's a lot of missing info worth knowing: > 1) checkpoints logs? Enable them, maybe the "slowness" happens > at checkpoints: > log_checkpoints=true Yes, it's the checkpoints. The delay is the delay of the "sync" part of the checkpoints : 2010-10-21 16:39:15 CEST LOG: checkpoint complete: wrote 365 buffers (11.9%); 0 transaction log file(s) added, 0 removed, 3 recycled; write=0.403 s, sync=21.312 s, total=21.829 s Maybe there is something I misunderstood, but aren't the checkpoints supposed to run smoothly over the checkpoint_completion_target interval ? Is there any way to smooth it over time ? > 2) How many rows does each table contain? The problems occur on the "big" table with around 570 000 rows. Sorry I forgot that information. > 3) HW: how many discs you have, and which controller you're using (and: > does it use a BBU?) 2 SAS 15K disks in RAID1 (Linux software RAID). The controller is LSI SAS1068E PCI-Express Fusion-MPT SAS, and we did enable the write cache (sdparm says : WCE 1 [cha: y] ). Not sure if it has a BBU, but we have redundant power supply, and when we'll go live, we'll have a warm standby on different hardware through WAL log shipping (it's not in place right now), and we can afford a few minutes of dataloss in case of exceptional failure. > The more you tell the list, the better help you'll get... Of course, thanks for your feedback. As for the othe questions of the Wiki page : - I don't think explain/explain analyze will provide any information for inserts with no subqueries/... - We have (Debian) default config for autovacuum, and I tried a "vacuum analyze;" just before running a bench, it didn't change anything. - I tried moving the WAL to another pair of similar RAID1 SAS disks, but it didn't have any significant effect. And I also forgot to give the PostgreSQL version, it's 8.4.4 from Debian backports. Regards, -- Gaël Le Mignot - gael@pilotsystems.net Pilot Systems - 9, rue Desargues - 75011 Paris Tel : +33 1 44 53 05 55 - www.pilotsystems.net Gérez vos contacts et vos newsletters : www.cockpit-mailing.com
> > does it use a BBU?) Sorry, this was supposed to read "do you have cache on the controller", of course a battery can't change the performance... but you got it anyway...
> 2010-10-21 16:39:15 CEST LOG: checkpoint complete: wrote 365 buffers > (11.9%); 0 transaction log file(s) added, 0 removed, 3 recycled; > write=0.403 s, sync=21.312 s, total=21.829 s I'm no expert, but isn't 21s to sync 365 buffers a big amount of time?
2010/10/21 Leonardo Francalanci <m_lists@yahoo.it>: >> 2010-10-21 16:39:15 CEST LOG: checkpoint complete: wrote 365 buffers >> (11.9%); 0 transaction log file(s) added, 0 removed, 3 recycled; >> write=0.403 s, sync=21.312 s, total=21.829 s > > > I'm no expert, but isn't 21s to sync 365 buffers a big amount of time? It is. I suggest to look at /proc/meminfo about dirty buffers and the results of 'iostat -x 2' runing for some moment > > > > > > -- > Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) > To make changes to your subscription: > http://www.postgresql.org/mailpref/pgsql-performance > -- Cédric Villemain 2ndQuadrant http://2ndQuadrant.fr/ PostgreSQL : Expertise, Formation et Support
Gael Le Mignot wrote: > The delay is the delay of the "sync" part of > the checkpoints : > > 2010-10-21 16:39:15 CEST LOG: checkpoint complete: wrote 365 buffers > (11.9%); 0 transaction log file(s) added, 0 removed, 3 recycled; > write=0.403 s, sync=21.312 s, total=21.829 s > > Maybe there is something I misunderstood, but aren't the checkpoints > supposed to run smoothly over the checkpoint_completion_target interval ? > Well, first off you have to get the checkpoints spaced out in time enough for that to work. Both checkpoint_segments and possibly checkpoint_timeout may also need to be increased in order for the checkpoint write spreading code to work. When I start seeing long sync times, I'll usually shoot for >64 segments and >10 minutes for the timeout to give that smoothing work some room to do what it's supposed to. However, only the main checkpoint writes are spread over time. The hope is that by the time the sync phase starts, the operating system will have already written most of them out. Sometimes, particularly in servers with lots of RAM for caching writes, this doesn't happen. In that case, you can have gigabytes of data queued up at the beginning of the sync phase--which is not spread out at all. We are currently working on a "spread sync" feature for PostgreSQL that makes this problem better on platforms/filesystems it's possible to improve behavior on (you can't do anything about this issue on ext3 for example). I'll be talking about that development at the PgWest conference in a two weeks: https://www.postgresqlconference.org/content/righting-your-writes and hope to submit a patch with a first version of this feature to the November development CommitFest, in hopes of it making it into version 9.1. If you can't come up with any solution here and need help with your current version sooner than that, we've already backported this improvement all the way to V8.3; drop me an off-list note if you want to discuss consulting services in this area we have available. If you're lucky, just adjusting the segment and timeout values may be enough for you. -- Greg Smith, 2ndQuadrant US greg@2ndQuadrant.com Baltimore, MD PostgreSQL Training, Services and Support www.2ndQuadrant.us Author, "PostgreSQL 9.0 High Performance" http://www.2ndquadrant.com/books
Hello Tom! Thu, 21 Oct 2010 10:55:48 -0400, you wrote: > Gael Le Mignot <gael@pilotsystems.net> writes: >> The problem is when we index objects into the full-text search part of >> the database (which a DELETE and then an INSERT into a specific table), >> the INSERT sometimes take a long time (from 10s to 20s), but the same >> insert (and many other similar ones) are fast (below 0.2s). >> This slowness comes regularly, about every 200 objects indexed, >> regardless of the frequency of the inserts. > Hm. You didn't say which PG version you're using, but if it's >= 8.4, > I think this may be caused by GIN's habit of queuing index insertions > until it's accumulated a reasonable-size batch: > http://www.postgresql.org/docs/9.0/static/gin-implementation.html#GIN-FAST-UPDATE > While you can turn that off, I think that doing so will reduce the > index's search efficiency over time. It might be better to schedule > regular vacuums on the table so that the work is done by vacuum rather > than foreground queries. Thanks for your feedback. It seems to be related, at least, if I increase the work_mem variable, the slowness because bigger (up to 1 minute for a work_mem of 8mb) but much less frequent (around 0.05% instead of 0.5% of the requests for 8mb instead of 1mb). So a big work_mem and a regular vacuum would do the tick, I think. Does auto_vacuum triggers the gin index vacuuming too, or does it require a manual vacuum ? Regards, -- Gaël Le Mignot - gael@pilotsystems.net Pilot Systems - 9, rue Desargues - 75011 Paris Tel : +33 1 44 53 05 55 - www.pilotsystems.net Gérez vos contacts et vos newsletters : www.cockpit-mailing.com
Gael Le Mignot wrote: > Hello, > > We are using PostgreSQL for storing data and full-text search indexes > for the webiste of a daily newspaper. We are very happy overall with the > results, but we have one "weird" behaviour that we would like to solve. > > The problem is when we index objects into the full-text search part of > the database (which a DELETE and then an INSERT into a specific table), > the INSERT sometimes take a long time (from 10s to 20s), but the same > insert (and many other similar ones) are fast (below 0.2s). > Have you tried with strace, just to see where the time is spent? -- Mladen Gogala Sr. Oracle DBA 1500 Broadway New York, NY 10036 (212) 329-5251 http://www.vmsinfo.com The Leader in Integrated Media Intelligence Solutions
Gael Le Mignot <gael@pilotsystems.net> writes: > Thu, 21 Oct 2010 10:55:48 -0400, you wrote: >>> I think this may be caused by GIN's habit of queuing index insertions >>> until it's accumulated a reasonable-size batch: >>> http://www.postgresql.org/docs/9.0/static/gin-implementation.html#GIN-FAST-UPDATE > So a big work_mem and a regular vacuum would do the tick, I think. Does > auto_vacuum triggers the gin index vacuuming too, or does it require a > manual vacuum ? Autovacuum will handle it too. regards, tom lane
>>> I think this may be caused by GIN's habit of queuing index insertions >>> until it's accumulated a reasonable-size batch: So the fact that it takes 21s to sync 365 buffers in this case is normal?
Hello, Thanks to everyone who gave me hints and feedbacks. I managed to solve the problem. My understanding of what was happening is the following : - The gin index (as explained on [1]), stores temporary list, and when they grow big enough, those are dispatched into the real index. Vacuum also does this index flush, in background. - This index flush, on a table with 500k rows, means making changes to a lot of disk pages, filling the WAL in one big burst, forcing an immediate checkpoint, and blocking the INSERT that triggered it. I managed to solve the problem by adjusting two set of parameters : - The work_mem variable, which sepcify the maximal size of the temporary list before the gin index is "flushed". - The autovacuum parameters. The main idea was to increase the size of temporary lists (through work_mem) and increase the frequency of autovacuums, to ensure that under real life load (even heavy real life load), the "index flush" is always done by the autovacuum, and never by the "list is full" trigger. With this setup, I managed to handle indexing 10 000 objects in 2 hours without any stall, which is much more than we'll have to handle under real life load. Regards, [1] http://www.postgresql.org/docs/8.4/static/gin-implementation.html -- Gaël Le Mignot - gael@pilotsystems.net Pilot Systems - 9, rue Desargues - 75011 Paris Tel : +33 1 44 53 05 55 - www.pilotsystems.net Gérez vos contacts et vos newsletters : www.cockpit-mailing.com