search

citusdata / citus

Distributed PostgreSQL as an extension
https://www.citusdata.com
GNU Affero General Public License v3.0
10.46k stars 662 forks source link

Deadlock when creating index on partitioned table #2714

Closed colton-citus closed 4 years ago

colton-citus commented 5 years ago

Following error observed when indexing partition column of distributed native partitioned table:

ERROR: canceling the transaction since it was involved in a distributed deadlock

Reproduction script:

CREATE TABLE test_table (
  transaction_timestamp timestamp NOT NULL,
  user_id integer DEFAULT NULL,
  merchant_id integer DEFAULT NULL
  ) PARTITION BY RANGE (transaction_timestamp);

CREATE TABLE test_table_2016 PARTITION OF public.test_table FOR VALUES FROM ('2016-01-01') TO ('2016-12-31');

SELECT create_distributed_table('test_table', 'user_id');
CREATE INDEX IF NOT EXISTS
  ix_timestamp ON test_table (transaction_timestamp);
colton-citus commented 5 years ago

Workaround:

set citus.multi_shard_modify_mode to 'sequential';
isabel-potgieter commented 4 years ago

@colton-citus - we experienced the same problem creating a unique index on one of our tables in citus - we tried the workaround and it did solve our problem while you are working on a long term solution.

Query format : 

create unique index concurrently uk2_name on schema.table (unique_col1, unique_col2, unique_col3,unique_col4,unique_col5,unique_col6,unique_col7,unique_col8,
   unique_col9,unique_col10, unique_col11 )

error stacktrace: 

Caused by: org.postgresql.util.PSQLException: ERROR: canceling the transaction since it was involved in a distributed deadlock
            at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2440) ~[postgresql-42.2.4.jar!/:42.2.4]
            at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2183) ~[postgresql-42.2.4.jar!/:42.2.4]
            at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:308) ~[postgresql-42.2.4.jar!/:42.2.4]
            at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441) ~[postgresql-42.2.4.jar!/:42.2.4]
            at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365) ~[postgresql-42.2.4.jar!/:42.2.4]
            at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:307) ~[postgresql-42.2.4.jar!/:42.2.4]
            at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:293) ~[postgresql-42.2.4.jar!/:42.2.4]
            at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:270) ~[postgresql-42.2.4.jar!/:42.2.4]
            at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:266) ~[postgresql-42.2.4.jar!/:42.2.4]
            at liquibase.executor.jvm.JdbcExecutor$ExecuteStatementCallback.doInStatement(JdbcExecutor.java:352) ~[liquibase-core-3.6.2.jar!/:na]
            ... 48 common frames omitted

let me know if you require any additional information.

marcocitus commented 4 years ago

@isabel-potgieter which version of Citus are you using?

isabel-potgieter commented 4 years ago

Hi

We used the Azure Hyperscale Citus database - I am not sure what the version of that is - we did the initial setup about a month ago.

Regards

On Fri, Jul 17, 2020 at 6:26 AM Marco Slot notifications@github.com wrote:

@isabel-potgieter https://github.com/isabel-potgieter which version of Citus are you using?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/citusdata/citus/issues/2714#issuecomment-660054608, or unsubscribe https://github.com/notifications/unsubscribe-auth/AQJZHEMPAZGVYQBIERMHAKTR4AYOJANCNFSM4HNYZTWA .

onderkalaci commented 4 years ago

Reported by HSC customer again:

CREATE TABLE public.test_index_creation1
(
    tenant_id integer NOT NULL,
    timeperiod timestamp without time zone NOT NULL,
field1 integer NOT NULL,
    inserted_utc timestamp without time zone NOT NULL DEFAULT now()
) PARTITION BY RANGE (timeperiod);

select create_distributed_table('public.test_index_creation1', 'tenant_id');

delete from partman.part_config  where parent_table = 'public.test_index_creation1';
SELECT partman.create_parent('public.test_index_creation1', 'timeperiod', 'native', '1 days');

--THEN RUN THIS AFTER

CREATE INDEX ix_test_index_creation1
    ON public.test_index_creation1 USING btree
    (tenant_id, timeperiod);

If you remove 1 at the end of the table name, it works fine. Similarly, as noted above: set citus.multi_shard_modify_mode to 'sequential'; should make it work

onderkalaci commented 4 years ago

https://github.com/citusdata/citus/issues/1664 and this issue essentially the same. When an index is created on a partition, Postgres automatically gives long index names such as:

