Skip site navigation (1) Skip section navigation (2)

'COPY ... FROM' inserts to btree, blocks on buffer writeout

From: Michael Wildpaner <mike(at)rainbow(dot)studorg(dot)tuwien(dot)ac(dot)at>
To: pgsql-hackers(at)postgresql(dot)org
Subject: 'COPY ... FROM' inserts to btree, blocks on buffer writeout
Date: 2004-12-31 18:04:31
Message-ID: Pine.LNX.4.58.0412311737240.11356@rainbow.studorg.tuwien.ac.at (view raw or flat)
Thread:
Lists: pgsql-hackers
Hi,

two concurrent clients try to 'COPY ... FROM ...' to the same table,
"feature_link".

The second one (pid 17983) is waiting for an ExclusiveLock on the table's
primary key index, "key__idpk__flink".

The first one (pid 17980) is inserting into the index's btree, waiting
for a buffer lock. This locking state seems to persist.

Do you have any idea what could cause this scenario and what kind of
debugging information I could extract (the processes are still running) to
find out who is currently holding the buffer lock in question?

Thanks for your help,
best wishes, Mike


[fuchs:~/build/postgresql-8.0.0beta2] vi +1004 ./src/backend/storage/buffer/bufmgr.c
    999   /*
   1000    * Protect buffer content against concurrent update.  (Note that
   1001    * hint-bit updates can still occur while the write is in progress,
   1002    * but we assume that that will not invalidate the data written.)
   1003    */
   1004   LockBuffer(buffer, BUFFER_LOCK_SHARE);
   1005


[fuchs:~/build/postgresql-8.0.0beta2] gdb src/backend/postgres
[...]
(gdb) attach 17980
[...]
(gdb) where
#0  0x0000002a96181279 in semop () from /lib64/tls/libc.so.6
#1  0x0000000000511707 in PGSemaphoreLock (sema=0x2aa16de2f0, interruptOK=0 '\0') at pg_sema.c:418
#2  0x000000000053549a in LWLockAcquire (lockid=32741, mode=LW_SHARED) at lwlock.c:315
#3  0x0000000000528a3d in FlushBuffer (buf=0x2a9953ea40, reln=0x900640) at bufmgr.c:1004
#4  0x000000000052806d in BufferAlloc (reln=0x2768021, blockNum=3220402560, foundPtr=0x7fbff3728f "") at bufmgr.c:365
#5  0x0000000000527edc in ReadBufferInternal (reln=0x2aa24786b8, blockNum=20055, bufferLockHeld=0 '\0') at bufmgr.c:153
#6  0x000000000044a930 in _bt_getbuf (rel=0x2aa24786b8, blkno=3220402560, access=2) at nbtpage.c:492
#7  0x0000000000448c87 in _bt_split (rel=0x2aa24786b8, buf=673, firstright=89, newitemoff=164, newitemsz=40, newitem=0x911d40, newitemonleft=0 '\0',
    itup_off=0x7fbff374c6, itup_blkno=0x7fbff374c8) at nbtinsert.c:683
#8  0x00000000004486ba in _bt_insertonpg (rel=0x2aa24786b8, buf=673, stack=0x9924f0, keysz=1, scankey=0x911d90, btitem=0x911d40, afteritem=0,
    split_only_page=0 '\0') at nbtinsert.c:500
#9  0x00000000004481eb in _bt_doinsert (rel=0x2aa24786b8, btitem=0x911d40, index_is_unique=1 '\001', heapRel=0x2aa2477c38) at nbtinsert.c:141
#10 0x000000000044bb71 in btinsert (fcinfo=0x2768021) at nbtree.c:257
#11 0x00000000005a44aa in OidFunctionCall6 (functionId=41320481, arg1=183111222968, arg2=548681250960, arg3=548681250928, arg4=9515332,
    arg5=183111220280, arg6=18446744073709551612) at fmgr.c:1487
#12 0x00000000004476a5 in index_insert (indexRelation=0x2aa24786b8, datums=0x7fbff37890, nulls=0x7fbff37870 " î", heap_t_ctid=0x913144,
    heapRelation=0x2aa2477c38, check_uniqueness=1 '\001') at indexam.c:226
#13 0x00000000004cf3cf in ExecInsertIndexTuples (slot=0x0, tupleid=0x7fbff37180, estate=0x990450, is_vacuum=0 '\0') at execUtils.c:859
#14 0x000000000049c1d1 in CopyFrom (rel=0x2aa2477c38, attnumlist=0x990060, binary=0 '\0', oids=0 '\0', delim=0x63e4cd "\t", null_print=0x608614 "\\N",
    csv_mode=0 '\0', quote=0x0, escape=0x0, force_notnull_atts=0x911cb0) at copy.c:1958
