From 6465f4d97d2135c923986085062a4e6c52d11d2b Mon Sep 17 00:00:00 2001 From: BodoBolero Date: Fri, 8 Nov 2024 17:47:30 +0100 Subject: [PATCH] now run the real bench ingest in two variants --- .github/workflows/benchmarking.yml | 182 ++++++++++++++--------------- 1 file changed, 91 insertions(+), 91 deletions(-) diff --git a/.github/workflows/benchmarking.yml b/.github/workflows/benchmarking.yml index ee829b8dd2..2494dee8d2 100644 --- a/.github/workflows/benchmarking.yml +++ b/.github/workflows/benchmarking.yml @@ -182,104 +182,104 @@ jobs: public.event_names EOF - # - name: Invoke pgcopydb - # env: - # BENCHMARK_INGEST_SOURCE_CONNSTR: ${{ secrets.BENCHMARK_INGEST_SOURCE_CONNSTR }} - # run: | - # export LD_LIBRARY_PATH=${PGCOPYDB_LIB_PATH}:${PG_16_LIB_PATH} - # export PGCOPYDB_SOURCE_PGURI="${BENCHMARK_INGEST_SOURCE_CONNSTR}" - # export PGCOPYDB_TARGET_PGURI="${NEW_PROJECT_CONNSTR}" - # ${PG_CONFIG} --bindir - # ${PGCOPYDB} --version - # ${PGCOPYDB} clone --skip-vacuum --no-owner --no-acl --skip-db-properties --table-jobs 4 \ - # --index-jobs 4 --restore-jobs 4 --split-tables-larger-than 10GB --skip-extensions \ - # --use-copy-binary --filters /tmp/pgcopydb_filter.txt 2>&1 | tee /tmp/pgcopydb_${{ matrix.target_project }}.log + - name: Invoke pgcopydb + env: + BENCHMARK_INGEST_SOURCE_CONNSTR: ${{ secrets.BENCHMARK_INGEST_SOURCE_CONNSTR }} + run: | + export LD_LIBRARY_PATH=${PGCOPYDB_LIB_PATH}:${PG_16_LIB_PATH} + export PGCOPYDB_SOURCE_PGURI="${BENCHMARK_INGEST_SOURCE_CONNSTR}" + export PGCOPYDB_TARGET_PGURI="${NEW_PROJECT_CONNSTR}" + ${PG_CONFIG} --bindir + ${PGCOPYDB} --version + ${PGCOPYDB} clone --skip-vacuum --no-owner --no-acl --skip-db-properties --table-jobs 4 \ + --index-jobs 4 --restore-jobs 4 --split-tables-larger-than 10GB --skip-extensions \ + --use-copy-binary --filters /tmp/pgcopydb_filter.txt 2>&1 | tee /tmp/pgcopydb_${{ matrix.target_project }}.log # create dummy pgcopydb log to test parsing - - name: create dummy log for parser test - run: | - cat << EOF > /tmp/pgcopydb_${{ matrix.target_project }}.log - 2024-11-04 18:00:53.433 500861 INFO main.c:136 Running pgcopydb version 0.17.10.g8361a93 from "/usr/lib/postgresql/17/bin/pgcopydb" - 2024-11-04 18:00:53.434 500861 INFO cli_common.c:1225 [SOURCE] Copying database from "postgres://neondb_owner@ep-bitter-shape-w2c1ir0a.us-east-2.aws.neon.build/neondb?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60" - 2024-11-04 18:00:53.434 500861 INFO cli_common.c:1226 [TARGET] Copying database into "postgres://neondb_owner@ep-icy-union-w25qd5pj.us-east-2.aws.neon.build/ludicrous?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60" - 2024-11-04 18:00:53.442 500861 INFO copydb.c:105 Using work dir "/tmp/pgcopydb" - 2024-11-04 18:00:53.541 500861 INFO snapshot.c:107 Exported snapshot "00000008-00000033-1" from the source database - 2024-11-04 18:00:53.556 500865 INFO cli_clone_follow.c:543 STEP 1: fetch source database tables, indexes, and sequences - 2024-11-04 18:00:54.570 500865 INFO copydb_schema.c:716 Splitting source candidate tables larger than 10 GB - 2024-11-04 18:00:54.570 500865 INFO copydb_schema.c:829 Table public.events is 96 GB large which is larger than --split-tables-larger-than 10 GB, and does not have a unique column of type integer: splitting by CTID - 2024-11-04 18:01:05.538 500865 INFO copydb_schema.c:905 Table public.events is 96 GB large, 10 COPY processes will be used, partitioning on ctid. - 2024-11-04 18:01:05.564 500865 INFO copydb_schema.c:905 Table public.email_transmissions is 27 GB large, 4 COPY processes will be used, partitioning on id. - 2024-11-04 18:01:05.584 500865 INFO copydb_schema.c:905 Table public.lessons is 25 GB large, 4 COPY processes will be used, partitioning on id. - 2024-11-04 18:01:05.605 500865 INFO copydb_schema.c:905 Table public.lesson_users is 16 GB large, 3 COPY processes will be used, partitioning on id. - 2024-11-04 18:01:05.605 500865 INFO copydb_schema.c:761 Fetched information for 26 tables (including 4 tables split in 21 partitions total), with an estimated total of 907 million tuples and 175 GB on-disk - 2024-11-04 18:01:05.687 500865 INFO copydb_schema.c:968 Fetched information for 57 indexes (supporting 25 constraints) - 2024-11-04 18:01:05.753 500865 INFO sequences.c:78 Fetching information for 24 sequences - 2024-11-04 18:01:05.903 500865 INFO copydb_schema.c:1122 Fetched information for 4 extensions - 2024-11-04 18:01:06.178 500865 INFO copydb_schema.c:1538 Found 0 indexes (supporting 0 constraints) in the target database - 2024-11-04 18:01:06.184 500865 INFO cli_clone_follow.c:584 STEP 2: dump the source database schema (pre/post data) - 2024-11-04 18:01:06.186 500865 INFO pgcmd.c:468 /usr/lib/postgresql/16/bin/pg_dump -Fc --snapshot 00000008-00000033-1 --section=pre-data --section=post-data --file /tmp/pgcopydb/schema/schema.dump 'postgres://neondb_owner@ep-bitter-shape-w2c1ir0a.us-east-2.aws.neon.build/neondb?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60' - 2024-11-04 18:01:06.952 500865 INFO cli_clone_follow.c:592 STEP 3: restore the pre-data section to the target database - 2024-11-04 18:01:07.004 500865 INFO pgcmd.c:1001 /usr/lib/postgresql/16/bin/pg_restore --dbname 'postgres://neondb_owner@ep-icy-union-w25qd5pj.us-east-2.aws.neon.build/ludicrous?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60' --section pre-data --jobs 4 --no-owner --no-acl --use-list /tmp/pgcopydb/schema/pre-filtered.list /tmp/pgcopydb/schema/schema.dump - 2024-11-04 18:01:07.438 500874 INFO table-data.c:656 STEP 4: starting 4 table-data COPY processes - 2024-11-04 18:01:07.451 500877 INFO vacuum.c:139 STEP 8: skipping VACUUM jobs per --skip-vacuum - 2024-11-04 18:01:07.457 500875 INFO indexes.c:182 STEP 6: starting 4 CREATE INDEX processes - 2024-11-04 18:01:07.457 500875 INFO indexes.c:183 STEP 7: constraints are built by the CREATE INDEX processes - 2024-11-04 18:01:07.507 500865 INFO blobs.c:74 Skipping large objects: none found. - 2024-11-04 18:01:07.509 500865 INFO sequences.c:194 STEP 9: reset sequences values - 2024-11-04 18:01:07.510 500886 INFO sequences.c:290 Set sequences values on the target database - 2024-11-04 20:49:00.587 500865 INFO cli_clone_follow.c:608 STEP 10: restore the post-data section to the target database - 2024-11-04 20:49:00.600 500865 INFO pgcmd.c:1001 /usr/lib/postgresql/16/bin/pg_restore --dbname 'postgres://neondb_owner@ep-icy-union-w25qd5pj.us-east-2.aws.neon.build/ludicrous?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60' --section post-data --jobs 4 --no-owner --no-acl --use-list /tmp/pgcopydb/schema/post-filtered.list /tmp/pgcopydb/schema/schema.dump - 2024-11-05 10:50:58.508 500865 INFO cli_clone_follow.c:639 All step are now done, 16h49m elapsed - 2024-11-05 10:50:58.508 500865 INFO summary.c:3155 Printing summary for 26 tables and 57 indexes + # - name: create dummy log for parser test + # run: | + # cat << EOF > /tmp/pgcopydb_${{ matrix.target_project }}.log + # 2024-11-04 18:00:53.433 500861 INFO main.c:136 Running pgcopydb version 0.17.10.g8361a93 from "/usr/lib/postgresql/17/bin/pgcopydb" + # 2024-11-04 18:00:53.434 500861 INFO cli_common.c:1225 [SOURCE] Copying database from "postgres://neondb_owner@ep-bitter-shape-w2c1ir0a.us-east-2.aws.neon.build/neondb?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60" + # 2024-11-04 18:00:53.434 500861 INFO cli_common.c:1226 [TARGET] Copying database into "postgres://neondb_owner@ep-icy-union-w25qd5pj.us-east-2.aws.neon.build/ludicrous?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60" + # 2024-11-04 18:00:53.442 500861 INFO copydb.c:105 Using work dir "/tmp/pgcopydb" + # 2024-11-04 18:00:53.541 500861 INFO snapshot.c:107 Exported snapshot "00000008-00000033-1" from the source database + # 2024-11-04 18:00:53.556 500865 INFO cli_clone_follow.c:543 STEP 1: fetch source database tables, indexes, and sequences + # 2024-11-04 18:00:54.570 500865 INFO copydb_schema.c:716 Splitting source candidate tables larger than 10 GB + # 2024-11-04 18:00:54.570 500865 INFO copydb_schema.c:829 Table public.events is 96 GB large which is larger than --split-tables-larger-than 10 GB, and does not have a unique column of type integer: splitting by CTID + # 2024-11-04 18:01:05.538 500865 INFO copydb_schema.c:905 Table public.events is 96 GB large, 10 COPY processes will be used, partitioning on ctid. + # 2024-11-04 18:01:05.564 500865 INFO copydb_schema.c:905 Table public.email_transmissions is 27 GB large, 4 COPY processes will be used, partitioning on id. + # 2024-11-04 18:01:05.584 500865 INFO copydb_schema.c:905 Table public.lessons is 25 GB large, 4 COPY processes will be used, partitioning on id. + # 2024-11-04 18:01:05.605 500865 INFO copydb_schema.c:905 Table public.lesson_users is 16 GB large, 3 COPY processes will be used, partitioning on id. + # 2024-11-04 18:01:05.605 500865 INFO copydb_schema.c:761 Fetched information for 26 tables (including 4 tables split in 21 partitions total), with an estimated total of 907 million tuples and 175 GB on-disk + # 2024-11-04 18:01:05.687 500865 INFO copydb_schema.c:968 Fetched information for 57 indexes (supporting 25 constraints) + # 2024-11-04 18:01:05.753 500865 INFO sequences.c:78 Fetching information for 24 sequences + # 2024-11-04 18:01:05.903 500865 INFO copydb_schema.c:1122 Fetched information for 4 extensions + # 2024-11-04 18:01:06.178 500865 INFO copydb_schema.c:1538 Found 0 indexes (supporting 0 constraints) in the target database + # 2024-11-04 18:01:06.184 500865 INFO cli_clone_follow.c:584 STEP 2: dump the source database schema (pre/post data) + # 2024-11-04 18:01:06.186 500865 INFO pgcmd.c:468 /usr/lib/postgresql/16/bin/pg_dump -Fc --snapshot 00000008-00000033-1 --section=pre-data --section=post-data --file /tmp/pgcopydb/schema/schema.dump 'postgres://neondb_owner@ep-bitter-shape-w2c1ir0a.us-east-2.aws.neon.build/neondb?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60' + # 2024-11-04 18:01:06.952 500865 INFO cli_clone_follow.c:592 STEP 3: restore the pre-data section to the target database + # 2024-11-04 18:01:07.004 500865 INFO pgcmd.c:1001 /usr/lib/postgresql/16/bin/pg_restore --dbname 'postgres://neondb_owner@ep-icy-union-w25qd5pj.us-east-2.aws.neon.build/ludicrous?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60' --section pre-data --jobs 4 --no-owner --no-acl --use-list /tmp/pgcopydb/schema/pre-filtered.list /tmp/pgcopydb/schema/schema.dump + # 2024-11-04 18:01:07.438 500874 INFO table-data.c:656 STEP 4: starting 4 table-data COPY processes + # 2024-11-04 18:01:07.451 500877 INFO vacuum.c:139 STEP 8: skipping VACUUM jobs per --skip-vacuum + # 2024-11-04 18:01:07.457 500875 INFO indexes.c:182 STEP 6: starting 4 CREATE INDEX processes + # 2024-11-04 18:01:07.457 500875 INFO indexes.c:183 STEP 7: constraints are built by the CREATE INDEX processes + # 2024-11-04 18:01:07.507 500865 INFO blobs.c:74 Skipping large objects: none found. + # 2024-11-04 18:01:07.509 500865 INFO sequences.c:194 STEP 9: reset sequences values + # 2024-11-04 18:01:07.510 500886 INFO sequences.c:290 Set sequences values on the target database + # 2024-11-04 20:49:00.587 500865 INFO cli_clone_follow.c:608 STEP 10: restore the post-data section to the target database + # 2024-11-04 20:49:00.600 500865 INFO pgcmd.c:1001 /usr/lib/postgresql/16/bin/pg_restore --dbname 'postgres://neondb_owner@ep-icy-union-w25qd5pj.us-east-2.aws.neon.build/ludicrous?sslmode=require&keepalives=1&keepalives_idle=10&keepalives_interval=10&keepalives_count=60' --section post-data --jobs 4 --no-owner --no-acl --use-list /tmp/pgcopydb/schema/post-filtered.list /tmp/pgcopydb/schema/schema.dump + # 2024-11-05 10:50:58.508 500865 INFO cli_clone_follow.c:639 All step are now done, 16h49m elapsed + # 2024-11-05 10:50:58.508 500865 INFO summary.c:3155 Printing summary for 26 tables and 57 indexes - OID | Schema | Name | Parts | copy duration | transmitted bytes | indexes | create index duration - ------+--------+----------------------+-------+---------------+-------------------+---------+---------------------- - 24654 | public | events | 10 | 1d11h | 878 GB | 1 | 1h41m - 24623 | public | email_transmissions | 4 | 4h46m | 99 GB | 3 | 2h04m - 24665 | public | lessons | 4 | 4h42m | 161 GB | 4 | 1m11s - 24661 | public | lesson_users | 3 | 2h46m | 49 GB | 3 | 39m35s - 24631 | public | emails | 1 | 34m07s | 10 GB | 2 | 17s - 24739 | public | payments | 1 | 5m47s | 1848 MB | 4 | 4m40s - 24681 | public | module_users | 1 | 4m57s | 1610 MB | 3 | 1m50s - 24694 | public | orders | 1 | 2m50s | 835 MB | 3 | 1m05s - 24597 | public | devices | 1 | 1m45s | 498 MB | 2 | 40s - 24723 | public | payment_methods | 1 | 1m24s | 548 MB | 2 | 31s - 24765 | public | user_collections | 1 | 2m17s | 1005 MB | 2 | 968ms - 24774 | public | users | 1 | 52s | 291 MB | 4 | 27s - 24760 | public | user_accounts | 1 | 16s | 172 MB | 3 | 16s - 24606 | public | edition_modules | 1 | 8s983 | 46 MB | 3 | 4s749 - 24583 | public | course_emails | 1 | 8s526 | 26 MB | 2 | 996ms - 24685 | public | modules | 1 | 1s592 | 21 MB | 3 | 1s696 - 24610 | public | editions | 1 | 2s199 | 7483 kB | 2 | 1s032 - 24755 | public | sp_content | 1 | 1s555 | 4177 kB | 0 | 0ms - 24619 | public | email_broadcasts | 1 | 744ms | 2645 kB | 2 | 677ms - 24590 | public | courses | 1 | 387ms | 1540 kB | 2 | 367ms - 24704 | public | payment_gateway_keys | 1 | 1s972 | 164 kB | 2 | 27ms - 24576 | public | accounts | 1 | 58ms | 24 kB | 1 | 14ms - 24647 | public | event_names | 1 | 32ms | 397 B | 1 | 8ms - 24716 | public | payment_gateways | 1 | 1s675 | 117 B | 1 | 11ms - 24748 | public | roles | 1 | 71ms | 173 B | 1 | 8ms - 24676 | public | management | 1 | 33ms | 40 B | 1 | 19ms + # OID | Schema | Name | Parts | copy duration | transmitted bytes | indexes | create index duration + # ------+--------+----------------------+-------+---------------+-------------------+---------+---------------------- + # 24654 | public | events | 10 | 1d11h | 878 GB | 1 | 1h41m + # 24623 | public | email_transmissions | 4 | 4h46m | 99 GB | 3 | 2h04m + # 24665 | public | lessons | 4 | 4h42m | 161 GB | 4 | 1m11s + # 24661 | public | lesson_users | 3 | 2h46m | 49 GB | 3 | 39m35s + # 24631 | public | emails | 1 | 34m07s | 10 GB | 2 | 17s + # 24739 | public | payments | 1 | 5m47s | 1848 MB | 4 | 4m40s + # 24681 | public | module_users | 1 | 4m57s | 1610 MB | 3 | 1m50s + # 24694 | public | orders | 1 | 2m50s | 835 MB | 3 | 1m05s + # 24597 | public | devices | 1 | 1m45s | 498 MB | 2 | 40s + # 24723 | public | payment_methods | 1 | 1m24s | 548 MB | 2 | 31s + # 24765 | public | user_collections | 1 | 2m17s | 1005 MB | 2 | 968ms + # 24774 | public | users | 1 | 52s | 291 MB | 4 | 27s + # 24760 | public | user_accounts | 1 | 16s | 172 MB | 3 | 16s + # 24606 | public | edition_modules | 1 | 8s983 | 46 MB | 3 | 4s749 + # 24583 | public | course_emails | 1 | 8s526 | 26 MB | 2 | 996ms + # 24685 | public | modules | 1 | 1s592 | 21 MB | 3 | 1s696 + # 24610 | public | editions | 1 | 2s199 | 7483 kB | 2 | 1s032 + # 24755 | public | sp_content | 1 | 1s555 | 4177 kB | 0 | 0ms + # 24619 | public | email_broadcasts | 1 | 744ms | 2645 kB | 2 | 677ms + # 24590 | public | courses | 1 | 387ms | 1540 kB | 2 | 367ms + # 24704 | public | payment_gateway_keys | 1 | 1s972 | 164 kB | 2 | 27ms + # 24576 | public | accounts | 1 | 58ms | 24 kB | 1 | 14ms + # 24647 | public | event_names | 1 | 32ms | 397 B | 1 | 8ms + # 24716 | public | payment_gateways | 1 | 1s675 | 117 B | 1 | 11ms + # 24748 | public | roles | 1 | 71ms | 173 B | 1 | 8ms + # 24676 | public | management | 1 | 33ms | 40 B | 1 | 19ms - Step Connection Duration Transfer Concurrency - -------------------------------------------------- ---------- ---------- ---------- ------------ - Catalog Queries (table ordering, filtering, etc) source 12s 1 - Dump Schema source 765ms 1 - Prepare Schema target 466ms 1 - COPY, INDEX, CONSTRAINTS, VACUUM (wall clock) both 2h47m 12 - COPY (cumulative) both 7h46m 1225 GB 4 - CREATE INDEX (cumulative) target 4h36m 4 - CONSTRAINTS (cumulative) target 8s493 4 - VACUUM (cumulative) target 0ms 4 - Reset Sequences both 60ms 1 - Large Objects (cumulative) (null) 0ms 0 - Finalize Schema both 14h01m 4 - -------------------------------------------------- ---------- ---------- ---------- ------------ - Total Wall Clock Duration both 16h49m 20 + # Step Connection Duration Transfer Concurrency + # -------------------------------------------------- ---------- ---------- ---------- ------------ + # Catalog Queries (table ordering, filtering, etc) source 12s 1 + # Dump Schema source 765ms 1 + # Prepare Schema target 466ms 1 + # COPY, INDEX, CONSTRAINTS, VACUUM (wall clock) both 2h47m 12 + # COPY (cumulative) both 7h46m 1225 GB 4 + # CREATE INDEX (cumulative) target 4h36m 4 + # CONSTRAINTS (cumulative) target 8s493 4 + # VACUUM (cumulative) target 0ms 4 + # Reset Sequences both 60ms 1 + # Large Objects (cumulative) (null) 0ms 0 + # Finalize Schema both 14h01m 4 + # -------------------------------------------------- ---------- ---------- ---------- ------------ + # Total Wall Clock Duration both 16h49m 20 - EOF + # EOF - name: show tables sizes and retrieve current backpressure seconds