DEBUG:  building index "test_index_creation1_p2020_09_2_tenant_id_timeperiod_field1_idx" on table "test_index_creation1_p2020_09_26_102135" serially
DEBUG:  building index "test_index_creation1_p2020_09__tenant_id_timeperiod_field1_idx1" on table "test_index_creation1_p2020_09_27_102167" serially
DEBUG:  building index "test_index_creation1_p2020_09__tenant_id_timeperiod_field1_idx2" on table "test_index_creation1_p2020_09_28_102199" serially
DEBUG:  building index "test_index_creation1_p2020_09__tenant_id_timeperiod_field1_idx3" on table "test_index_creation1_p2020_09_29_102231" serially
DEBUG:  building index "test_index_creation1_p2020_09_3_tenant_id_timeperiod_field1_idx" on table "test_index_creation1_p2020_09_30_102263" serially
DEBUG:  building index "test_index_creation1_p2020_10_0_tenant_id_timeperiod_field1_idx" on table "test_index_creation1_p2020_10_01_102295" serially
DEBUG:  building index "test_index_creation1_p2020_10__tenant_id_timeperiod_field1_idx1" on table "test_index_creation1_p2020_10_02_102327" serially
DEBUG:  building index "test_index_creation1_p2020_10__tenant_id_timeperiod_field1_idx2" on table "test_index_creation1_p2020_10_03_102359" serially
DEBUG:  building index "test_index_creation1_p2020_10__tenant_id_timeperiod_field1_idx3" on table "test_index_creation1_p2020_10_04_102391" serially
DEBUG:  building index "test_index_creation1_default_10_tenant_id_timeperiod_field1_idx" on table "test_index_creation1_default_102423" serially
CREATE INDEX

And, the backtrace for the self-deadlocked processes:

