Thread: Index creation problem
Hi,
www.gtwm.co.uk - company / www.agilebase.co.uk - product
I'm getting a problem where my application hangs in the process of adding a field to a table. The app adds the field, then creates an index on the field. It hangs for ages (minutes) until I cancel the query. My investigation so far has been
Look at current queries:
agilebasedata=# SELECT datname,procpid,current_query FROM pg_stat_activity;
datname | procpid | current_query
-----------------+---------+-----------------------------------------------------------------------------------------------------------------
agilebaseschema | 5799 | <IDLE> in transaction
agilebasedata | 18126 | SELECT datname,procpid,current_query FROM pg_stat_activity;
agilebasedata | 5844 | <IDLE>
agilebasedata | 5108 | CREATE INDEX l_ntvs1fk9de719830100m5aoi8suwo ON ntvs1fk9desoci59z(lower(m5aoi8suwo4jocu76) varchar_pattern_ops)
agilebasedata | 5109 | <IDLE> in transaction
agilebaseschema | 25200 | <IDLE>
agilebasedata | 29257 | <IDLE>
agilebasedata | 31574 | <IDLE>
(8 rows)
As you can see, the only user query running is the CREATE INDEX. Cancelling this with
select pg_cancel_backend(5108);
gets the app back on it's feet.
I thought there may be some sort of deadlock, but there is only one long running query. By the way, the indexing query should return quickly, as there are 0 rows in the table. It does in fact return immediately when you run it manually:
agilebasedata=# CREATE INDEX l_nx4uaurg3r1981190097whsqcun3e9 ON nx4uaurg3r94vwqhj(lower(whsqcun3e9lfzlwlv) varchar_pattern_ops);
ERROR: relation "l_nx4uaurg3r1981190097whsqcun3e9" already exists
agilebasedata=# drop index l_nx4uaurg3r1981190097whsqcun3e9;
DROP INDEX
agilebasedata=# CREATE INDEX l_nx4uaurg3r1981190097whsqcun3e9 ON nx4uaurg3r94vwqhj(lower(whsqcun3e9lfzlwlv) varchar_pattern_ops);
CREATE INDEX
One thing to mention is that there are a lot of indexes and relations:
agilebasedata=# select count(*) from pg_index;
count
-------
2587
(1 row)
agilebasedata=# select count(*) from pg_class;
count
-------
5361
(1 row)
I wonder if I'm running up against some sort of limit. I am going to change the code so it doesn't add an index (it's not always necessary) but would like to get to the bottom of things first.
Regards
Oliver Kohll
www.gtwm.co.uk - company / www.agilebase.co.uk - product
On 19 Oct 2012, at 13:28, Frank Lanitz <frank@frank.uvena.de> wrote:
Just an idea without bigger investigation: Whare are the idle in
transactions are doing? Maybe they are blocking the create index.
Cheers,
Frank
Good question, I don't know. The app runs on Java / Apache Tomcat, which maintains a connection pool, so I assumed the IDLEs were just opened connections but I didn't notice two were idle in transaction. I haven't dealt with this before but this looks like a good explanation:
I will up logging and try to replicate. Next time I will look at pg_locks too.
Also, the PG version is 9.1.6.
Oliver
Oliver Kohll wrote: > I'm getting a problem where my application hangs in the process of adding a field to a table. The app > adds the field, then creates an index on the field. It hangs for ages (minutes) until I cancel the > query. My investigation so far has been > > Look at current queries: > > agilebasedata=# SELECT datname,procpid,current_query FROM pg_stat_activity; > datname | procpid | current_query > -----------------+---------+-------------------------------------------- ------------------------------ > --------------------------------------- > agilebaseschema | 5799 | <IDLE> in transaction > agilebasedata | 18126 | SELECT datname,procpid,current_query FROM pg_stat_activity; > agilebasedata | 5844 | <IDLE> > agilebasedata | 5108 | CREATE INDEX l_ntvs1fk9de719830100m5aoi8suwo ON > ntvs1fk9desoci59z(lower(m5aoi8suwo4jocu76) varchar_pattern_ops) > agilebasedata | 5109 | <IDLE> in transaction > agilebaseschema | 25200 | <IDLE> > agilebasedata | 29257 | <IDLE> > agilebasedata | 31574 | <IDLE> > (8 rows) > > As you can see, the only user query running is the CREATE INDEX. Cancelling this with > > select pg_cancel_backend(5108); > > gets the app back on it's feet. > > I thought there may be some sort of deadlock, but there is only one long running query. By the way, > the indexing query should return quickly, as there are 0 rows in the table. It does in fact return > immediately when you run it manually: > > agilebasedata=# CREATE INDEX l_nx4uaurg3r1981190097whsqcun3e9 ON > nx4uaurg3r94vwqhj(lower(whsqcun3e9lfzlwlv) varchar_pattern_ops); > ERROR: relation "l_nx4uaurg3r1981190097whsqcun3e9" already exists > agilebasedata=# drop index l_nx4uaurg3r1981190097whsqcun3e9; > DROP INDEX > agilebasedata=# CREATE INDEX l_nx4uaurg3r1981190097whsqcun3e9 ON > nx4uaurg3r94vwqhj(lower(whsqcun3e9lfzlwlv) varchar_pattern_ops); > CREATE INDEX > > > One thing to mention is that there are a lot of indexes and relations: > > agilebasedata=# select count(*) from pg_index; > count > ------- > 2587 > (1 row) > > agilebasedata=# select count(*) from pg_class; > count > ------- > 5361 > (1 row) > > I wonder if I'm running up against some sort of limit. I am going to change the code so it doesn't add > an index (it's not always necessary) but would like to get to the bottom of things first. In the example you show, some connections are "idle in transaction". Such connections can hold locks that block your CREATE INDEX. Could you look at pg_locks if there is a lock that is not granted? There could also be prepared transactions holding locks, if you use that feature. There is also CREATE INDEX CONCURRENTLY which locks the table less. Does that make a difference? Does the process for the hanging backend consume CPU? You could try taking a stack trace to see where it hangs. Yours, Laurenz Albe
Oliver Kohll wrote: >> In the example you show, some connections are "idle in transaction". >> Such connections can hold locks that block your CREATE INDEX. >> Could you look at pg_locks if there is a lock that is not granted? >> There could also be prepared transactions holding locks, if >> you use that feature. > > Yes there was indeed an un-granted lock on the table. By logging all SQL I think I've found the client > code which is causing the problem, a line was added recently that basically causes > > DROP INDEX IF EXISTS > followed by > CREATE INDEX > > to be run twice in quick succession. These are all in the same thread and transaction so I wouldn't > have thought there'd be a locking problem but it's the most likely candidate at the moment. You should always include the list in your replies - other people might be interested in the solution. There must be at least two transactions involved to create a locking problem like you describe. But since CREATE INDEX takes strong locks, it can easily get locked by other "harmless" things. Yours, Laurenz Albe
On 19 Oct 2012, at 15:09, "Albe Laurenz" <laurenz.albe@wien.gv.at> wrote:
You should always include the list in your replies -
other people might be interested in the solution.
There must be at least two transactions involved
to create a locking problem like you describe.
But since CREATE INDEX takes strong locks, it can
easily get locked by other "harmless" things.
OK, I've reduced the calls to CREATE INDEX, waiting to test that. If there's still an issue I will use CONCURRENTLY as you suggested.
Many thanks
Oliver