pgcopydb
pgcopydb copied to clipboard
dimitri
ERROR: index is already associated with a constraint
Logs from pgcopydb index/constraint worker
2024-06-04T15:46:50.589Z test_db 83 indexes.c NOTICE CREATE UNIQUE INDEX t_volume_adjust_pkey ON u_testdb_00.t_cal_volume_adjust USING btree (vat_nbid);
2024-06-04T15:46:50.589Z test_db 83 pgsql.c SQL [TARGET 28282] CREATE UNIQUE INDEX t_volume_adjust_pkey ON u_testdb_00.t_cal_volume_adjust USING btree (vat_nbid);;
2024-06-04T15:46:50.606Z test_db 83 indexes.c NOTICE ALTER TABLE u_testdb_00.t_cal_volume_adjust ADD CONSTRAINT t_volume_adjust_pkey PRIMARY KEY USING INDEX t_volume_adjust_pkey
2024-06-04T15:46:50.607Z test_db 83 pgsql.c SQL [TARGET 28282] ALTER TABLE u_testdb_00.t_cal_volume_adjust ADD CONSTRAINT t_volume_adjust_pkey PRIMARY KEY USING INDEX t_volume_adjust_pkey;
2024-06-04T15:46:50.663Z test_db 83 indexes.c NOTICE ALTER TABLE u_testdb_00.t_cal_volume_adjust ADD CONSTRAINT t_volume_adjust_pkey PRIMARY KEY USING INDEX t_volume_adjust_pkey
2024-06-04T15:46:50.663Z test_db 83 pgsql.c SQL [TARGET 28282] ALTER TABLE u_testdb_00.t_cal_volume_adjust ADD CONSTRAINT t_volume_adjust_pkey PRIMARY KEY USING INDEX t_volume_adjust_pkey;
2024-06-04T15:46:50.664Z test_db 83 pgsql.c ERROR [TARGET 28282] ERROR: index "t_volume_adjust_pkey" is already associated with a constraint
2024-06-04T15:46:50.667Z test_db 83 pgsql.c ERROR [TARGET 28282] ERROR: index "t_volume_adjust_pkey" is already associated with a constraint
2024-06-04T15:46:50.669Z test_db 83 pgsql.c ERROR [TARGET 28282] SQL query: ALTER TABLE u_testdb_00.t_cal_volume_adjust ADD CONSTRAINT t_volume_adjust_pkey PRIMARY KEY USING INDEX t_volume_adjust_pkey
@apduvuri We need more logs and details related to source DB for this issue
Hi @apduvuri , can you please give the following query a try on source db?
select i.oid, i.qname, i.nspname, i.relname, i.restore_list_name,
i.tableoid, t.qname, t.nspname, t.relname,
isprimary, isunique, columns, i.sql,
c.oid as constraintoid, conname,
condeferrable, condeferred, c.sql as condef
from s_index i
join s_table t on t.oid = i.tableoid
left join s_constraint c on c.indexoid = i.oid
where t.nspname = u_testdb_00 and t.relname = t_cal_volume_adjust;
@rimbi Could you check why we're sending the ALTER_TABLE command twice? (It should only be sent once)
Also let's have more logs for that part of the code where this problem might originate?
Just to confirm: I've also encountered this bug when migrating a Postgres database in follow mode (or online migration as its called in Azure Postgres Migration Service). Near the end of the migration this exact bug occurred. On a second attempt the migration succeeded. So it looks like a race condition / concurrency issue of some kind.
The same error on my side.
From my observation it occurs always when --index-jobs 1 there is no error when I run it with --index-jobs 4.
2025-04-10 16:21:20.808 2015254 ERROR pgsql.c:2330 [TARGET 8136] ERROR: index "receivable_security_concn_limit_pkey" is already associated with a constraint
2025-04-10 16:21:20.809 2015254 ERROR pgsql.c:2330 [TARGET 8136] LINE 1: ... TABLE public.receivable_security_concn_limit ADD CONSTRAINT...
2025-04-10 16:21:20.809 2015254 ERROR pgsql.c:2330 [TARGET 8136] ^
2025-04-10 16:21:20.809 2015254 ERROR pgsql.c:2330 [TARGET 8136] ERROR: index "receivable_security_concn_limit_pkey" is already associated with a constraint
2025-04-10 16:21:20.809 2015254 ERROR pgsql.c:2341 [TARGET 8136] SQL query: ALTER TABLE public.receivable_security_concn_limit ADD CONSTRAINT receivable_security_concn_limit_pkey PRIMARY KEY USING INDEX receivable_security_concn_limit_pkey
2025-04-10 16:21:20.809 2015254 ERROR pgsql.c:2349 [TARGET 8136] SQL params:
2025-04-10 16:21:20.809 2015254 ERROR catalog.c:4268 Failed to iterate over list of indexes, see above for details
2025-04-10 16:21:20.809 2015254 ERROR indexes.c:445 Failed to create constraints for table public.receivable_security_concn_limit
2025-04-10 16:21:20.809 2015254 ERROR indexes.c:301 Failed to create index with oid 19797874, see above for details
2025-04-10 16:21:38.704 2015254 ERROR catalog.c:8004 Failed to execute statement: update summary set done_time_epoch = $1, duration = $2 where pid = $3 and indexoid = $4
2025-04-10 16:21:38.704 2015254 ERROR catalog.c:8005 [SQLite 5] database is locked
2025-04-10 16:21:38.704 2015254 ERROR catalog.c:7977 Failed to execute SQLite query, see above for details
2025-04-10 16:21:38.705 2015254 ERROR indexes.c:301 Failed to create index with oid 19869848, see above for details
2025-04-10 16:21:43.716 2015254 ERROR catalog.c:8004 Failed to execute statement: insert or replace into process( pid, ps_type, ps_title, tableoid, partnum, indexoid)values($1, $2, $3, $4, $5, $6)
...
this part shows many times later too:
2025-04-10 16:47:25.901 2015254 ERROR catalog.c:8005 [SQLite 5] database is locked
2025-04-10 16:47:25.901 2015254 ERROR catalog.c:7977 Failed to execute SQLite query, see above for details
2025-04-10 16:47:25.901 2015254 ERROR indexes.c:397 Failed to track progress in our catalogs, see above for details
2025-04-10 16:47:25.901 2015254 ERROR indexes.c:301 Failed to create index with oid 108607, see above for details
2025-04-10 16:47:30.996 2015254 ERROR catalog.c:8004 Failed to execute statement: insert or replace into process( pid, ps_type, ps_title, tableoid, partnum, indexoid)values($1, $2, $3, $4, $5, $6)
2025-04-10 16:47:30.996 2015254 ERROR catalog.c:8005 [SQLite 5] database is locked
2025-04-10 16:47:30.996 2015254 ERROR catalog.c:7977 Failed to execute SQLite query, see above for details
2025-04-10 16:47:30.996 2015254 ERROR indexes.c:397 Failed to track progress in our catalogs, see above for details
2025-04-10 16:47:30.996 2015254 ERROR indexes.c:301 Failed to create index with oid 108608, see above for details
2025-04-10 16:47:36.222 2015254 ERROR catalog.c:8004 Failed to execute statement: delete from process where pid = $1
2025-04-10 16:47:36.222 2015254 ERROR catalog.c:8005 [SQLite 5] database is locked
2025-04-10 16:47:36.222 2015254 ERROR catalog.c:7977 Failed to execute SQLite query, see above for details
2025-04-10 16:47:36.222 2015254 WARN indexes.c:328 Failed to delete catalog process entry for pid 2015254
2025-04-10 16:47:36.222 2015254 ERROR catalog.c:912 Failed to close "./pgcopy-tmp//schema/source.db":
2025-04-10 16:47:36.222 2015254 ERROR catalog.c:913 [SQLite]: unable to close due to unfinalized statements or unfinished backups
2025-04-10 16:47:36.314 2015243 ERROR copydb.c:767 Sub-process 2015254 exited with code 12
2025-04-10 16:47:36.314 2015243 ERROR indexes.c:123 Some INDEX worker process(es) have exited with error, see above for details
2025-04-10 16:47:36.314 2015243 ERROR indexes.c:59 Failed to create indexes, see above for details
2025-04-10 16:47:36.319 2015215 ERROR copydb.c:767 Sub-process 2015243 exited with code 12
2025-04-10 17:00:58.723 2015215 ERROR table-data.c:207 Some sub-processes have exited with error status, see above for details
2025-04-10 17:00:58.723 2015215 ERROR table-data.c:214 Errors detected, see above for details
2025-04-10 17:00:58.723 2015215 FATAL table-data.c:71 Failed to COPY the data, see above for details
2025-04-10 17:00:58.723 2015215 ERROR cli_clone_follow.c:504 Failed to clone source database, see above for details
2025-04-10 17:00:58.787 2015209 ERROR cli_clone_follow.c:764 clone process 2015215 has terminated [6]