(lldb) bt
* thread #1, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x00007fff603a536a libsystem_kernel.dylib`poll + 10
    frame #1: 0x000000010bfbd6e5 postgres`WaitEventSetWaitBlock(set=0x00007f966c81b548, cur_timeout=<unavailable>, occurred_events=0x00007ffee3f030b8, nevents=1) at latch.c:1207:7
    frame #2: 0x000000010bfbd314 postgres`WaitEventSetWait(set=0x00007f966c81b548, timeout=-1, occurred_events=0x00007ffee3f03070, nevents=1, wait_event_info=<unavailable>) at latch.c:1032:8
    frame #3: 0x000000010bfbd095 postgres`WaitLatchOrSocket(latch=<unavailable>, wakeEvents=<unavailable>, sock=-1, timeout=-1, wait_event_info=50331652) at latch.c:407:7
    frame #4: 0x000000010bfce764 postgres`ProcSleep(locallock=0x00007f966d8050c0, lockMethodTable=<unavailable>) at proc.c:1289:11
    frame #5: 0x000000010bfc9d90 postgres`WaitOnLock(locallock=0x00007f966d8050c0, owner=<unavailable>) at lock.c:1768:7
    frame #6: 0x000000010bfc90bf postgres`LockAcquireExtended(locktag=<unavailable>, lockmode=5, sessionLock=<unavailable>, dontWait=<unavailable>, reportMemoryError=<unavailable>, locallockp=0x0000000000000000) at lock.c:1050:3
    frame #7: 0x000000010bfc7d40 postgres`XactLockTableWait(xid=642, rel=<unavailable>, ctid=<unavailable>, oper=XLTW_InsertIndex) at lmgr.c:658:10
    frame #8: 0x000000010bd5a981 postgres`_bt_doinsert(rel=0x000000010eafc7e8, itup=0x00007f966c81a1c8, checkUnique=UNIQUE_CHECK_YES, heapRel=0x000000010eaf3b70) at nbtinsert.c:269:5
    frame #9: 0x000000010bd621c6 postgres`btinsert(rel=0x000000010eafc7e8, values=<unavailable>, isnull=<unavailable>, ht_ctid=0x00007f966a04f17c, heapRel=<unavailable>, checkUnique=<unavailable>, indexInfo=<unavailable>) at nbtree.c:205:11
    frame #10: 0x000000010bdb4c50 postgres`CatalogIndexInsert(indstate=<unavailable>, heapTuple=<unavailable>) at indexing.c:157:3
    frame #11: 0x000000010bdb4ace postgres`CatalogTupleInsert(heapRel=0x000000010eaf3b70, tup=0x00007f966a04f178) at indexing.c:191:2
    frame #12: 0x000000010bdad32e postgres`InsertPgClassTuple(pg_class_desc=0x000000010eaf3b70, new_rel_desc=<unavailable>, new_rel_oid=<unavailable>, relacl=0, reloptions=0) at heap.c:942:2
    frame #13: 0x000000010bdb0c86 postgres`index_create(heapRelation=0x000000010eb1c3c0, indexRelationName="test_index_creation1_p2020_09_26_10213_tenant_id_timeperiod_idx", indexRelationId=<unavailable>, parentIndexRelid=18622, parentConstraintId=0, relFileNode=0, indexInfo=0x00007f966c81a6d8, indexColNames=0x00007f966c81abc8, accessMethodObjectId=403, tableSpaceId=0, collationObjectId=0x00007f966c81adb8, classObjectId=0x00007f966c81add8, coloptions=0x00007f966c81adf8, reloptions=0, flags=0, constr_flags=0, allow_system_table_mods=<unavailable>, is_internal=<unavailable>, constraintId=0x00007ffee3f03a0c) at index.c:960:2
    frame #14: 0x000000010be3cba7 postgres`DefineIndex(relationId=<unavailable>, stmt=0x00007f966c81a130, indexRelationId=0, parentIndexId=18622, parentConstraintId=0, is_alter_table=<unavailable>, check_rights=<unavailable>, check_not_in_use=<unavailable>, skip_build=<unavailable>, quiet=<unavailable>) at indexcmds.c:1058:3
    frame #15: 0x000000010be3cf73 postgres`DefineIndex(relationId=<unavailable>, stmt=0x00007f966a04f010, indexRelationId=<unavailable>, parentIndexId=0, parentConstraintId=0, is_alter_table=<unavailable>, check_rights=<unavailable>, check_not_in_use=<unavailable>, skip_build=<unavailable>, quiet=<unavailable>) at indexcmds.c:1282:6
    frame #16: 0x000000010bfe4fae postgres`ProcessUtilitySlow(pstate=<unavailable>, pstmt=0x00007f966a808918, queryString="CREATE  INDEX   ix_test_102104 ON public.test_index_creation1_102104 USING btree (tenant_id ,timeperiod ) ", context=PROCESS_UTILITY_TOPLEVEL, params=0x0000000000000000, queryEnv=<unavailable>, dest=<unavailable>, completionTag="") at utility.c:1373:7
    frame #17: 0x000000010bfe3db9 postgres`standard_ProcessUtility(pstmt=<unavailable>, queryString=<unavailable>, context=PROCESS_UTILITY_TOPLEVEL, params=0x0000000000000000, queryEnv=0x0000000000000000, dest=<unavailable>, completionTag="") at utility.c:0
    frame #18: 0x000000010e8a92b0 citus.so`multi_ProcessUtility(pstmt=0x00007f966a808918, queryString=<unavailable>, context=PROCESS_UTILITY_TOPLEVEL, params=0x0000000000000000, queryEnv=<unavailable>, dest=0x00007f9669808130, completionTag="") at utility_hook.c:486:3
    frame #19: 0x000000010eab090e pg_stat_statements.so`pgss_ProcessUtility(pstmt=0x00007f9669808038, queryString="CREATE  INDEX   ix_test_102104 ON public.test_index_creation1_102104 USING btree (tenant_id ,timeperiod ) ", context=PROCESS_UTILITY_TOPLEVEL, params=0x0000000000000000, queryEnv=0x0000000000000000, dest=0x00007f9669808130, completionTag="") at pg_stat_statements.c:1002:5
    frame #20: 0x000000010bfe3536 postgres`PortalRunUtility(portal=0x00007f966983e118, pstmt=0x00007f9669808038, isTopLevel=<unavailable>, setHoldSnapshot=<unavailable>, dest=<unavailable>, completionTag="") at pquery.c:1175:2
    frame #21: 0x000000010bfe2cb4 postgres`PortalRunMulti(portal=0x00007f966983e118, isTopLevel=<unavailable>, setHoldSnapshot=<unavailable>, dest=0x00007f9669808130, altdest=0x00007f9669808130, completionTag="") at pquery.c:0
    frame #22: 0x000000010bfe2660 postgres`PortalRun(portal=0x00007f966983e118, count=9223372036854775807, isTopLevel=<unavailable>, run_once=<unavailable>, dest=0x00007f9669808130, altdest=0x00007f9669808130, completionTag="") at pquery.c:796:5
    frame #23: 0x000000010bfdfd48 postgres`exec_simple_query(query_string="CREATE  INDEX   ix_test_102104 ON public.test_index_creation1_102104 USING btree (tenant_id ,timeperiod ) ") at postgres.c:1215:10
    frame #24: 0x000000010bfdf4f5 postgres`PostgresMain(argc=<unavailable>, argv=<unavailable>, dbname=<unavailable>, username=<unavailable>) at postgres.c:0
    frame #25: 0x000000010bf6a126 postgres`BackendRun(port=0x000000010c32ba6a) at postmaster.c:4448:2
    frame #26: 0x000000010bf699e9 postgres`BackendStartup(port=<unavailable>) at postmaster.c:4139:3
    frame #27: 0x000000010bf691c5 postgres`ServerLoop at postmaster.c:1704:7
    frame #28: 0x000000010bf67277 postgres`PostmasterMain(argc=3, argv=0x00007f9669403230) at postmaster.c:1377:11
    frame #29: 0x000000010bed1316 postgres`main(argc=3, argv=0x00007f9669403230) at main.c:228:3
    frame #30: 0x00007fff602683d5 libdyld.dylib`start + 1

Where, the blocking happens on

(lldb) print get_rel_name(2663)
(char *) $3 = 0x00007f966c81b810 "pg_class_relname_nsp_index"