#15 0x000000000049a34f in DoCopy (stmt=0x2768021) at copy.c:1043
#16 0x000000000053d7b9 in PortalRunUtility (portal=0x906b40, query=0x8fa5f0, dest=0x8fa910, completionTag=0x7fbff37f60 "") at pquery.c:839
#17 0x000000000053da41 in PortalRunMulti (portal=0x906b40, dest=0x8fa910, altdest=0x8fa910, completionTag=0x7fbff37f60 "") at pquery.c:902
---Type <return> to continue, or q <return> to quit---
#18 0x000000000053d230 in PortalRun (portal=0x906b40, count=9223372036854775807, dest=0x8fa910, altdest=0x8fa910, completionTag=0x7fbff37f60 "")
    at pquery.c:543
#19 0x0000000000539c59 in exec_simple_query (
    query_string=0x8fa700 "COPY feature_link from '/anniedev1/impseb/datastore/results/2004/12/29/22/38/bio:query:ncbi-blast:10562062.out_featurelink'")
    at postgres.c:924
#20 0x000000000053bf6d in PostgresMain (argc=9414400, argv=0x86f028, username=0x86eff0 "annieseb") at postgres.c:2970
#21 0x0000000000514db7 in BackendRun (port=0x89c650) at postmaster.c:2848
#22 0x0000000000514850 in BackendStartup (port=0x89c650) at postmaster.c:2470
#23 0x0000000000512fde in ServerLoop () at postmaster.c:1215
#24 0x0000000000512446 in PostmasterMain (argc=1, argv=0x804850) at postmaster.c:898
#25 0x00000000004e3206 in main (argc=1, argv=0x804850) at main.c:265


[fuchs:/anniedev1/impseb/work/annie] ps -ef | grep impseb2 | grep -v grep | sort
anniedb2 17976 21254  0 Dec29 ?        00:03:50 postgres: annieseb impseb2 10.44.1.20(33855) idle in transaction
anniedb2 17977 21254  0 Dec29 ?        00:01:38 postgres: annieseb impseb2 10.44.1.20(33856) idle in transaction
anniedb2 17979 21254  0 Dec29 ?        00:03:21 postgres: annieseb impseb2 10.44.1.20(33857) idle in transaction
anniedb2 17980 21254  0 Dec29 ?        00:02:26 postgres: annieseb impseb2 10.44.1.20(33858) COPY
anniedb2 17981 21254  0 Dec29 ?        00:00:53 postgres: annieseb impseb2 10.44.1.20(33859) idle in transaction
anniedb2 17982 21254  0 Dec29 ?        00:03:31 postgres: annieseb impseb2 10.44.1.20(33860) idle in transaction
anniedb2 17983 21254  0 Dec29 ?        00:03:34 postgres: annieseb impseb2 10.44.1.20(33861) COPY waiting
anniedb2 18084 21254  0 Dec29 ?        00:03:15 postgres: annieseb impseb2 10.44.1.20(33863) idle in transaction
anniedb2 23066 21254  0 17:45 ?        00:00:00 postgres: annieseb impseb2 10.44.1.21(45361) idle

[fuchs:/anniedev1/impseb/work/annie] bin/pg-dump-locks
pid 17979
pid 23130
    granted: AccessShareLock on table pg_locks (16837)
    granted: AccessShareLock on table pg_class (1259)
    granted: AccessShareLock on table pg_index (16390)
pid 17981
pid 17983
    waiting: ExclusiveLock on table key__idpk__flink (2124233471)
    granted: RowExclusiveLock on table ncbi_blast_result (2112117337)
    granted: AccessShareLock on table nmt_parameter_set (2112116466)
    granted: RowExclusiveLock on table ncbi_blast_round (2112085544)
    granted: AccessShareLock on table gpi_learning_set (2112116456)
    granted: RowExclusiveLock on table ncbi_blast_alignment (2112117357)
    granted: AccessShareLock on table gpi3_learning_set (2112116461)
    granted: RowExclusiveLock on table feature_link (2112116486)
    granted: AccessShareLock on table managed_file_group (2112116530)
    granted: AccessShareLock on table algorithm_index_file (2112116535)
    granted: AccessShareLock on table def_parser_type (2112116451)
    granted: AccessShareLock on table sequence_type (2112116441)
    granted: AccessShareLock on table file_type (2112116515)
    granted: AccessShareLock on table managed_file (2112116525)
    granted: AccessShareLock on table ptsone_function (2112116471)
    granted: AccessShareLock on table toppred_function (2112116476)
    granted: RowExclusiveLock on table ncbi_blast_subject (2112085549)
    granted: AccessShareLock on table set_type (2112116436)
    granted: AccessShareLock on table data_store (2112116520)
    granted: AccessShareLock on table sequence_alphabet (2112116431)
