vacuum_log
text/plain
Filename: vacuum_log
Type: text/plain
Part: 1
postgres=# \i ~/vacuum_check_logs.sql psql:/home/alena/vacuum_check_logs.sql:2: ERROR: extension "dblink" does not exist CREATE EXTENSION dblink_connect ---------------- OK (1 row) psql:/home/alena/vacuum_check_logs.sql:5: ERROR: table "vestat" does not exist SET SET CREATE TABLE CREATE INDEX psql:/home/alena/vacuum_check_logs.sql:15: INFO: vacuuming "postgres.public.vestat" psql:/home/alena/vacuum_check_logs.sql:15: INFO: finished vacuuming "postgres.public.vestat": index scans: 0 pages: 0 removed, 0 remain, 0 scanned (100.00% of total) tuples: 0 removed, 0 remain, 0 are dead but not yet removable removable cutoff: 741, which was 0 XIDs old when operation ended new relfrozenxid: 741, which is 2 XIDs ahead of previous value frozen: 0 pages from table (100.00% of total) had 0 tuples frozen index scan not needed: 0 pages from table (100.00% of total) had 0 dead item identifiers removed I/O timings: read: 0.092 ms, write: 0.000 ms avg read rate: 32.964 MB/s, avg write rate: 0.000 MB/s buffer usage: 13 hits, 1 misses, 0 dirtied WAL usage: 1 records, 0 full page images, 237 bytes system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s VACUUM pg_sleep ---------- (1 row) INSERT 0 1000000 DELETE 100000 psql:/home/alena/vacuum_check_logs.sql:24: INFO: vacuuming "postgres.public.vestat" psql:/home/alena/vacuum_check_logs.sql:24: INFO: table "vestat": truncated 3922 to 3530 pages psql:/home/alena/vacuum_check_logs.sql:24: INFO: finished vacuuming "postgres.public.vestat": index scans: 1 pages: 392 removed, 3530 remain, 3922 scanned (100.00% of total) tuples: 100000 removed, 900000 remain, 0 are dead but not yet removable removable cutoff: 743, which was 1 XIDs old when operation ended frozen: 0 pages from table (0.00% of total) had 0 tuples frozen index scan needed: 393 pages from table (10.02% of total) had 100000 dead item identifiers removed index "vestat_idx": pages: 2197 in total, 218 newly deleted, 218 currently deleted, 0 reusable I/O timings: read: 0.000 ms, write: 0.033 ms avg read rate: 0.000 MB/s, avg write rate: 0.057 MB/s buffer usage: 12585 hits, 0 misses, 4 dirtied WAL usage: 5369 records, 1 full page images, 928676 bytes system usage: CPU: user: 0.42 s, system: 0.00 s, elapsed: 0.54 s VACUUM pg_sleep ---------- (1 row) CHECKPOINT dblink_exec ------------- BEGIN (1 row) a --- (1 row) UPDATE 900000 psql:/home/alena/vacuum_check_logs.sql:37: INFO: vacuuming "postgres.public.vestat" psql:/home/alena/vacuum_check_logs.sql:37: INFO: finished vacuuming "postgres.public.vestat": index scans: 0 pages: 0 removed, 7512 remain, 7512 scanned (100.00% of total) tuples: 0 removed, 1800000 remain, 900000 are dead but not yet removable removable cutoff: 744, which was 1 XIDs old when operation ended frozen: 0 pages from table (0.00% of total) had 0 tuples frozen index scan not needed: 0 pages from table (0.00% of total) had 0 dead item identifiers removed index "vestat_idx": pages: 4171 in total, 0 newly deleted, 218 currently deleted, 218 reusable I/O timings: read: 0.000 ms, write: 0.043 ms avg read rate: 0.000 MB/s, avg write rate: 0.062 MB/s buffer usage: 19424 hits, 0 misses, 6 dirtied WAL usage: 2 records, 1 full page images, 1529 bytes system usage: CPU: user: 0.55 s, system: 0.00 s, elapsed: 0.75 s VACUUM pg_sleep ---------- (1 row) CHECKPOINT dblink_exec ------------- COMMIT (1 row) psql:/home/alena/vacuum_check_logs.sql:44: INFO: vacuuming "postgres.public.vestat" psql:/home/alena/vacuum_check_logs.sql:44: INFO: finished vacuuming "postgres.public.vestat": index scans: 1 pages: 0 removed, 7512 remain, 7512 scanned (100.00% of total) tuples: 900000 removed, 900000 remain, 0 are dead but not yet removable removable cutoff: 745, which was 0 XIDs old when operation ended new relfrozenxid: 744, which is 3 XIDs ahead of previous value frozen: 1 pages from table (0.01% of total) had 133 tuples frozen index scan needed: 3530 pages from table (46.99% of total) had 900000 dead item identifiers removed index "vestat_idx": pages: 4171 in total, 0 newly deleted, 218 currently deleted, 218 reusable I/O timings: read: 0.000 ms, write: 0.000 ms avg read rate: 0.000 MB/s, avg write rate: 18.654 MB/s buffer usage: 22960 hits, 0 misses, 11456 dirtied WAL usage: 18513 records, 7471 full page images, 21157546 bytes system usage: CPU: user: 2.19 s, system: 0.00 s, elapsed: 4.79 s VACUUM pg_sleep ---------- (1 row) CHECKPOINT DELETE 900000 psql:/home/alena/vacuum_check_logs.sql:51: INFO: vacuuming "postgres.public.vestat" psql:/home/alena/vacuum_check_logs.sql:51: INFO: table "vestat": truncated 7512 to 0 pages psql:/home/alena/vacuum_check_logs.sql:51: INFO: finished vacuuming "postgres.public.vestat": index scans: 1 pages: 7512 removed, 0 remain, 3983 scanned (53.02% of total) tuples: 900000 removed, 422804 remain, 0 are dead but not yet removable removable cutoff: 746, which was 1 XIDs old when operation ended new relfrozenxid: 746, which is 2 XIDs ahead of previous value frozen: 0 pages from table (0.00% of total) had 0 tuples frozen index scan needed: 3983 pages from table (53.02% of total) had 900000 dead item identifiers removed index "vestat_idx": pages: 4171 in total, 3949 newly deleted, 4167 currently deleted, 218 reusable I/O timings: read: 0.000 ms, write: 0.000 ms avg read rate: 0.000 MB/s, avg write rate: 16.985 MB/s buffer usage: 51482 hits, 0 misses, 3958 dirtied WAL usage: 23781 records, 3954 full page images, 14444904 bytes system usage: CPU: user: 0.52 s, system: 0.01 s, elapsed: 1.82 s VACUUM pg_sleep ---------- (1 row) CHECKPOINT INSERT 0 1000000 UPDATE 1000000 psql:/home/alena/vacuum_check_logs.sql:60: INFO: vacuuming "postgres.public.vestat" psql:/home/alena/vacuum_check_logs.sql:60: INFO: finished vacuuming "postgres.public.vestat": index scans: 1 pages: 0 removed, 8347 remain, 8347 scanned (100.00% of total) tuples: 1000000 removed, 1000000 remain, 0 are dead but not yet removable removable cutoff: 749, which was 0 XIDs old when operation ended new relfrozenxid: 748, which is 2 XIDs ahead of previous value frozen: 0 pages from table (0.00% of total) had 0 tuples frozen index scan needed: 3922 pages from table (46.99% of total) had 1000000 dead item identifiers removed index "vestat_idx": pages: 8341 in total, 0 newly deleted, 3949 currently deleted, 3949 reusable I/O timings: read: 3.922 ms, write: 1.230 ms avg read rate: 1.336 MB/s, avg write rate: 3.396 MB/s buffer usage: 32348 hits, 573 misses, 1456 dirtied WAL usage: 20571 records, 2 full page images, 9938566 bytes system usage: CPU: user: 2.69 s, system: 0.01 s, elapsed: 3.34 s VACUUM pg_sleep ---------- (1 row) CHECKPOINT