Progress views under the sub-command stack: what they show, per command Produced by v02-matrix.sh (attached) on 2026-11-13. Builds, all --enable-debug -O2, from the same commit: 77bba5454f9 (master), with asserts 77bba5454f9 + 0001-Allow-progress-tracking-of-sub-commands, with asserts 77bba5454f9 + 0001, without asserts The script ran three times per build, alternating builds (m, 0001, 0001 without asserts, ...). Below is the first run of each build. Across the three runs every cell showed the same kinds of rows, except for transitions caught by one or two samples (an "initializing" phase, an idle sample between two statements), and TopMemoryContext gave the same numbers byte for byte. Each line: samples per row seen, in order of first appearance. A = pg_stat_progress_analyze (phase, relid), C = pg_stat_progress_copy (command, type, relid), I = pg_stat_progress_create_index (command, phase, relid), V = pg_stat_progress_vacuum (phase, relid), R = pg_stat_progress_repack (command, phase, relid). "(none)" = no row in any of them. "C (command not set yet)" = a COPY row whose parameters are still zero (between pgstat_progress_start_command() and the first update). In multi-statement cells, "step i" is the statement being run and "idle" means the backend was between statements. "max bytes" = largest bytes_processed sampled; "sent" = bytes the client received. Sample counts depend on how long each command took; compare which rows appear, not the counts. ------------------------------------------------------------------------ P1: the cf6958 matrix, unchanged analyze_ft: ANALYZE ft 77bba5454f9: 1193 samples: 375 C COPY FROM FILE relid=ft; 818 (none) [max bytes: 60875386; sent: 0] 0001: 1189 samples: 366 C COPY FROM FILE relid=ft; 812 A computing statistics relid=ft; 4 A finalizing analyze relid=ft; 7 (none) [max bytes: 61043138; sent: 0] 0001 no asserts: 1064 samples: 292 C COPY FROM FILE relid=ft; 759 A computing statistics relid=ft; 3 A finalizing analyze relid=ft; 10 (none) [max bytes: 61006441; sent: 0] ------------------------------------------------------------------------ analyze_partitioned: ANALYZE parted 77bba5454f9: 2407 samples: 53 A acquiring inherited sample rows relid=parted children 0/2; 710 C COPY FROM FILE relid=p_ft; 1559 (none); 36 A acquiring sample rows relid=p_heap; 46 A computing statistics relid=p_heap; 3 A finalizing analyze relid=p_heap [max bytes: 60940913; sent: 0] 0001: 2644 samples: 30 A acquiring inherited sample rows relid=parted children 0/2; 675 C COPY FROM FILE relid=p_ft; 771 A computing statistics relid=parted children 2/2; 4 A finalizing analyze relid=parted children 2/2; 15 (none); 18 A acquiring sample rows relid=p_heap; 48 A computing statistics relid=p_heap; 4 A finalizing analyze relid=p_heap; 1074 A computing statistics relid=p_ft; 5 A finalizing analyze relid=p_ft [max bytes: 61006441; sent: 0] 0001 no asserts: 2022 samples: 37 A acquiring inherited sample rows relid=parted children 0/2; 511 C COPY FROM FILE relid=p_ft; 643 A computing statistics relid=parted children 2/2; 3 A finalizing analyze relid=parted children 2/2; 30 (none); 18 A acquiring sample rows relid=p_heap; 30 A computing statistics relid=p_heap; 2 A finalizing analyze relid=p_heap; 746 A computing statistics relid=p_ft; 2 A finalizing analyze relid=p_ft [max bytes: 61006441; sent: 0] ------------------------------------------------------------------------ vacuum_analyze_parted: VACUUM ANALYZE parted 77bba5454f9: 1521 samples: 34 A acquiring inherited sample rows relid=parted children 0/2; 371 C COPY FROM FILE relid=p_ft; 941 (none); 56 V scanning heap relid=p_heap; 40 A acquiring sample rows relid=p_heap; 71 A computing statistics relid=p_heap; 7 A finalizing analyze relid=p_heap; 1 A (any phase) on system catalogs [max bytes: 60875386; sent: 0] 0001: 1545 samples: 45 A acquiring inherited sample rows relid=parted children 0/2; 469 C COPY FROM FILE relid=p_ft; 890 A computing statistics relid=parted children 2/2; 4 A finalizing analyze relid=parted children 2/2; 11 (none); 42 V scanning heap relid=p_heap; 1 V performing final cleanup relid=p_heap; 32 A acquiring sample rows relid=p_heap; 47 A computing statistics relid=p_heap; 4 A finalizing analyze relid=p_heap [max bytes: 60940913; sent: 0] 0001 no asserts: 1130 samples: 27 A acquiring inherited sample rows relid=parted children 0/2; 256 C COPY FROM FILE relid=p_ft; 695 A computing statistics relid=parted children 2/2; 3 A finalizing analyze relid=parted children 2/2; 15 (none); 66 V scanning heap relid=p_heap; 37 A acquiring sample rows relid=p_heap; 29 A computing statistics relid=p_heap; 2 A finalizing analyze relid=p_heap [max bytes: 61006441; sent: 0] ------------------------------------------------------------------------ analyze_all: ANALYZE 77bba5454f9: 3650 samples: 77 A acquiring inherited sample rows relid=parted children 0/2; 489 C COPY FROM FILE relid=p_ft; 1823 (none); 33 A acquiring sample rows relid=p_heap; 38 A computing statistics relid=p_heap; 6 A finalizing analyze relid=p_heap; 251 A acquiring sample rows relid=heapx; 91 A computing statistics relid=heapx; 4 A finalizing analyze relid=heapx; 2 A acquiring sample rows relid=small_heap; 1 A initializing relid=t7; 47 A acquiring sample rows relid=heapf; 12 A computing statistics relid=heapf; 6 A finalizing analyze relid=heapf; 275 A acquiring sample rows relid=rp; 373 A computing statistics relid=rp; 5 A finalizing analyze relid=rp; 117 A (any phase) on system catalogs [max bytes: 60940913; sent: 0] 0001: 2256 samples: 28 A acquiring inherited sample rows relid=parted children 0/2; 317 C COPY FROM FILE relid=p_ft; 698 A computing statistics relid=parted children 2/2; 4 A finalizing analyze relid=parted children 2/2; 266 (none); 15 A acquiring sample rows relid=p_heap; 50 A computing statistics relid=p_heap; 4 A finalizing analyze relid=p_heap; 143 A acquiring sample rows relid=heapx; 59 A computing statistics relid=heapx; 2 A finalizing analyze relid=heapx; 1 A finalizing analyze relid=t8; 10 A acquiring sample rows relid=heapf; 4 A computing statistics relid=heapf; 3 A finalizing analyze relid=heapf; 199 A acquiring sample rows relid=rp; 340 A computing statistics relid=rp; 4 A finalizing analyze relid=rp; 109 A (any phase) on system catalogs [max bytes: 61006441; sent: 0] 0001 no asserts: 2422 samples: 25 A acquiring inherited sample rows relid=parted children 0/2; 257 C COPY FROM FILE relid=p_ft; 720 A computing statistics relid=parted children 2/2; 2 A finalizing analyze relid=parted children 2/2; 464 (none); 36 A acquiring sample rows relid=p_heap; 35 A computing statistics relid=p_heap; 2 A finalizing analyze relid=p_heap; 154 A acquiring sample rows relid=heapx; 53 A computing statistics relid=heapx; 1 A finalizing analyze relid=heapx; 10 A acquiring sample rows relid=heapf; 3 A computing statistics relid=heapf; 1 A finalizing analyze relid=heapf; 186 A acquiring sample rows relid=rp; 361 A computing statistics relid=rp; 2 A finalizing analyze relid=rp; 110 A (any phase) on system catalogs [max bytes: 61043138; sent: 0] ------------------------------------------------------------------------ copy_to_select_ft: COPY (SELECT a FROM ft) TO STDOUT 77bba5454f9: 219 samples: 219 C COPY TO PIPE relid=- [max bytes: 61006441; sent: 10888896] 0001: 209 samples: 209 C COPY TO PIPE relid=- [max bytes: 61006441; sent: 10888896] 0001 no asserts: 166 samples: 166 C COPY TO PIPE relid=- [max bytes: 55240005; sent: 10888896] ------------------------------------------------------------------------ copy_from_trigger: COPY t3 FROM '$W/three.txt' 77bba5454f9: 97 samples: 91 C COPY FROM FILE relid=ft_small; 6 (none) [max bytes: 7797796; sent: 0] 0001: 98 samples: 94 C COPY FROM FILE relid=ft_small; 1 C (command not set yet) relid=ft_small; 3 (none) [max bytes: 7797796; sent: 0] 0001 no asserts: 81 samples: 75 C COPY FROM FILE relid=ft_small; 6 (none) [max bytes: 7813120; sent: 0] ------------------------------------------------------------------------ copy_from_trigger_copy_to: COPY t4 FROM '$W/three.txt' 77bba5454f9: 97 samples: 83 C COPY TO FILE relid=-; 14 (none) [max bytes: 1279438; sent: 0] 0001: 78 samples: 47 C COPY TO FILE relid=-; 27 C COPY FROM FILE relid=t4; 4 (none) [max bytes: 1251214; sent: 0] 0001 no asserts: 72 samples: 44 C COPY TO FILE relid=-; 22 C COPY FROM FILE relid=t4; 6 (none) [max bytes: 1265893; sent: 0] ------------------------------------------------------------------------ copy_to_two_scans: COPY (SELECT a FROM ft UNION ALL SELECT a FROM ft_small) TO STDOUT 77bba5454f9: 248 samples: 248 C COPY TO PIPE relid=- [max bytes: 12151821; sent: 12177791] 0001: 249 samples: 249 (none) [max bytes: 0; sent: 12177791] 0001 no asserts: 192 samples: 192 (none) [max bytes: 0; sent: 12177791] ------------------------------------------------------------------------ insert_select_ft: INSERT INTO t SELECT * FROM ft 77bba5454f9: 1504 samples: 1493 C COPY FROM FILE relid=ft; 11 (none) [max bytes: 61006441; sent: 0] 0001: 1278 samples: 1270 C COPY FROM FILE relid=ft; 8 (none) [max bytes: 61006441; sent: 0] 0001 no asserts: 1235 samples: 1222 C COPY FROM FILE relid=ft; 13 (none) [max bytes: 61043138; sent: 0] ------------------------------------------------------------------------ ctas_ft: CREATE TABLE ctas AS SELECT * FROM ft 77bba5454f9: 1358 samples: 61 (none); 1297 C COPY FROM FILE relid=ft [max bytes: 61006441; sent: 0] 0001: 1120 samples: 1073 C COPY FROM FILE relid=ft; 47 (none) [max bytes: 61006441; sent: 0] 0001 no asserts: 1153 samples: 1090 C COPY FROM FILE relid=ft; 63 (none) [max bytes: 61006441; sent: 0] ------------------------------------------------------------------------ select_ft: SELECT count(*) FROM ft 77bba5454f9: 257 samples: 257 C COPY FROM FILE relid=ft [max bytes: 60940913; sent: 38] 0001: 221 samples: 221 C COPY FROM FILE relid=ft [max bytes: 60875386; sent: 38] 0001 no asserts: 198 samples: 198 C COPY FROM FILE relid=ft [max bytes: 61006441; sent: 38] ------------------------------------------------------------------------ explain_then_select: EXPLAIN SELECT * FROM ft_small; SELECT count(*) FROM ft 77bba5454f9: 259 samples: 258 C COPY FROM FILE relid=ft; 1 (none) [max bytes: 60940913; sent: 343] 0001: 230 samples: 230 (none) [max bytes: 0; sent: 343] 0001 no asserts: 188 samples: 188 (none) [max bytes: 0; sent: 345] ------------------------------------------------------------------------ select_program: SELECT count(*) FROM ft_prog 77bba5454f9: 293 samples: 293 C COPY FROM PROGRAM relid=ft_prog [max bytes: 61006441; sent: 38] 0001: 249 samples: 248 C COPY FROM PROGRAM relid=ft_prog; 1 (none) [max bytes: 60875386; sent: 38] 0001 no asserts: 203 samples: 203 C COPY FROM PROGRAM relid=ft_prog [max bytes: 61006441; sent: 38] ------------------------------------------------------------------------ copy_to_program: COPY (SELECT a FROM ft_prog) TO STDOUT 77bba5454f9: 263 samples: 263 C COPY TO PIPE relid=- [max bytes: 10869952; sent: 10888896] 0001: 224 samples: 223 C COPY TO PIPE relid=-; 1 (none) [max bytes: 10842624; sent: 10888896] 0001 no asserts: 192 samples: 192 C COPY TO PIPE relid=- [max bytes: 38202862; sent: 10888896] ------------------------------------------------------------------------ copy_to_plain: COPY (SELECT a FROM t) TO STDOUT 77bba5454f9: 218 samples: 218 C COPY TO PIPE relid=- [max bytes: 10887064; sent: 10888896] 0001: 186 samples: 186 C COPY TO PIPE relid=- [max bytes: 10837240; sent: 10888896] 0001 no asserts: 181 samples: 181 C COPY TO PIPE relid=- [max bytes: 10795736; sent: 10888896] ------------------------------------------------------------------------ select_two_scans: SELECT (SELECT count(*) FROM ft) + (SELECT count(*) FROM ft_small) 77bba5454f9: 293 samples: 293 C COPY FROM FILE relid=ft_small [max bytes: 61006441; sent: 41] 0001: 268 samples: 268 (none) [max bytes: 0; sent: 41] 0001 no asserts: 206 samples: 206 (none) [max bytes: 0; sent: 41] ------------------------------------------------------------------------ select_rescan: SELECT count(*) FROM generate_series(1, 3) g(i), LATERAL (SELECT a FROM ft WHERE a > i OFFSET 0) s 77bba5454f9: 612 samples: 612 C COPY FROM FILE relid=ft [max bytes: 61006441; sent: 38] 0001: 560 samples: 560 C COPY FROM FILE relid=ft [max bytes: 60940913; sent: 38] 0001 no asserts: 477 samples: 477 C COPY FROM FILE relid=ft [max bytes: 61043138; sent: 38] ------------------------------------------------------------------------ select_error: SELECT count(*) FROM ft_bad 77bba5454f9: 12 samples: 12 C COPY FROM FILE relid=ft_bad [max bytes: 3795420; sent: 0; stderr: ERROR: invalid input syntax for type integer: "oops"] 0001: 17 samples: 17 C COPY FROM FILE relid=ft_bad [max bytes: 3795420; sent: 0; stderr: ERROR: invalid input syntax for type integer: "oops"] 0001 no asserts: 13 samples: 13 C COPY FROM FILE relid=ft_bad [max bytes: 3735066; sent: 0; stderr: ERROR: invalid input syntax for type integer: "oops"] ------------------------------------------------------------------------ P2: COPY TO over a file_fdw scan; TO PROGRAM keeps EndCopy waiting 1 s copy_to_ft_program_sleep: COPY (SELECT a FROM ft) TO PROGRAM 'cat >/dev/null; sleep 1' 77bba5454f9: 1050 samples: 191 C COPY TO PROGRAM relid=-; 859 (none) [max bytes: 45410845; sent: 0] in time order: C COPY TO PROGRAM relid=- x191 [bytes 16518..10883056, went down 1x] [n 3525..1499270] (none) x859 0001: 1082 samples: 199 C COPY TO PROGRAM relid=-; 883 C COPY FROM FILE relid=ft [max bytes: 59826930; sent: 0] in time order: C COPY TO PROGRAM relid=- x199 [bytes 23698..10879760, went down 2x] [n 4961..1498858] C COPY FROM FILE relid=ft x883 [bytes 0..0] [n 0..0] 0001 no asserts: 1078 samples: 173 C COPY TO PROGRAM relid=-; 905 C COPY FROM FILE relid=ft [max bytes: 10870824; sent: 0] in time order: C COPY TO PROGRAM relid=- x173 [bytes 15308..10870824] [n 3283..1497741] C COPY FROM FILE relid=ft x905 [bytes 0..0] [n 0..0] ------------------------------------------------------------------------ P3: one file_fdw scan per statement, same session alternate (one session): step 1: SELECT count(*) FROM ft; step 2: SELECT count(*) FROM ft; step 3: SELECT count(*) FROM ft; step 4: SELECT count(*) FROM ft; 77bba5454f9: 932 samples: 225 step 1: C COPY FROM FILE relid=ft; 226 step 2: C COPY FROM FILE relid=ft; 1 step 3: (none); 238 step 3: C COPY FROM FILE relid=ft; 242 step 4: C COPY FROM FILE relid=ft [max bytes: 60940913; sent: 152] in time order: step 1: C COPY FROM FILE relid=ft x225 [bytes 262126..60875386] [n 0..0] step 2: C COPY FROM FILE relid=ft x226 [bytes 65536..60875386] [n 0..0] step 3: (none) x1 step 3: C COPY FROM FILE relid=ft x238 [bytes 262126..60940913] [n 0..0] step 4: C COPY FROM FILE relid=ft x242 [bytes 65536..60875386] [n 0..0] 0001: 936 samples: 231 step 1: C COPY FROM FILE relid=ft; 1 step 1: idle: (none); 235 step 2: (none); 235 step 3: C COPY FROM FILE relid=ft; 234 step 4: (none) [max bytes: 61006441; sent: 152] in time order: step 1: C COPY FROM FILE relid=ft x231 [bytes 262126..60875386] [n 0..0] step 1: idle: (none) x1 step 2: (none) x235 step 3: C COPY FROM FILE relid=ft x235 [bytes 131072..61006441] [n 0..0] step 4: (none) x234 0001 no asserts: 764 samples: 187 step 1: C COPY FROM FILE relid=ft; 1 step 1: (none); 191 step 2: (none); 195 step 3: C COPY FROM FILE relid=ft; 190 step 4: (none) [max bytes: 61006441; sent: 152] in time order: step 1: C COPY FROM FILE relid=ft x187 [bytes 327650..60744328] [n 0..0] step 1: (none) x1 step 2: (none) x191 step 3: C COPY FROM FILE relid=ft x195 [bytes 262126..61006441] [n 0..0] step 4: (none) x190 ------------------------------------------------------------------------ explain_first (one session): step 1: EXPLAIN SELECT * FROM ft_small; step 2: SELECT count(*) FROM ft; 77bba5454f9: 242 samples: 242 step 2: C COPY FROM FILE relid=ft [max bytes: 61006441; sent: 343] in time order: step 2: C COPY FROM FILE relid=ft x242 [bytes 262126..61006441] [n 0..0] 0001: 236 samples: 235 step 2: (none); 1 step 2: idle: (none) [max bytes: 0; sent: 343] in time order: step 2: (none) x235 step 2: idle: (none) x1 0001 no asserts: 184 samples: 184 step 2: (none) [max bytes: 0; sent: 345] in time order: step 2: (none) x184 ------------------------------------------------------------------------ P4: two file_fdw scans that fail, then other commands in the same session two_scans_error (one session): step 1: SELECT (SELECT count(*) FROM ft_bad) + (SELECT count(*) FROM ft_small); step 2: CREATE INDEX heapx_a ON heapx (a); step 3: VACUUM (DISABLE_PAGE_SKIPPING) rp; step 4: ANALYZE heapx; step 5: COPY heapx TO '/dev/null'; step 6: SELECT count(*) FROM ft; step 7: DROP INDEX heapx_a; 77bba5454f9: 1978 samples: 9 step 1: C COPY FROM FILE relid=ft_small; 47 step 2: I CREATE INDEX building index: scanning table relid=heapx; 14 step 2: I CREATE INDEX building index: sorting live tuples relid=heapx; 89 step 2: I CREATE INDEX building index: loading tuples in tree relid=heapx; 9 step 2: (none); 1 step 2: idle: (none); 1214 step 3: V scanning heap relid=rp; 3 step 3: V cleaning up indexes relid=rp; 1 step 3: (none); 132 step 4: A acquiring sample rows relid=heapx; 55 step 4: A computing statistics relid=heapx; 1 step 4: A finalizing analyze relid=heapx; 6 step 4: (none); 153 step 5: C COPY TO FILE relid=heapx; 237 step 6: C COPY FROM FILE relid=ft; 7 step 7: (none) [max bytes: 61006441; sent: 38] 0001: 1779 samples: 10 step 1: (none); 150 step 2: (none); 1030 step 3: (none); 170 step 4: (none); 163 step 5: (none); 247 step 6: (none); 9 step 7: (none) [max bytes: 0; sent: 38] 0001 no asserts: 1857 samples: 8 step 1: (none); 137 step 2: (none); 1160 step 3: (none); 169 step 4: (none); 1 step 4: idle: (none); 152 step 5: (none); 191 step 6: (none); 39 step 7: (none) [max bytes: 0; sent: 38] ------------------------------------------------------------------------ control_new_session (one session): step 1: CREATE INDEX heapx_a ON heapx (a); step 2: VACUUM (DISABLE_PAGE_SKIPPING) rp; step 3: ANALYZE heapx; step 4: COPY heapx TO '/dev/null'; step 5: SELECT count(*) FROM ft; step 6: DROP INDEX heapx_a; 77bba5454f9: 710 samples: 36 step 1: I CREATE INDEX building index: scanning table relid=heapx; 14 step 1: I CREATE INDEX building index: sorting live tuples relid=heapx; 106 step 1: I CREATE INDEX building index: loading tuples in tree relid=heapx; 20 step 1: (none); 1 step 2: (none); 45 step 2: V scanning heap relid=rp; 2 step 2: V cleaning up indexes relid=rp; 118 step 3: A acquiring sample rows relid=heapx; 56 step 3: A computing statistics relid=heapx; 2 step 3: A finalizing analyze relid=heapx; 13 step 3: (none); 51 step 4: C COPY TO FILE relid=heapx; 1 step 5: (none); 235 step 5: C COPY FROM FILE relid=ft; 1 step 5: idle: (none); 9 step 6: (none) [max bytes: 60809859; sent: 38] 0001: 721 samples: 33 step 1: I CREATE INDEX building index: scanning table relid=heapx; 14 step 1: I CREATE INDEX building index: sorting live tuples relid=heapx; 89 step 1: I CREATE INDEX building index: loading tuples in tree relid=heapx; 8 step 1: (none); 56 step 2: V scanning heap relid=rp; 3 step 2: V cleaning up indexes relid=rp; 1 step 3: A initializing relid=heapx; 99 step 3: A acquiring sample rows relid=heapx; 57 step 3: A computing statistics relid=heapx; 1 step 3: A finalizing analyze relid=heapx; 8 step 3: (none); 51 step 4: C COPY TO FILE relid=heapx; 1 step 5: idle: (none); 290 step 5: C COPY FROM FILE relid=ft; 9 step 6: (none); 1 step 6: idle: (none) [max bytes: 61006441; sent: 38] 0001 no asserts: 746 samples: 25 step 1: I CREATE INDEX building index: scanning table relid=heapx; 12 step 1: I CREATE INDEX building index: sorting live tuples relid=heapx; 85 step 1: I CREATE INDEX building index: loading tuples in tree relid=heapx; 11 step 1: (none); 35 step 2: V scanning heap relid=rp; 3 step 2: V cleaning up indexes relid=rp; 118 step 3: A acquiring sample rows relid=heapx; 50 step 3: A computing statistics relid=heapx; 31 step 3: (none); 43 step 4: C COPY TO FILE relid=heapx; 1 step 5: (none); 185 step 5: C COPY FROM FILE relid=ft; 146 step 6: (none); 1 step 6: idle: (none) [max bytes: 60940913; sent: 38] ------------------------------------------------------------------------ two_scans_cancel (one session): step 1: SET statement_timeout = 200; step 2: SELECT (SELECT count(*) FROM ft) + (SELECT count(*) FROM ft_small); step 3: RESET statement_timeout; step 4: CREATE INDEX heapx_a ON heapx (a); step 5: DROP INDEX heapx_a; 77bba5454f9: 336 samples: 165 step 2: C COPY FROM FILE relid=ft_small; 1 step 4: I CREATE INDEX initializing relid=heapx; 54 step 4: I CREATE INDEX building index: scanning table relid=heapx; 19 step 4: I CREATE INDEX building index: sorting live tuples relid=heapx; 79 step 4: I CREATE INDEX building index: loading tuples in tree relid=heapx; 10 step 4: (none); 1 step 4: idle: (none); 7 step 5: (none) [max bytes: 31125857; sent: 0] 0001: 300 samples: 171 step 2: (none); 120 step 4: (none); 9 step 5: (none) [max bytes: 0; sent: 0] 0001 no asserts: 310 samples: 172 step 2: (none); 1 step 3: (none); 128 step 4: (none); 9 step 5: (none) [max bytes: 0; sent: 0] ------------------------------------------------------------------------ P5: generic plan with two file_fdw scans (merge join) generic_plan (one session): step 1: SET plan_cache_mode = force_generic_plan; step 2: SET enable_hashjoin = off; step 3: SET enable_nestloop = off; step 4: PREPARE q AS SELECT count(*) FROM ft a JOIN ft_small b ON a.a = b.a; step 5: EXECUTE q; step 6: EXECUTE q; step 7: EXECUTE q; step 8: EXECUTE q; step 9: SELECT pg_sleep(0.3); 77bba5454f9: 1239 samples: 243 step 5: C COPY FROM FILE relid=ft_small; 1 step 5: (none); 241 step 6: C COPY FROM FILE relid=ft_small; 1 step 6: (none); 243 step 7: C COPY FROM FILE relid=ft_small; 1 step 7: idle: (none); 239 step 8: C COPY FROM FILE relid=ft_small; 1 step 8: (none); 269 step 9: (none) [max bytes: 61043138; sent: 173] in time order: step 5: C COPY FROM FILE relid=ft_small x243 [bytes 0..7813120, went down 1x] [n 0..0] step 5: (none) x1 step 6: C COPY FROM FILE relid=ft_small x241 [bytes 196596..7813120, went down 1x] [n 0..0] step 6: (none) x1 step 7: C COPY FROM FILE relid=ft_small x243 [bytes 131072..7813120, went down 1x] [n 0..0] step 7: idle: (none) x1 step 8: C COPY FROM FILE relid=ft_small x239 [bytes 327650..7813120, went down 1x] [n 0..0] step 8: (none) x1 step 9: (none) x269 0001: 1224 samples: 234 step 5: (none); 1 step 5: idle: (none); 238 step 6: C COPY FROM FILE relid=ft_small; 1 step 6: (none); 245 step 7: C COPY FROM FILE relid=ft_small; 1 step 7: C COPY FROM FILE relid=ft; 236 step 8: C COPY FROM FILE relid=ft_small; 1 step 8: C COPY FROM FILE relid=ft; 267 step 9: (none) [max bytes: 61043138; sent: 173] in time order: step 5: (none) x234 step 5: idle: (none) x1 step 6: C COPY FROM FILE relid=ft_small x238 [bytes 327650..7813120, went down 1x] [n 0..0] step 6: (none) x1 step 7: C COPY FROM FILE relid=ft_small x245 [bytes 196596..7813120, went down 1x] [n 0..0] step 7: C COPY FROM FILE relid=ft x1 [bytes 0..0] [n 0..0] step 8: C COPY FROM FILE relid=ft_small x236 [bytes 65536..7813120, went down 1x] [n 0..0] step 8: C COPY FROM FILE relid=ft x1 [bytes 0..0] [n 0..0] step 9: (none) x267 0001 no asserts: 1065 samples: 203 step 5: (none); 196 step 6: C COPY FROM FILE relid=ft_small; 1 step 6: C COPY FROM FILE relid=ft; 192 step 7: C COPY FROM FILE relid=ft_small; 1 step 7: (none); 205 step 8: C COPY FROM FILE relid=ft_small; 267 step 9: (none) [max bytes: 61043138; sent: 173] in time order: step 5: (none) x203 step 6: C COPY FROM FILE relid=ft_small x196 [bytes 262126..7813120, went down 1x] [n 0..0] step 6: C COPY FROM FILE relid=ft x1 [bytes 0..0] [n 0..0] step 7: C COPY FROM FILE relid=ft_small x192 [bytes 65536..7813120, went down 1x] [n 0..0] step 7: (none) x1 step 8: C COPY FROM FILE relid=ft_small x205 [bytes 393174..7813120, went down 1x] [n 0..0] step 9: (none) x267 ------------------------------------------------------------------------ P6: three levels; COPY FROM whose trigger runs COPY (SELECT ...) TO copy_from_trigger_copy_ft3: COPY t6 FROM '$W/ints.txt' 77bba5454f9: 189 samples: 124 (none); 23 C (command not set yet) relid=ft3; 25 C COPY TO FILE relid=-; 17 C COPY FROM FILE relid=ft3 [max bytes: 6; sent: 0] 0001: 186 samples: 146 (none); 14 C COPY FROM FILE relid=ft3; 12 C (command not set yet) relid=ft3; 14 C COPY TO FILE relid=- [max bytes: 6; sent: 0] 0001 no asserts: 148 samples: 1 C COPY FROM FILE relid=t6; 106 (none); 12 C COPY TO FILE relid=-; 19 C COPY FROM FILE relid=ft3; 10 C (command not set yet) relid=ft3 [max bytes: 65536; sent: 0] ------------------------------------------------------------------------ copy_from_trigger_copy_heap: COPY t6h FROM '$W/ints.txt' 77bba5454f9: 129 samples: 111 (none); 18 C COPY TO FILE relid=- [max bytes: 6; sent: 0] 0001: 132 samples: 82 C COPY FROM FILE relid=t6h; 19 C COPY TO FILE relid=-; 31 (none) [max bytes: 108894; sent: 0] 0001 no asserts: 91 samples: 54 C COPY FROM FILE relid=t6h; 28 C COPY TO FILE relid=-; 9 (none) [max bytes: 108894; sent: 0] ------------------------------------------------------------------------ P7: errors inside nested commands caught_error_in_trigger: COPY t7 FROM '$W/ints.txt' 77bba5454f9: 98 samples: 48 (none); 31 C COPY FROM FILE relid=tbad; 19 C (command not set yet) relid=tbad [max bytes: 7; sent: 0] 0001: 86 samples: 61 C COPY FROM FILE relid=tbad; 20 C (command not set yet) relid=tbad; 5 C COPY FROM FILE relid=t7 [max bytes: 108894; sent: 0] 0001 no asserts: 88 samples: 59 C COPY FROM FILE relid=tbad; 19 C (command not set yet) relid=tbad; 10 C COPY FROM FILE relid=t7 [max bytes: 108894; sent: 0] ------------------------------------------------------------------------ index_function_catches: CREATE INDEX heapf_f ON heapf (f_catch(a)) 77bba5454f9: 505 samples: 505 (none) [max bytes: 0; sent: 0] 0001: 476 samples: 444 I CREATE INDEX building index: scanning table relid=heapf; 18 I CREATE INDEX building index: sorting live tuples relid=heapf; 8 I CREATE INDEX building index: loading tuples in tree relid=heapf; 6 (none) [max bytes: 0; sent: 0] 0001 no asserts: 352 samples: 11 (none); 322 I CREATE INDEX building index: scanning table relid=heapf; 15 I CREATE INDEX building index: sorting live tuples relid=heapf; 4 I CREATE INDEX building index: loading tuples in tree relid=heapf [max bytes: 0; sent: 0] ------------------------------------------------------------------------ toplevel_error_in_trigger (one session): step 1: COPY t8 FROM '$W/three.txt'; step 2: SELECT pg_sleep(0.3); step 3: CREATE INDEX heapx_a ON heapx (a); step 4: SELECT pg_sleep(0.3); step 5: DROP INDEX heapx_a; 77bba5454f9: 663 samples: 253 step 2: (none); 1 step 3: I CREATE INDEX initializing relid=heapx; 41 step 3: I CREATE INDEX building index: scanning table relid=heapx; 14 step 3: I CREATE INDEX building index: sorting live tuples relid=heapx; 64 step 3: I CREATE INDEX building index: loading tuples in tree relid=heapx; 15 step 3: (none); 267 step 4: (none); 1 step 5: idle: (none); 7 step 5: (none) [max bytes: 0; sent: 66] in time order: step 2: (none) x253 step 3: I CREATE INDEX initializing relid=heapx x1 [n 0..0] step 3: I CREATE INDEX building index: scanning table relid=heapx x41 [n 0..4416] step 3: I CREATE INDEX building index: sorting live tuples relid=heapx x14 [n 4425..0] step 3: I CREATE INDEX building index: loading tuples in tree relid=heapx x64 [n 0..0] step 3: (none) x15 step 4: (none) x267 step 5: idle: (none) x1 step 5: (none) x7 0001: 684 samples: 256 step 2: C COPY FROM FILE relid=t8; 155 step 3: C COPY FROM FILE relid=t8; 263 step 4: C COPY FROM FILE relid=t8; 10 step 5: C COPY FROM FILE relid=t8 [max bytes: 6; sent: 66] in time order: step 2: C COPY FROM FILE relid=t8 x256 [bytes 6..6] [n 0..0] step 3: C COPY FROM FILE relid=t8 x155 [bytes 6..6] [n 0..0] step 4: C COPY FROM FILE relid=t8 x263 [bytes 6..6] [n 0..0] step 5: C COPY FROM FILE relid=t8 x10 [bytes 6..6] [n 0..0] 0001 no asserts: 682 samples: 268 step 2: C COPY FROM FILE relid=t8; 125 step 3: C COPY FROM FILE relid=t8; 1 step 3: idle: C COPY FROM FILE relid=t8; 273 step 4: C COPY FROM FILE relid=t8; 14 step 5: C COPY FROM FILE relid=t8; 1 step 5: idle: C COPY FROM FILE relid=t8 [max bytes: 6; sent: 66] in time order: step 2: C COPY FROM FILE relid=t8 x268 [bytes 6..6] [n 0..0] step 3: C COPY FROM FILE relid=t8 x125 [bytes 6..6] [n 0..0] step 3: idle: C COPY FROM FILE relid=t8 x1 [bytes 6..6] [n 0..0] step 4: C COPY FROM FILE relid=t8 x273 [bytes 6..6] [n 0..0] step 5: C COPY FROM FILE relid=t8 x14 [bytes 6..6] [n 0..0] step 5: idle: C COPY FROM FILE relid=t8 x1 [bytes 6..6] [n 0..0] ------------------------------------------------------------------------ caught_error_no_outer (one session): step 1: DO $$BEGIN COPY tbad FROM '$W/badsmall.txt'; EXCEPTION WHEN others THEN NULL; END$$; step 2: SELECT pg_sleep(0.3); step 3: CREATE INDEX heapx_a ON heapx (a); step 4: SELECT pg_sleep(0.3); step 5: DROP INDEX heapx_a; 77bba5454f9: 664 samples: 261 step 2: (none); 1 step 3: I CREATE INDEX initializing relid=heapx; 39 step 3: I CREATE INDEX building index: scanning table relid=heapx; 19 step 3: I CREATE INDEX building index: sorting live tuples relid=heapx; 67 step 3: I CREATE INDEX building index: loading tuples in tree relid=heapx; 6 step 3: (none); 265 step 4: (none); 6 step 5: (none) [max bytes: 0; sent: 66] in time order: step 2: (none) x261 step 3: I CREATE INDEX initializing relid=heapx x1 [n 0..0] step 3: I CREATE INDEX building index: scanning table relid=heapx x39 [n 9..4330] step 3: I CREATE INDEX building index: sorting live tuples relid=heapx x19 [n 4425..0] step 3: I CREATE INDEX building index: loading tuples in tree relid=heapx x67 [n 0..0] step 3: (none) x6 step 4: (none) x265 step 5: (none) x6 0001: 674 samples: 1 step 1: (none); 263 step 2: C COPY FROM FILE relid=tbad; 136 step 3: C COPY FROM FILE relid=tbad; 267 step 4: C COPY FROM FILE relid=tbad; 7 step 5: C COPY FROM FILE relid=tbad [max bytes: 7; sent: 66] in time order: step 1: (none) x1 step 2: C COPY FROM FILE relid=tbad x263 [bytes 7..7] [n 0..0] step 3: C COPY FROM FILE relid=tbad x136 [bytes 7..7] [n 0..0] step 4: C COPY FROM FILE relid=tbad x267 [bytes 7..7] [n 0..0] step 5: C COPY FROM FILE relid=tbad x7 [bytes 7..7] [n 0..0] 0001 no asserts: 659 samples: 1 step 1: (none); 269 step 2: C COPY FROM FILE relid=tbad; 112 step 3: C COPY FROM FILE relid=tbad; 269 step 4: C COPY FROM FILE relid=tbad; 8 step 5: C COPY FROM FILE relid=tbad [max bytes: 7; sent: 66] in time order: step 1: (none) x1 step 2: C COPY FROM FILE relid=tbad x269 [bytes 7..7] [n 0..0] step 3: C COPY FROM FILE relid=tbad x112 [bytes 7..7] [n 0..0] step 4: C COPY FROM FILE relid=tbad x269 [bytes 7..7] [n 0..0] step 5: C COPY FROM FILE relid=tbad x8 [bytes 7..7] [n 0..0] ------------------------------------------------------------------------ toplevel_error_copy_to_ft_bad (one session): step 1: COPY (SELECT a FROM ft_bad) TO '/dev/null'; step 2: SELECT pg_sleep(0.3); step 3: CREATE INDEX heapx_a ON heapx (a); step 4: SELECT pg_sleep(0.3); step 5: DROP INDEX heapx_a; 77bba5454f9: 657 samples: 6 step 1: C COPY TO FILE relid=-; 264 step 2: (none); 1 step 3: I CREATE INDEX initializing relid=heapx; 40 step 3: I CREATE INDEX building index: scanning table relid=heapx; 16 step 3: I CREATE INDEX building index: sorting live tuples relid=heapx; 63 step 3: I CREATE INDEX building index: loading tuples in tree relid=heapx; 7 step 3: (none); 1 step 3: idle: (none); 253 step 4: (none); 6 step 5: (none) [max bytes: 517884; sent: 66] in time order: step 1: C COPY TO FILE relid=- x6 [bytes 27443..517884] [n 5710..88165] step 2: (none) x264 step 3: I CREATE INDEX initializing relid=heapx x1 [n 0..0] step 3: I CREATE INDEX building index: scanning table relid=heapx x40 [n 11..4314] step 3: I CREATE INDEX building index: sorting live tuples relid=heapx x16 [n 4425..0] step 3: I CREATE INDEX building index: loading tuples in tree relid=heapx x63 [n 0..0] step 3: (none) x7 step 3: idle: (none) x1 step 4: (none) x253 step 5: (none) x6 0001: 687 samples: 6 step 1: C COPY TO FILE relid=-; 264 step 2: C COPY FROM FILE relid=ft_bad; 144 step 3: C COPY FROM FILE relid=ft_bad; 263 step 4: C COPY FROM FILE relid=ft_bad; 1 step 5: idle: C COPY FROM FILE relid=ft_bad; 9 step 5: C COPY FROM FILE relid=ft_bad [max bytes: 586080; sent: 66] in time order: step 1: C COPY TO FILE relid=- x6 [bytes 77178..586080] [n 14714..99531] step 2: C COPY FROM FILE relid=ft_bad x264 [bytes 0..0] [n 0..0] step 3: C COPY FROM FILE relid=ft_bad x144 [bytes 0..0] [n 0..0] step 4: C COPY FROM FILE relid=ft_bad x263 [bytes 0..0] [n 0..0] step 5: idle: C COPY FROM FILE relid=ft_bad x1 [bytes 0..0] [n 0..0] step 5: C COPY FROM FILE relid=ft_bad x9 [bytes 0..0] [n 0..0] 0001 no asserts: 670 samples: 10 step 1: C COPY TO FILE relid=-; 274 step 2: C COPY FROM FILE relid=ft_bad; 103 step 3: C COPY FROM FILE relid=ft_bad; 272 step 4: C COPY FROM FILE relid=ft_bad; 11 step 5: C COPY FROM FILE relid=ft_bad [max bytes: 571764; sent: 66] in time order: step 1: C COPY TO FILE relid=- x10 [bytes 31723..571764] [n 6566..97145] step 2: C COPY FROM FILE relid=ft_bad x274 [bytes 0..0] [n 0..0] step 3: C COPY FROM FILE relid=ft_bad x103 [bytes 0..0] [n 0..0] step 4: C COPY FROM FILE relid=ft_bad x272 [bytes 0..0] [n 0..0] step 5: C COPY FROM FILE relid=ft_bad x11 [bytes 0..0] [n 0..0] ------------------------------------------------------------------------ P9: REPACK, CLUSTER and VACUUM FULL of a 2M-row table with 3 indexes repack: REPACK rp 77bba5454f9: 2791 samples: 365 R REPACK seq scanning heap relid=rp; 2411 R REPACK rebuilding index relid=rp; 15 (none) [max bytes: 0; sent: 0] 0001: 2672 samples: 420 R REPACK seq scanning heap relid=rp; 1165 I REINDEX building index: scanning table relid=rp; 372 I REINDEX building index: sorting live tuples relid=rp; 677 I REINDEX building index: loading tuples in tree relid=rp; 1 R REPACK performing final cleanup relid=rp; 37 (none) [max bytes: 0; sent: 0] 0001 no asserts: 2368 samples: 348 R REPACK seq scanning heap relid=rp; 1101 I REINDEX building index: scanning table relid=rp; 310 I REINDEX building index: sorting live tuples relid=rp; 582 I REINDEX building index: loading tuples in tree relid=rp; 1 R REPACK performing final cleanup relid=rp; 26 (none) [max bytes: 0; sent: 0] ------------------------------------------------------------------------ cluster: CLUSTER rp USING rp_a 77bba5454f9: 2907 samples: 538 R CLUSTER index scanning heap relid=rp; 2325 R CLUSTER rebuilding index relid=rp; 1 R CLUSTER performing final cleanup relid=rp; 43 (none) [max bytes: 0; sent: 0] 0001: 2994 samples: 571 R CLUSTER index scanning heap relid=rp; 1211 I REINDEX building index: scanning table relid=rp; 378 I REINDEX building index: sorting live tuples relid=rp; 793 I REINDEX building index: loading tuples in tree relid=rp; 1 I REINDEX initializing relid=rp; 40 (none) [max bytes: 0; sent: 0] 0001 no asserts: 2685 samples: 1 R CLUSTER initializing relid=rp; 469 R CLUSTER index scanning heap relid=rp; 1035 I REINDEX building index: scanning table relid=rp; 337 I REINDEX building index: sorting live tuples relid=rp; 790 I REINDEX building index: loading tuples in tree relid=rp; 1 R CLUSTER performing final cleanup relid=rp; 52 (none) [max bytes: 0; sent: 0] ------------------------------------------------------------------------ vacuum_full: VACUUM FULL rp 77bba5454f9: 3403 samples: 350 R VACUUM FULL seq scanning heap relid=rp; 2979 R VACUUM FULL rebuilding index relid=rp; 74 (none) [max bytes: 0; sent: 0] 0001: 2773 samples: 458 R VACUUM FULL seq scanning heap relid=rp; 1 I REINDEX initializing relid=rp; 1201 I REINDEX building index: scanning table relid=rp; 356 I REINDEX building index: sorting live tuples relid=rp; 728 I REINDEX building index: loading tuples in tree relid=rp; 29 (none) [max bytes: 0; sent: 0] 0001 no asserts: 2318 samples: 307 R VACUUM FULL seq scanning heap relid=rp; 1035 I REINDEX building index: scanning table relid=rp; 357 I REINDEX building index: sorting live tuples relid=rp; 584 I REINDEX building index: loading tuples in tree relid=rp; 1 I REINDEX initializing relid=rp; 34 (none) [max bytes: 0; sent: 0] ------------------------------------------------------------------------ P8: TopMemoryContext used_bytes of one session 77bba5454f9: start: TopMemoryContext total 124064 used 96272 after 10000 nested COPY TO inside COPY FROM: TopMemoryContext total 124064 used 99472 after 10000 errors caught inside COPY FROM: TopMemoryContext total 124064 used 100512 after 10000 errors caught in a DO block: TopMemoryContext total 124064 used 100512 after 10000 top-level errors in a nested COPY: TopMemoryContext total 124064 used 101552 errors: 10000 0001: start: TopMemoryContext total 124064 used 96272 after 10000 nested COPY TO inside COPY FROM: TopMemoryContext total 124064 used 99472 after 10000 errors caught inside COPY FROM: TopMemoryContext total 124064 used 100512 after 10000 errors caught in a DO block: TopMemoryContext total 124064 used 100784 after 10000 top-level errors in a nested COPY: TopMemoryContext total 4252832 used 2822064 errors: 10000 0001 no asserts: start: TopMemoryContext total 124032 used 95912 after 10000 nested COPY TO inside COPY FROM: TopMemoryContext total 124032 used 99080 after 10000 errors caught inside COPY FROM: TopMemoryContext total 124032 used 100112 after 10000 errors caught in a DO block: TopMemoryContext total 124032 used 100376 after 10000 top-level errors in a nested COPY: TopMemoryContext total 4252800 used 2741648 errors: 10000 ------------------------------------------------------------------------ server log: TRAP, PANIC or "terminated by signal" 77bba5454f9: (nothing) 0001: (nothing) 0001 no asserts: (nothing) ------------------------------------------------------------------------ P9 over all three runs: share of the samples with no pg_stat_progress_repack row (and with a pg_stat_progress_create_index row instead) 77bba5454f9 r1: repack: 2791, 15 no repack row (0.5%), 0 create_index (0.0%) 77bba5454f9 r1: cluster: 2907, 43 no repack row (1.5%), 0 create_index (0.0%) 77bba5454f9 r1: vacuum_full: 3403, 74 no repack row (2.2%), 0 create_index (0.0%) 77bba5454f9 r2: repack: 3012, 14 no repack row (0.5%), 0 create_index (0.0%) 77bba5454f9 r2: cluster: 3038, 35 no repack row (1.2%), 0 create_index (0.0%) 77bba5454f9 r2: vacuum_full: 3618, 40 no repack row (1.1%), 0 create_index (0.0%) 77bba5454f9 r3: repack: 2539, 33 no repack row (1.3%), 0 create_index (0.0%) 77bba5454f9 r3: cluster: 2904, 54 no repack row (1.9%), 0 create_index (0.0%) 77bba5454f9 r3: vacuum_full: 2580, 25 no repack row (1.0%), 0 create_index (0.0%) 0001 r1: repack: 2672, 2251 no repack row (84.2%), 2214 create_index (82.9%) 0001 r1: cluster: 2994, 2423 no repack row (80.9%), 2383 create_index (79.6%) 0001 r1: vacuum_full: 2773, 2315 no repack row (83.5%), 2286 create_index (82.4%) 0001 r2: repack: 2702, 2344 no repack row (86.8%), 2318 create_index (85.8%) 0001 r2: cluster: 2993, 2465 no repack row (82.4%), 2420 create_index (80.9%) 0001 r2: vacuum_full: 3295, 2672 no repack row (81.1%), 2642 create_index (80.2%) 0001 r3: repack: 2405, 2114 no repack row (87.9%), 2080 create_index (86.5%) 0001 r3: cluster: 2654, 2137 no repack row (80.5%), 2122 create_index (80.0%) 0001 r3: vacuum_full: 2717, 2380 no repack row (87.6%), 2345 create_index (86.3%) 0001 no asserts r1: repack: 2368, 2019 no repack row (85.3%), 1993 create_index (84.2%) 0001 no asserts r1: cluster: 2685, 2214 no repack row (82.5%), 2162 create_index (80.5%) 0001 no asserts r1: vacuum_full: 2318, 2011 no repack row (86.8%), 1977 create_index (85.3%) 0001 no asserts r2: repack: 2301, 2008 no repack row (87.3%), 1961 create_index (85.2%) 0001 no asserts r2: cluster: 2489, 2058 no repack row (82.7%), 2015 create_index (81.0%) 0001 no asserts r2: vacuum_full: 2314, 2030 no repack row (87.7%), 1995 create_index (86.2%) 0001 no asserts r3: repack: 2179, 1888 no repack row (86.6%), 1875 create_index (86.0%) 0001 no asserts r3: cluster: 2331, 1945 no repack row (83.4%), 1900 create_index (81.5%) 0001 no asserts r3: vacuum_full: 2376, 2131 no repack row (89.7%), 2106 create_index (88.6%)