pid 17980
    granted: AccessShareLock on table data_store (2112116520)
    granted: RowExclusiveLock on table ncbi_blast_subject (2112085549)
    granted: AccessShareLock on table managed_file_group (2112116530)
    granted: RowExclusiveLock on table ncbi_blast_round (2112085544)
    granted: AccessShareLock on table ptsone_function (2112116471)
    granted: ExclusiveLock on table key__idpk__flink (2124233471)
    granted: AccessShareLock on table algorithm_index_file (2112116535)
    granted: AccessShareLock on table toppred_function (2112116476)
    granted: AccessShareLock on table def_parser_type (2112116451)
    granted: AccessShareLock on table file_type (2112116515)
    granted: RowExclusiveLock on table feature_link (2112116486)
    granted: AccessShareLock on table sequence_type (2112116441)
    granted: AccessShareLock on table managed_file (2112116525)
    granted: AccessShareLock on table sequence_alphabet (2112116431)
    granted: AccessShareLock on table gpi_learning_set (2112116456)
    granted: AccessShareLock on table set_type (2112116436)
    granted: RowExclusiveLock on table ncbi_blast_result (2112117337)
    granted: AccessShareLock on table gpi3_learning_set (2112116461)
    granted: RowExclusiveLock on table ncbi_blast_alignment (2112117357)
    granted: AccessShareLock on table nmt_parameter_set (2112116466)
pid 17982
pid 18084
    granted: AccessShareLock on table changeable_bio_set (2112116407)
    granted: AccessShareLock on table ojb_splice_list (2112117699)
    granted: AccessShareLock on table set_type (2112116436)
    granted: AccessShareLock on table sequence_alphabet (2112116431)
pid 17976
pid 17977

impseb2=# select * from pg_locks;
  relation  |  database  | transaction |  pid  |       mode       | granted
------------+------------+-------------+-------+------------------+---------
 2112117337 | 2112078897 |             | 17983 | RowExclusiveLock | t
            |            |    26991056 | 17979 | ExclusiveLock    | t
 2112116466 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112085544 | 2112078897 |             | 17983 | RowExclusiveLock | t
            |            |    26991864 | 17983 | ExclusiveLock    | t
 2112116520 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112116407 | 2112078897 |             | 18084 | AccessShareLock  | t
 2112116456 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112085549 | 2112078897 |             | 17980 | RowExclusiveLock | t
 2112117357 | 2112078897 |             | 17983 | RowExclusiveLock | t
 2112116461 | 2112078897 |             | 17983 | AccessShareLock  | t
            |            |    26990698 | 17981 | ExclusiveLock    | t
 2112116530 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112085544 | 2112078897 |             | 17980 | RowExclusiveLock | t
            |            |    26991878 | 17980 | ExclusiveLock    | t
 2112116486 | 2112078897 |             | 17983 | RowExclusiveLock | t
 2112117699 | 2112078897 |             | 18084 | AccessShareLock  | t
 2112116530 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112116535 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112116471 | 2112078897 |             | 17980 | AccessShareLock  | t
 2124233471 | 2112078897 |             | 17980 | ExclusiveLock    | t
 2112116436 | 2112078897 |             | 18084 | AccessShareLock  | t
 2112116535 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112116476 | 2112078897 |             | 17980 | AccessShareLock  | t
            |            |    26990811 | 17977 | ExclusiveLock    | t
 2112116451 | 2112078897 |             | 17980 | AccessShareLock  | t
      16837 | 2112078897 |             | 23060 | AccessShareLock  | t
 2112116451 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112116441 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112116515 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112116525 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112116515 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112116471 | 2112078897 |             | 17983 | AccessShareLock  | t
            |            |    27016842 | 18084 | ExclusiveLock    | t
 2112116476 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112116486 | 2112078897 |             | 17980 | RowExclusiveLock | t
 2112116441 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112116525 | 2112078897 |             | 17980 | AccessShareLock  | t
            |            |    27018036 | 17976 | ExclusiveLock    | t
 2112116431 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112116456 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112085549 | 2112078897 |             | 17983 | RowExclusiveLock | t
 2112116436 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112116436 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112117337 | 2112078897 |             | 17980 | RowExclusiveLock | t
 2112116461 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112117357 | 2112078897 |             | 17980 | RowExclusiveLock | t
 2112116466 | 2112078897 |             | 17980 | AccessShareLock  | t
 2112116520 | 2112078897 |             | 17983 | AccessShareLock  | t
            |            |    26991357 | 17982 | ExclusiveLock    | t
            |            |    27018054 | 23060 | ExclusiveLock    | t
 2124233471 | 2112078897 |             | 17983 | ExclusiveLock    | f
 2112116431 | 2112078897 |             | 17983 | AccessShareLock  | t
 2112116431 | 2112078897 |             | 18084 | AccessShareLock  | t
(54 rows)

-- 
Do not feel safe. The poet remembers.           DI Michael Wildpaner
You can kill one, but another is born.                 Ph.D. Student
The words are written down,
the deed, the date.  (Czeslaw Milosz)

Responses

pgsql-hackers by date

Next:From: Tom LaneDate: 2004-12-31 19:18:33
Subject: Re: uptime() for postmaster
Previous:From: Matthias SchmidtDate: 2004-12-31 13:06:13
Subject: uptime() for postmaster

Privacy Policy | About PostgreSQL
Copyright © 1996-2014 The PostgreSQL Global Development Group