'COPY ... FROM' inserts to btree, blocks on buffer writeout - Mailing list pgsql-hackers
From | Michael Wildpaner |
---|---|
Subject | 'COPY ... FROM' inserts to btree, blocks on buffer writeout |
Date | |
Msg-id | Pine.LNX.4.58.0412311737240.11356@rainbow.studorg.tuwien.ac.at Whole thread Raw |
Responses |
Re: 'COPY ... FROM' inserts to btree, blocks on buffer writeout
Re: 'COPY ... FROM' inserts to btree, blocks on buffer writeout |
List | 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 buffercontent 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: RowExclusiveLockon 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 ontable 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: AccessShareLockon table set_type (2112116436) granted: AccessShareLock on table data_store (2112116520) granted: AccessShareLockon 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: RowExclusiveLockon 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 tablefeature_link (2112116486) granted: AccessShareLock on table sequence_type (2112116441) granted: AccessShareLockon 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: AccessShareLockon 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 tablesequence_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 | t2112116466 | 2112078897 | | 17983 | AccessShareLock | t2112085544 | 2112078897 | | 17983 | RowExclusiveLock | t | | 26991864 | 17983 | ExclusiveLock | t2112116520 | 2112078897 | | 17980 | AccessShareLock | t2112116407 | 2112078897 | | 18084 | AccessShareLock | t2112116456 | 2112078897 | | 17983 | AccessShareLock | t2112085549 | 2112078897 | | 17980 | RowExclusiveLock | t2112117357 | 2112078897| | 17983 | RowExclusiveLock | t2112116461 | 2112078897 | | 17983 | AccessShareLock |t | | 26990698 | 17981 | ExclusiveLock | t2112116530 | 2112078897 | | 17980 | AccessShareLock | t2112085544 | 2112078897 | | 17980 | RowExclusiveLock | t | | 26991878| 17980 | ExclusiveLock | t2112116486 | 2112078897 | | 17983 | RowExclusiveLock | t2112117699 | 2112078897| | 18084 | AccessShareLock | t2112116530 | 2112078897 | | 17983 | AccessShareLock |t2112116535 | 2112078897 | | 17983 | AccessShareLock | t2112116471 | 2112078897 | | 17980 | AccessShareLock | t2124233471 | 2112078897 | | 17980 | ExclusiveLock | t2112116436 | 2112078897 | | 18084 | AccessShareLock | t2112116535 | 2112078897 | | 17980 | AccessShareLock | t2112116476 | 2112078897| | 17980 | AccessShareLock | t | | 26990811 | 17977 | ExclusiveLock |t2112116451 | 2112078897 | | 17980 | AccessShareLock | t 16837 | 2112078897 | | 23060 | AccessShareLock | t2112116451 | 2112078897 | | 17983 | AccessShareLock | t2112116441 | 2112078897 | | 17983 | AccessShareLock | t2112116515 | 2112078897 | | 17983 | AccessShareLock | t2112116525 | 2112078897| | 17983 | AccessShareLock | t2112116515 | 2112078897 | | 17980 | AccessShareLock |t2112116471 | 2112078897 | | 17983 | AccessShareLock | t | | 27016842 | 18084 | ExclusiveLock | t2112116476 | 2112078897 | | 17983 | AccessShareLock | t2112116486 | 2112078897 | | 17980 | RowExclusiveLock | t2112116441 | 2112078897 | | 17980 | AccessShareLock | t2112116525 | 2112078897| | 17980 | AccessShareLock | t | | 27018036 | 17976 | ExclusiveLock |t2112116431 | 2112078897 | | 17980 | AccessShareLock | t2112116456 | 2112078897 | | 17980 | AccessShareLock | t2112085549 | 2112078897 | | 17983 | RowExclusiveLock | t2112116436 | 2112078897 | | 17980 | AccessShareLock | t2112116436 | 2112078897 | | 17983 | AccessShareLock | t2112117337 | 2112078897| | 17980 | RowExclusiveLock | t2112116461 | 2112078897 | | 17980 | AccessShareLock |t2112117357 | 2112078897 | | 17980 | RowExclusiveLock | t2112116466 | 2112078897 | | 17980 | AccessShareLock | t2112116520 | 2112078897 | | 17983 | AccessShareLock | t | | 26991357| 17982 | ExclusiveLock | t | | 27018054 | 23060 | ExclusiveLock | t2124233471 | 2112078897| | 17983 | ExclusiveLock | f2112116431 | 2112078897 | | 17983 | AccessShareLock |t2112116431 | 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)
pgsql-hackers by date: