pgcopydb
pgcopydb copied to clipboard
Published
20 hours ago •
dimitri
dimitri
Parsing error with test_decoding plugin
Facing parsing issues with test_decoding plugin in the below error message:
2023-06-24 11:41:47 20041 INFO pgsql.c:4267 Reported write_lsn 24B1/F40FA20, flush_lsn 0/0, replay_lsn 0/0
2023-06-24 11:41:55 20042 ERROR ld_test_decoding.c:909 Failed to parse decoding message for UPDATE on table "public"."audition" which is not in our catalogs
2023-06-24 11:41:55 20042 ERROR ld_test_decoding.c:500 Failed to parse UPDATE new-tuple columns for logical message table public.audition: UPDATE: audition_id[text]:'5127494f-361f-4774-837a-24ca89f6916f' person_id[bigint]:96476415 created_ts[timestamp with time zone]:'2023-06-23 03:58:26.044+00' last_seen[timestamp with time zone]:'2023-06-24 11:41:37.277+00' correlation_id[text]:'4dcbe359-ecd5-461e-ba9e-dc5508a7d611:2420286' context_guid[text]:'a9cab2e8-8adf-42cd-8108-fa01137b0aa9' request_type[integer]:1 segmentation_name[text]:null audition_hash[text]:'e002a33d4f5e4b447d7ad4f1640e813f95ee34355be5fbf81014c63229ce9b16' request_hash[text]:'c524c7407b02e2f979e98ea62c5de38761afeae582108f64f8075731f99f2e92' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAAErT7S+y9a6YHQPasU/Ql0ON1L1RzR5CsSbC8DdTlL/0hUjT/0DasHqC/YATpwyelDeOL/50+759V8m5IFq6+FUe4nZIASv1vwKukJRLrNU0D8ealw1sKBt3KmnqnzBVVHNG+sMs8u1e/eFGGdNPbMApzF0A5iVX8JZDie089U3/GHxU+67ocahM493QokX2ST59TzJu1NeziG62TNykLVs=' complete_audition[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null
2023-06-24 11:41:55 20042 ERROR ld_test_decoding.c:271 Failed to parse test_decoding UPDATE message: table public.audition: UPDATE: audition_id[text]:'5127494f-361f-4774-837a-24ca89f6916f' person_id[bigint]:96476415 created_ts[timestamp with time zone]:'2023-06-23 03:58:26.044+00' last_seen[timestamp with time zone]:'2023-06-24 11:41:37.277+00' correlation_id[text]:'4dcbe359-ecd5-461e-ba9e-dc5508a7d611:2420286' context_guid[text]:'a9cab2e8-8adf-42cd-8108-fa01137b0aa9' request_type[integer]:1 segmentation_name[text]:null audition_hash[text]:'e002a33d4f5e4b447d7ad4f1640e813f95ee34355be5fbf81014c63229ce9b16' request_hash[text]:'c524c7407b02e2f979e98ea62c5de38761afeae582108f64f8075731f99f2e92' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAAErT7S+y9a6YHQPasU/Ql0ON1L1RzR5CsSbC8DdTlL/0hUjT/0DasHqC/YATpwyelDeOL/50+759V8m5IFq6+FUe4nZIASv1vwKukJRLrNU0D8ealw1sKBt3KmnqnzB
VVHNG+sMs8u1e/eFGGdNPbMApzF0A5iVX8JZDie089U3/GHxU+67ocahM493QokX2ST59TzJu1NeziG62TNykLVs=' complete_audition[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null
2023-06-24 11:41:55 20042 ERROR ld_transform.c:1054 Failed to parse test_decoding message, see above for details
2023-06-24 11:41:55 20042 ERROR ld_transform.c:766 Failed to parse JSON message: {"action":"U","xid":"0","lsn":"24B1/ECE6900","timestamp":"2023-06-24 11:41:37.360240+0000","message":"table public.audition: UPDATE: audition_id[text]:'5127494f-361f-4774-837a-24ca89f6916f' person_id[bigint]:96476415 created_ts[timestamp with time zone]:'2023-06-23 03:58:26.044+00' last_seen[timestamp with time zone]:'2023-06-24 11:41:37.277+00' correlation_id[text]:'4dcbe359-ecd5-461e-ba9e-dc5508a7d611:2420286' context_guid[text]:'a9cab2e8-8adf-42cd-8108-fa01137b0aa9' request_type[integer]:1 segmentation_name[text]:null audition_hash[text]:'e002a33d4f5e4b447d7ad4f1640e813f95ee34355be5fbf81014c63229ce9b16' request_hash[text]:'c524c7407b02e2f979e98ea62c5de38761afeae582108f64f8075731f99f2e92' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAAErT7S+y9a6YHQPasU\/Ql0ON1L1RzR5CsSbC8DdTlL\/0hUjT\/0DasHqC\/YATpwyelDeOL\/50+759V8m5IFq6+FUe4nZIASv1vwKukJRLrNU0D8ealw1sKBt3KmnqnzBVVHNG+sMs8u1e\/eFGGdNPbMApzF0A5iVX8JZDie089U3\/GHxU+67ocahM493QokX2ST59TzJu1NeziG62TNykLVs=' complete_audition[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null"}
2023-06-24 11:41:57 20041 INFO pgsql.c:4267 Reported write_lsn 24B1/1034A5A0, flush_lsn 24B1/F40FA20, replay_lsn 0/0
2023-06-24 11:42:04 20038 INFO pgcmd.c:831 /usr/bin/pg_restore --dbname postgres://[email protected]:5432/dreamer --single-transaction --clean --if-exists --no-comments --no-acl --exclude-schema admin --use-list /tmp/pgcopydb/schema/pre.list /tmp/pgcopydb/schema/pre.dump
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "restore-list-name": ""
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: }
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: },
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: {
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore:
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 warning: line ignored: "oid": 7231181,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "schema": "public",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "name": "idx_dream_number",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "isPrimary": false,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "isUnique": false,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "columns": "dream_number",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "sql": "CREATE INDEX idx_dream_number ON public.dream_pony USING btree (dream_number)",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "restore-list-name": "public idx_dream_number dreamer",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "table": {
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "oid": 6601056,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "schema": "public",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "name": "dream_pony"
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: }
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: war
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 ning: line ignored: },
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: {
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "oid": 16486,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "schema": "public",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "name": "play_pkey",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "isPrimary": true,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "isUnique": true,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "columns": "id",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "sql": "CREATE UNIQUE INDEX play_pkey ON public.play_evolutions USING btree (id)",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "restore-list-name": "public play_evo<F6>
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "restore-list-name": "public play_pkey dreamer",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "table": {
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "oid": 16428,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "schema": "public",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: war
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 ning: line ignored: "name": "play"
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: },
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "constraint": {
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "oid": 16487,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "name": "play_pkey",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "sql": "PRIMARY KEY (id)",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "restore-list-name": ""
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: }
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: },
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: {
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "oid": 16484,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "schema": "public",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "name": "play_lock_pkey",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "isPrimary": true,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "isUnique": true,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "columns": "lock",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "sql": "CREATE UNIQUE INDEX play_lock_pkey ON public.play_lock USING btree (lock)",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "restore-list-name": "public play_lock_pkey dreamer",
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "table": {
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "oid": 16434,
2023-06-24 11:42:04 20038 ERROR string_utils.c:603 pg_restore: warning: line ignored: "schema": <F5>
2023-06-24 11:42:05 20038 INFO indexes.c:30 STEP 6: starting 4 CREATE INDEX processes
2023-06-24 11:42:05 20038 INFO indexes.c:31 STEP 7: constraints are built by the CREATE INDEX processes
2023-06-24 11:42:05 20047 INFO table-data.c:354 STEP 4: starting 4 table data COPY processes
2023-06-24 11:42:05 20038 INFO vacuum.c:32 STEP 8: starting 4 VACUUM processes
2023-06-24 11:42:05 20038 INFO blobs.c:29 STEP 5: copy Large Objects (BLOBs) in 1 sub-process
2023-06-24 11:42:05 20038 INFO sequences.c:102 STEP 9: reset sequences values
2023-06-24 11:42:05 20061 INFO sequences.c:168 Reset sequences values on the target database
2023-06-24 11:42:05 20060 INFO pgsql.c:3084 Copying large objects
2023-06-24 11:42:07 20041 INFO pgsql.c:4267 Reported write_lsn 24B1/114468E0, flush_lsn 24B1/1034A5A0, replay_lsn 0/0
2023-06-24 11:42:17 20041 INFO pgsql.c:4267 Reported write_lsn 24B1/1277A3F8, flush_lsn 24B1/114468E0, replay_lsn 0/0
2023-06-24 11:42:27 20041 INFO pgsql.c:4267 Reported write_lsn 24B1/13615208, flush_lsn 24B1/1277A3F8, replay_lsn 0/0
2023-06-24 11:42:33 20042 ERROR ld_test_decoding.c:909 Failed to parse decoding message for UPDATE on table "public"."audition" which is not in our catalogs
2023-06-24 11:42:33 20042 ERROR ld_test_decoding.c:500 Failed to parse UPDATE new-tuple columns for logical message table public.audition: UPDATE: audition_id[text]:'9f5d6e6a-3aab-4dac-912c-e97c80d47a96' person_id[bigint]:102115349489 created_ts[timestamp with time zone]:'2023-06-23 03:58:32.582+00' last_seen[timestamp with time zone]:'2023-06-24 11:41:55.73+00' correlation_id[text]:'4dcbe359-ecd5-461e-ba9e-dc5508a7d611:2420354' context_guid[text]:'46e5cd4a-dbb3-49bb-8335-74885c478b6a' request_type[integer]:1 segmentation_name[text]:null audition_hash[text]:'f05827f63aaca322ba9c60d2875ca457ae54fb91db354a1ddc15d42ec2214b45' request_hash[text]:'81faf64180ebe597eecd95a88a7494e201d20ca132efd3a2ee12f722a9a00cce' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAANxjjxgLmYL6WgyCiUU70Jru0N+nRwd56D19IXKZFKTti295KeMVRXmjbwt+wU+OGvY9JBVvumGuJCzTISPe/mQhsCJl8M/QU6yKURILpzaQrZxVVbgOjToUouXG04rAl9HvVoPq93odzUC2Ow88NAmV7I7pBp+s1XLWC3i2HJvvCioJYBddQ6g40R3ramA0kI5XS3USM6ZkmdE=' complete_audition[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null
2023-06-24 11:42:33 20042 ERROR ld_test_decoding.c:271 Failed to parse test_decoding UPDATE message: table public.audition: UPDATE: audition_id[text]:'9f5d6e6a-3aab-4dac-912c-e97c80d47a96' person_id[bigint]:102115349489 created_ts[timestamp with time zone]:'2023-06-23 03:58:32.582+00' last_seen[timestamp with time zone]:'2023-06-24 11:41:55.73+00' correlation_id[text]:'4dcbe359-ecd5-461e-ba9e-dc5508a7d611:2420354' context_guid[text]:'46e5cd4a-dbb3-49bb-8335-74885c478b6a' request_type[integer]:1 segmentation_name[text]:null audition_hash[text]:'f05827f63aaca322ba9c60d2875ca457ae54fb91db354a1ddc15d42ec2214b45' request_hash[text]:'81faf64180ebe597eecd95a88a7494e201d20ca132efd3a2ee12f722a9a00cce' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAANxjjxgLmYL6WgyCiUU70Jru0N+nRwd56D19IXKZFKTti295KeMVRXmjbwt+wU+OGvY9JBVvumGuJCzTISPe/mQhsCJl8M/QU6yKURILpzaQrZxVVbgOjToUouXG04rAl9HvVoPq93odzUC2Ow88NAmV7I7pBp+s1XLWC3i2HJvvCioJYBddQ6g40R3ramA0kI5XS3USM6ZkmdE=' complete_audition[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null
2023-06-24 11:42:33 20042 ERROR ld_transform.c:1054 Failed to parse test_decoding message, see above for details
2023-06-24 11:42:33 20042 ERROR ld_transform.c:766 Failed to parse JSON message: {"action":"U","xid":"0","lsn":"24B1/100121A8","timestamp":"2023-06-24 11:41:55.738675+0000","message":"table public.audition: UPDATE: audition_id[text]:'9f5d6e6a-3aab-4dac-912c-e97c80d47a96' person_id[bigint]:102115349489 created_ts[timestamp with time zone]:'2023-06-23 03:58:32.582+00' last_seen[timestamp with time zone]:'2023-06-24 11:41:55.73+00' correlation_id[text]:'4dcbe359-ecd5-461e-ba9e-dc5508a7d611:2420354' context_guid[text]:'46e5cd4a-dbb3-49bb-8335-74885c478b6a' request_type[integer]:1 segmentation_name[text]:null audition_hash[text]:'f05827f63aaca322ba9c60d2875ca457ae54fb91db354a1ddc15d42ec2214b45' request_hash[text]:'81faf64180ebe597eecd95a88a7494e201d20ca132efd3a2ee12f722a9a00cce' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAANxjjxgLmYL6WgyCiUU70Jru0N+nRwd56D19IXKZFKTti295KeMVRXmjbwt+wU+OGvY9JBVvumGuJCzTISPe\/mQhsCJl8M\/QU6yKURILpzaQrZxVVbgOjToUouXG04rAl9HvVoPq93odzUC2Ow88NAmV7I7pBp+s1XLWC3i2HJvvCioJYBddQ6g40R3ramA0kI5XS3USM6ZkmdE=' complete_audition[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null"}
source version: postgres 11 target version: postgres 13
command:
/usr/lib/postgresql/15/bin/pgcopydb clone --table-jobs 4 --index-jobs 4 --drop-if-exists --follow --plugin test_decoding --no-acl --no-comments --skip-extensions --filter /home/user/ignore.txt --source "host=dream-db-11.cdnmzeaj1lfr.us-east-2.rds.amazonaws.com port=5432 dbname=dreamer user=admin" --target "host=dream-db.cdnmzeaj1lfr.us-east-2.rds.amazonaws.com port=5432 dbname=dreamer user=admin"
Hi @ulo23k ; thanks for opening this issue. Is it possible that table public.audition is filtered-out in your setup? That could explain why it's not in our internal catalogs, and we might want to ignore the activity entirely in that case too.
Failed to parse decoding message for UPDATE on table "public"."audition" which is not in our catalogs
Thanks for the quick response @dimitri. I did not filter out the "public"."audition" in my setup. These are the contents of my filter file:
[exclude-schema]
admin
Okay. Is there a way that you can share a test-case that reproduces the problem? Maybe a schema and some data inspired from your actual database without having to leak information in the open?
Hi @dimitri Thanks for the response. there is no real way for me to create a test with some test data because I'm already using test data to begin with. I pulled the latest commit and tried the test again with test_decoding plugin and this is the below output.
2023-07-04 23:08:36 66872 INFO main.c:163 Running pgcopydb version 0.12.6.gba7df80 from "/usr/lib/postgresql/15/bin/pgcopydb"
2023-07-04 23:08:36 66872 INFO cli_common.c:1186 [SOURCE] Copying database from "postgres://[email protected]:5432/dreamliner"
2023-07-04 23:08:36 66872 INFO cli_common.c:1187 [TARGET] Copying database into "postgres://[email protected]:5432/dreamliner"
2023-07-04 23:08:36 66872 INFO pgsql.c:3563 Created logical replication slot "pgcopydb" with plugin "test_decoding" at 2553/98FC5F0 and exported snapshot 000000F5-000ECCDF-1
2023-07-04 23:08:36 66872 INFO ld_stream.c:2462 create schema if not exists pgcopydb
2023-07-04 23:08:36 66872 INFO ld_stream.c:2462 drop table if exists pgcopydb.sentinel
2023-07-04 23:08:36 66872 WARN pgsql.c:840 NOTICE: table "sentinel" does not exist, skipping
2023-07-04 23:08:36 66872 INFO ld_stream.c:2462 create table pgcopydb.sentinel(startpos pg_lsn, endpos pg_lsn, apply bool, write_lsn pg_lsn, flush_lsn pg_lsn, replay_lsn pg_lsn)
2023-07-04 23:08:36 66872 INFO ld_stream.c:2371 Created logical replication origin "pgcopydb" at LSN 2553/98FC5F0
2023-07-04 23:08:36 66876 INFO cli_clone_follow.c:506 STEP 1: fetch source database tables, indexes, and sequences
2023-07-04 23:08:36 66876 INFO copydb_schema.c:133 Fetched information for 9 extensions
2023-07-04 23:08:36 66880 INFO ld_apply.c:307 Waiting until the pgcopydb sentinel apply is enabled
2023-07-04 23:08:36 66878 INFO ld_stream.c:556 Resuming streaming at LSN 2553/98FC5F0 from replication slot "pgcopydb"
2023-07-04 23:08:36 66876 INFO copydb_schema.c:419 Fetched information for 7 tables, with an estimated total of 311 million tuples and 756 GB
2023-07-04 23:08:36 66876 INFO copydb_schema.c:445 Fetched information for 20 indexes
2023-07-04 23:08:36 66876 INFO sequences.c:39 Fetching information for 2 sequences
2023-07-04 23:08:36 66878 INFO pgsql.c:4276 Reported write_lsn 2553/98FC5F0, flush_lsn 2553/98FC5F0, replay_lsn 0/0
2023-07-04 23:08:36 66876 INFO cli_clone_follow.c:523 STEP 2: dump the source database schema (pre/post data)
2023-07-04 23:08:36 66876 INFO pgcmd.c:447 /usr/bin/pg_dump -Fc --snapshot 000000F5-000ECCDF-1 --section pre-data --exclude-schema admin --file /tmp/pgcopydb/schema/pre.dump postgres://master@dreamliner-pg11-prod-db.cdnmzeaj1lha.us-east-1.rds.amazonaws.com:5432/dreamliner
2023-07-04 23:08:36 66876 INFO pgcmd.c:447 /usr/bin/pg_dump -Fc --snapshot 000000F5-000ECCDF-1 --section post-data --exclude-schema admin --file /tmp/pgcopydb/schema/post.dump postgres://master@dreamliner-pg11-prod-db.cdnmzeaj1lha.us-east-1.rds.amazonaws.com:5432/dreamliner
2023-07-04 23:08:36 66876 INFO cli_clone_follow.c:535 STEP 3: restore the pre-data section to the target database
2023-07-04 23:08:36 66876 INFO dump_restore.c:198 Drop tables on the target database, per --drop-if-exists
2023-07-04 23:08:36 66876 INFO pgcmd.c:855 /usr/bin/pg_restore --dbname postgres://master@dreamliner-pg13-prod-db.cdnmzeaj1lha.us-east-1.rds.amazonaws.com:5432/dreamliner --single-transaction --clean --if-exists --no-comments --no-acl --exclude-schema admin --use-list /tmp/pgcopydb/schema/pre.list /tmp/pgcopydb/schema/pre.dump
2023-07-04 23:08:36 66876 INFO indexes.c:30 STEP 6: starting 4 CREATE INDEX processes
2023-07-04 23:08:36 66876 INFO indexes.c:31 STEP 7: constraints are built by the CREATE INDEX processes
2023-07-04 23:08:36 66885 INFO table-data.c:354 STEP 4: starting 4 table data COPY processes
2023-07-04 23:08:36 66876 INFO vacuum.c:32 STEP 8: starting 4 VACUUM processes
2023-07-04 23:08:36 66876 INFO blobs.c:29 STEP 5: copy Large Objects (BLOBs) in 1 sub-process
2023-07-04 23:08:36 66876 INFO sequences.c:102 STEP 9: reset sequences values
2023-07-04 23:08:36 66899 INFO sequences.c:168 Reset sequences values on the target database
2023-07-04 23:08:37 66898 INFO pgsql.c:3092 Copying large objects
2023-07-04 23:08:46 66878 INFO pgsql.c:4276 Reported write_lsn 2553/9A3E3A8, flush_lsn 2553/98FC5F0, replay_lsn 0/0
2023-07-04 23:08:56 66878 INFO pgsql.c:4276 Reported write_lsn 2553/9C45888, flush_lsn 2553/9A3E3A8, replay_lsn 0/0
2023-07-04 23:09:06 66878 INFO pgsql.c:4276 Reported write_lsn 2553/9E00258, flush_lsn 2553/9C45888, replay_lsn 0/0
2023-07-04 23:09:16 66878 INFO pgsql.c:4276 Reported write_lsn 2553/9F96940, flush_lsn 2553/9E00258, replay_lsn 0/0
2023-07-04 23:09:26 66878 INFO pgsql.c:4276 Reported write_lsn 2553/A10A260, flush_lsn 2553/9F96940, replay_lsn 0/0
2023-07-04 23:09:30 66879 ERROR ld_test_decoding.c:909 Failed to parse decoding message for UPDATE on table "public"."audition" which is not in our catalogs
2023-07-04 23:09:30 66879 ERROR ld_test_decoding.c:500 Failed to parse UPDATE new-tuple columns for logical message table public.audition: UPDATE: audit_id[text]:'bd180bb3-8590-4770-878b-7e7dbcc5e0d6' person_id[bigint]:70163495 created_ts[timestamp with time zone]:'2023-07-02 16:39:57.057+00' last_seen[timestamp with time zone]:'2023-07-04 23:08:36.295+00' correlation_id[text]:'N85LYR2fyYxWoE-arcade_edge_dashboard' context_guid[text]:'87ddc989-7d58-4e54-8f51-58a362764e8e' request_type[integer]:3 segmentation_name[text]:'UHC Rewards Gift Card' audit_hash[text]:'8867923259c6f1802f5880f80937facdcf149584e47302de806466f9fa45c7d6' request_hash[text]:'b82d4524df50141cb63c6f5eb53262f9cbc3066b64d659bb8680db2dff8839e8' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAAOfRrQ1r6p46+vZAD8hOd5ZhifhFPL1RPO67w3V5jCjFwj6Y4m3DqUNSlPVQXJByLH17C4nj4LNG0jYIr3VJmOGlSKZTUwMsUewjFJnCj0zhpjM=' complete_audit[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null
2023-07-04 23:09:30 66879 ERROR ld_test_decoding.c:271 Failed to parse test_decoding UPDATE message: table public.audition: UPDATE: audit_id[text]:'bd180bb3-8590-4770-878b-7e7dbcc5e0d6' person_id[bigint]:70163495 created_ts[timestamp with time zone]:'2023-07-02 16:39:57.057+00' last_seen[timestamp with time zone]:'2023-07-04 23:08:36.295+00' correlation_id[text]:'N85LYR2fyYxWoE-arcade_edge_dashboard' context_guid[text]:'87ddc989-7d58-4e54-8f51-58a362764e8e' request_type[integer]:3 segmentation_name[text]:'UHC Rewards Gift Card' audit_hash[text]:'8867923259c6f1802f5880f80937facdcf149584e47302de806466f9fa45c7d6' request_hash[text]:'b82d4524df50141cb63c6f5eb53262f9cbc3066b64d659bb8680db2dff8839e8' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAAOfRrQ1r6p46+vZAD8hOd5ZhifhFPL1RPO67w3V5jCjFwj6Y4m3DqUNSlPVQXJByLH17C4nj4LNG0jYIr3VJmOGlSKZTUwMsUewjFJnCj0zhpjM=' complete_audit[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null
2023-07-04 23:09:30 66879 ERROR ld_transform.c:1115 Failed to parse test_decoding message, see above for details
2023-07-04 23:09:30 66879 ERROR ld_transform.c:815 Failed to parse JSON message: {"action":"U","xid":"0","lsn":"2553/9914C50","timestamp":"2023-07-04 23:08:36.343566+0000","message":"table public.audition: UPDATE: audit_id[text]:'bd180bb3-8590-4770-878b-7e7dbcc5e0d6' person_id[bigint]:70163495 created_ts[timestamp with time zone]:'2023-07-02 16:39:57.057+00' last_seen[timestamp with time zone]:'2023-07-04 23:08:36.295+00' correlation_id[text]:'N85LYR2fyYxWoE-arcade_edge_dashboard' context_guid[text]:'87ddc989-7d58-4e54-8f51-58a362764e8e' request_type[integer]:3 segmentation_name[text]:'UHC Rewards Gift Card' audit_hash[text]:'8867923259c6f1802f5880f80937facdcf149584e47302de806466f9fa45c7d6' request_hash[text]:'b82d4524df50141cb63c6f5eb53262f9cbc3066b64d659bb8680db2dff8839e8' complete_request[text]:'UkFMWUhMVEgAAAAAAAAAAOfRrQ1r6p46+vZAD8hOd5ZhifhFPL1RPO67w3V5jCjFwj6Y4m3DqUNSlPVQXJByLH17C4nj4LNG0jYIr3VJmOGlSKZTUwMsUewjFJnCj0zhpjM=' complete_audit[bytea]:unchanged-toast-datum event_date[timestamp with time zone]:null"}
2023-07-04 23:09:36 66878 INFO pgsql.c:4276 Reported write_lsn 2553/C10E658, flush_lsn 2553/A10A260, replay_lsn 0/0
2023-07-04 23:09:46 66878 INFO pgsql.c:4276 Reported write_lsn 2553/C29B6B8, flush_lsn 2553/C10E658, replay_lsn 0/0
2023-07-04 23:09:56 66878 INFO pgsql.c:4276 Reported write_lsn 2553/C3E9978, flush_lsn 2553/C29B6B8, replay_lsn 0/0
2023-07-04 23:10:07 66878 INFO pgsql.c:4276 Reported write_lsn 2553/C55CB08, flush_lsn 2553/C3E9978, replay_lsn 0/0
2023-07-04 23:10:17 66878 INFO pgsql.c:4276 Reported write_lsn 2553/C7281D8, flush_lsn 2553/C55CB08, replay_lsn 0/0
2023-07-04 23:10:27 66878 INFO pgsql.c:4276 Reported write_lsn 2553/C8C6E60, flush_lsn 2553/C7281D8, replay_lsn 0/0
2023-07-04 23:10:37 66878 INFO pgsql.c:4276 Reported write_lsn 2553/C9E4F00, flush_lsn 2553/C8C6E60, replay_lsn 0/0
2023-07-04 23:10:47 66878 INFO pgsql.c:4276 Reported write_lsn 2553/CB971E8, flush_lsn 2553/C9E4F00, replay_lsn 0/0
2023-07-04 23:10:57 66878 INFO pgsql.c:4276 Reported write_lsn 2553/CE01C20, flush_lsn 2553/CB971E8, replay_lsn 0/0
2023-07-04 23:11:07 66878 INFO pgsql.c:4276 Reported write_lsn 2553/CFBFBB8, flush_lsn 2553/CE01C20, replay_lsn 0/0
2023-07-04 23:11:17 66878 INFO pgsql.c:4276 Reported write_lsn 2553/D25AC90, flush_lsn 2553/CFBFBB8, replay_lsn 0/0
2023-07-04 23:11:27 66878 INFO pgsql.c:4276 Reported write_lsn 2553/D47D5C8, flush_lsn 2553/D25AC90, replay_lsn 0/0
2023-07-04 23:11:37 66878 INFO pgsql.c:4276 Reported write_lsn 2553/D630C78, flush_lsn 2553/D47D5C8, replay_lsn 0/0
2023-07-04 23:11:47 66878 INFO pgsql.c:4276 Reported write_lsn 2553/D887900, flush_lsn 2553/D630C78, replay_lsn 0/0
2023-07-04 23:11:58 66878 INFO pgsql.c:4276 Reported write_lsn 2553/DA8FA38, flush_lsn 2553/D887900, replay_lsn 0/0
2023-07-04 23:12:08 66878 INFO pgsql.c:4276 Reported write_lsn 2553/DC4C2D0, flush_lsn 2553/DA8FA38, replay_lsn 0/0
2023-07-04 23:12:18 66878 INFO pgsql.c:4276 Reported write_lsn 2553/DE3C228, flush_lsn 2553/DC4C2D0, replay_lsn 0/0
2023-07-04 23:12:28 66878 INFO pgsql.c:4276 Reported write_lsn 2553/DFE57B8, flush_lsn 2553/DE3C228, replay_lsn 0/0
2023-07-04 23:12:38 66878 INFO pgsql.c:4276 Reported write_lsn 2553/E1BB338, flush_lsn 2553/DFE57B8, replay_lsn 0/0
2023-07-04 23:12:48 66878 INFO pgsql.c:4276 Reported write_lsn 2553/E31F930, flush_lsn 2553/E1BB338, replay_lsn 0/0
2023-07-04 23:12:58 66878 INFO pgsql.c:4276 Reported write_lsn 2553/E5782D8, flush_lsn 2553/E31F930, replay_lsn 0/0
2023-07-04 23:13:08 66878 INFO pgsql.c:4276 Reported write_lsn 2553/E777518, flush_lsn 2553/E5782D8, replay_lsn 0/0
2023-07-04 23:13:18 66878 INFO pgsql.c:4276 Reported write_lsn 2553/E8D9B48, flush_lsn 2553/E777518, replay_lsn 0/0
2023-07-04 23:13:28 66878 INFO pgsql.c:4276 Reported write_lsn 2553/EA6F438, flush_lsn 2553/E8D9B48, replay_lsn 0/0
2023-07-04 23:13:38 66878 INFO pgsql.c:4276 Reported write_lsn 2553/EC83DA0, flush_lsn 2553/EA6F438, replay_lsn 0/0
2023-07-04 23:13:48 66878 INFO pgsql.c:4276 Reported write_lsn 2553/EEA55C8, flush_lsn 2553/EC83DA0, replay_lsn 0/0
2023-07-04 23:13:58 66878 INFO pgsql.c:4276 Reported write_lsn 2553/F041AB0, flush_lsn 2553/EEA55C8, replay_lsn 0/0
2023-07-04 23:14:08 66878 INFO pgsql.c:4276 Reported write_lsn 2553/F196310, flush_lsn 2553/F041AB0, replay_lsn 0/0
2023-07-04 23:14:19 66878 INFO pgsql.c:4276 Reported write_lsn 2553/F34AE40, flush_lsn 2553/F196310, replay_lsn 0/0
2023-07-04 23:14:29 66878 INFO pgsql.c:4276 Reported write_lsn 2553/F4F5C90, flush_lsn 2553/F34AE40, replay_lsn 0/0
2023-07-04 23:14:30 66879 ERROR ld_transform.c:977 Failed to parse BEGIN: transaction already in progress
2023-07-04 23:14:30 66879 ERROR ld_transform.c:815 Failed to parse JSON message: {"action":"B","xid":"1862589495","lsn":"2553/C000028","timestamp":"2023-07-04 23:09:30.279215+0000","message":"BEGIN 1862589495"}
2023-07-04 23:14:39 66878 INFO pgsql.c:4276 Reported write_lsn 2553/10154628, flush_lsn 2553/F4F5C90, replay_lsn 0/0
2023-07-04 23:14:49 66878 INFO pgsql.c:4276 Reported write_lsn 2553/1024F6D0, flush_lsn 2553/10154628, replay_lsn 0/0
2023-07-04 23:14:59 66878 INFO pgsql.c:4276 Reported write_lsn 2553/10457888, flush_lsn 2553/1024F6D0, replay_lsn 0/0
2023-07-04 23:15:09 66878 INFO pgsql.c:4276 Reported write_lsn 2553/105F2ED0, flush_lsn 2553/10457888, replay_lsn 0/0
2023-07-04 23:15:19 66878 INFO pgsql.c:4276 Reported write_lsn 2553/107142E8, flush_lsn 2553/105F2ED0, replay_lsn 0/0
2023-07-04 23:15:29 66878 INFO pgsql.c:4276 Reported write_lsn 2553/108D71D8, flush_lsn 2553/107142E8, replay_lsn 0/0
2023-07-04 23:15:39 66878 INFO pgsql.c:4276 Reported write_lsn 2553/10AEA7F0, flush_lsn 2553/108D71D8, replay_lsn 0/0
2023-07-04 23:15:49 66878 INFO pgsql.c:4276 Reported write_lsn 2553/10C70ED0, flush_lsn 2553/10AEA7F0, replay_lsn 0/0
2023-07-04 23:15:59 66878 INFO pgsql.c:4276 Reported write_lsn 2553/10DAEC90, flush_lsn 2553/10C70ED0, replay_lsn 0/0
2023-07-04 23:16:09 66878 INFO pgsql.c:4276 Reported write_lsn 2553/10ED9848, flush_lsn 2553/10DAEC90, replay_lsn 0/0
2023-07-04 23:16:19 66878 INFO pgsql.c:4276 Reported write_lsn 2553/110C2B50, flush_lsn 2553/10ED9848, replay_lsn 0/0
2023-07-04 23:16:29 66878 INFO pgsql.c:4276 Reported write_lsn 2553/11287A88, flush_lsn 2553/110C2B50, replay_lsn 0/0
2023-07-04 23:16:39 66878 INFO pgsql.c:4276 Reported write_lsn 2553/1145B718, flush_lsn 2553/11287A88, replay_lsn 0/0
2023-07-04 23:16:49 66878 INFO pgsql.c:4276 Reported write_lsn 2553/11582C30, flush_lsn 2553/1145B718, replay_lsn 0/0
2023-07-04 23:16:59 66878 INFO pgsql.c:4276 Reported write_lsn 2553/11710B08, flush_lsn 2553/11582C30, replay_lsn 0/0
2023-07-04 23:17:09 66878 INFO pgsql.c:4276 Reported write_lsn 2553/118A3590, flush_lsn 2553/11710B08, replay_lsn 0/0
2023-07-04 23:17:19 66878 INFO pgsql.c:4276 Reported write_lsn 2553/11A93200, flush_lsn 2553/118A3590, replay_lsn 0/0
2023-07-04 23:17:29 66878 INFO pgsql.c:4276 Reported write_lsn 2553/11BB0BA0, flush_lsn 2553/11A93200, replay_lsn 0/0
2023-07-04 23:17:40 66878 INFO pgsql.c:4276 Reported write_lsn 2553/11D142E0, flush_lsn 2553/11BB0BA0, replay_lsn 0/0
2023-07-04 23:17:50 66878 INFO pgsql.c:4276 Reported write_lsn 2553/11EE9510, flush_lsn 2553/11D142E0, replay_lsn 0/0
2023-07-04 23:18:00 66878 INFO pgsql.c:4276 Reported write_lsn 2553/12100F28, flush_lsn 2553/11EE9510, replay_lsn 0/0
2023-07-04 23:18:10 66878 INFO pgsql.c:4276 Reported write_lsn 2553/1221BF98, flush_lsn 2553/12100F28, replay_lsn 0/0
2023-07-04 23:18:20 66878 INFO pgsql.c:4276 Reported write_lsn 2553/12310400, flush_lsn 2553/1221BF98, replay_lsn 0/0
2023-07-04 23:18:30 66878 INFO pgsql.c:4276 Reported write_lsn 2553/1246FF70, flush_lsn 2553/12310400, replay_lsn 0/0
2023-07-04 23:18:40 66878 INFO pgsql.c:4276 Reported write_lsn 2553/12611A48, flush_lsn 2553/1246FF70, replay_lsn 0/0
2023-07-04 23:18:50 66878 INFO pgsql.c:4276 Reported write_lsn 2553/127CD970, flush_lsn 2553/12611A48, replay_lsn 0/0
2023-07-04 23:19:00 66878 INFO pgsql.c:4276 Reported write_lsn 2553/12938760, flush_lsn 2553/127CD970, replay_lsn 0/0
2023-07-04 23:19:10 66878 INFO pgsql.c:4276 Reported write_lsn 2553/12AD6550, flush_lsn 2553/12938760, replay_lsn 0/0
2023-07-04 23:19:20 66878 INFO pgsql.c:4276 Reported write_lsn 2553/12CD6830, flush_lsn 2553/12AD6550, replay_lsn 0/0
2023-07-04 23:19:30 66879 ERROR ld_transform.c:977 Failed to parse BEGIN: transaction already in progress
2023-07-04 23:19:30 66879 ERROR ld_transform.c:815 Failed to parse JSON message: {"action":"B","xid":"1862594614","lsn":"2553/10000028","timestamp":"2023-07-04 23:14:30.78838+0000","message":"BEGIN 1862594614"}
2023-07-04 23:19:30 66878 INFO pgsql.c:4276 Reported write_lsn 2553/14004EE8, flush_lsn 2553/12CD6830, replay_lsn 0/0
2023-07-04 23:19:40 66878 INFO pgsql.c:4276 Reported write_lsn 2553/14166D40, flush_lsn 2553/14004EE8, replay_lsn 0/0
2023-07-04 23:19:50 66878 INFO pgsql.c:4276 Reported write_lsn 2553/142C6220, flush_lsn 2553/14166D40, replay_lsn 0/0
2023-07-04 23:20:00 66878 INFO pgsql.c:4276 Reported write_lsn 2553/1440E498, flush_lsn 2553/142C6220, replay_lsn 0/0
2023-07-04 23:20:10 66878 INFO pgsql.c:4276 Reported write_lsn 2553/145A8510, flush_lsn 2553/1440E498, replay_lsn 0/0
2023-07-04 23:20:20 66878 INFO pgsql.c:4276 Reported write_lsn 2553/1470BBA0, flush_lsn 2553/145A8510, replay_lsn 0/0
2023-07-04 23:20:30 66878 INFO pgsql.c:4276 Reported write_lsn 2553/14896940, flush_lsn 2553/1470BBA0, replay_lsn 0/0
2023-07-04 23:20:40 66878 INFO pgsql.c:4276 Reported write_lsn 2553/14A4BEA0, flush_lsn 2553/14896940, replay_lsn 0/0
2023-07-04 23:20:50 66878 INFO pgsql.c:4276 Reported write_lsn 2553/14B56E48, flush_lsn 2553/14A4BEA0, replay_lsn 0/0
(END)
Facing same issue, someone please help on how to proceed.
pgcopydb clone follow -- Failed to parse test_decoding message #668
