1/ Create tables as below ========================= Create a test database. Then, run below commands: CREATE TABLE T_1M (id integer, md5 text); INSERT INTO T_1M SELECT generate_series(1,1000000) AS id, md5(random()::text) AS md5; ANALYZE t_1m; CREATE TABLE T_10M ( id integer, md5 text); INSERT INTO T_10M SELECT generate_series(1,10000000) AS id, md5(random()::text) AS md5; ANALYZE t_10m; CREATE VIEW PRG AS SELECT pid, query FROM pg_stat_activity; SELECT * from PRG; 2/ Start 2 psql session as below ================================ => Terminal 1, we start the monitoring psql session: [pgadm@rco ~]$ psql -d test psql (10devel) Type "help" for help. test=# => Terminal 2, we start the monitored psql session: [pgadm@rco ~]$ psql -A -d test psql (10devel) Type "help" for help. test=# Redirect output to file to avoid blocking on psql terminal test=# \o out => Terminal 1 (Monitoring backend): get the pid of the process to be monitored: test=# select pid, query from pg_stat_activity ; pid | query -------+-------------------------------------------------------------------------------------------------------------------------------------------------------- --------------------------------------------------------------------------------------------------------------------------------------- 13162 | 13164 | 14609 | select pid, query from pg_stat_activity ; 14611 | SELECT c.oid::pg_catalog.regclass, pg_get_expr(c.relpartbound, c.oid) FROM pg_catalog.pg_class c, pg_catalog.pg_inherits i WHERE c.oid=i.inhrelid AND i .inhparent = '16391' AND EXISTS (SELECT 1 FROM pg_class c WHERE c.oid = '16391') ORDER BY c.oid::pg_catalog.regclass::pg_catalog.text; 13160 | 13159 | 13161 | (7 rows) test=# Process backend with pid 14611 is the one of psql session opened in terminal 2. test=# PROGRESS 14611; PLAN PROGRESS ---------------- (1 row) test=# 3/ Example 1 ============ => Terminal 1: redirect output test=# \o out => Terminal 1 test=# select * from t_10M order by md5; => Terminal 2 test=# PROGRESS 9546; PLAN PROGRESS -------------------------------------------------------------------------------------------------------------- status: query: select * from t_10M order by md5; time used (s): 30 Gather Merge worker child: 11850 -> Sort on tapes final merge => rows r/w merge 4937353/4223486 sort 713852/3264290 21% tape blocks 18775 Sort Key: md5 -> Parallel Seq Scan on t_10m => rows 3264291/3806198 85% worker child: 11849 -> Sort on tapes final merge => rows r/w merge 5337584/4578133 sort 759436/3473270 21% tape blocks 19978 Sort Key: md5 -> Parallel Seq Scan on t_10m => rows 3473271/3806198 91% worker parent: 9546 -> Sort on tapes final merge => rows r/w merge 4936087/4223292 sort 712780/3262440 21% tape blocks 18765 Sort Key: md5 -> Parallel Seq Scan on t_10m => rows 3262441/3806198 85% total disk space used (MB) 449 (17 rows) test=# 4/ Example 2 ============ => Terminal 1 test=# select a.md5 from t_10m a, t_10m b where a.md5=b.md5 order by a.md5; => Terminal 2 test=# PROGRESS 9546; PLAN PROGRESS ------------------------------------------------------------------------------------------------ status: query: select a.md5 from t_10m a, t_10m b where a.md5=b.md5 order by a.md5; time used (s): 5 Gather Merge worker child: 11888 -> Sort in memory loading tuples 0 Sort Key: a.md5 -> Hash Join => hashtable nbatch 256 kbytes r/w 0/283064, disk use (bytes) 289857536 Hash Cond: (a.md5 = b.md5) -> Parallel Seq Scan on t_10m => rows 1/3806198 0% => blks 3/83334 0% -> Hash => hashtable nbatch 256 kbytes r/w 0/283064, disk use (bytes) 289857536 Buckets: 65536 Batches: 256 Memory Usage: 1364kB -> Seq Scan on t_10m => rows 5509969/9134874 60% => blks 45916/83334 55% worker child: 11887 -> Sort in memory loading tuples 0 Sort Key: a.md5 -> Hash Join => hashtable nbatch 256 kbytes r/w 0/273368, disk use (bytes) 279928832 Hash Cond: (a.md5 = b.md5) -> Parallel Seq Scan on t_10m => rows 1/3806198 0% => blks 3/83334 0% -> Hash => hashtable nbatch 256 kbytes r/w 0/273368, disk use (bytes) 279928832 Buckets: 65536 Batches: 256 Memory Usage: 1321kB -> Seq Scan on t_10m => rows 5323058/9134874 58% => blks 44358/83334 53% worker parent: 9546 -> Sort in memory loading tuples 0 Sort Key: a.md5 -> Hash Join => hashtable nbatch 256 kbytes r/w 0/274304, disk use (bytes) 280887296 Hash Cond: (a.md5 = b.md5) -> Parallel Seq Scan on t_10m => rows 1/3806198 0% => blks 3/83334 0% -> Hash => hashtable nbatch 256 kbytes r/w 0/274304, disk use (bytes) 280887296 Buckets: 65536 Batches: 256 Memory Usage: 1325kB -> Seq Scan on t_10m => rows 5339905/9134874 58% => blks 44499/83334 53% total disk space used (GB) 1 (32 rows) test=# 5/ Example 3 ============ => Terminal 1 test=# select ctid from t_10m order by ctid; => Terminal 2 test=# PROGRESS 9546; PLAN PROGRESS ----------------------------------------------------------------------------------------------- status: query: select ctid from t_10m order by ctid; time used (s): 4 Sort on tapes merging => rows r/w merge 4860558/4860545 sort 0/10000000 0% tape blocks 19581 Sort Key: ctid -> Seq Scan on t_10m => rows 10000001/9134874 109% total disk space used (MB) 152 (7 rows) test=# 6/ Example 4 ============ => Terminal 1 test=# select distinct * from t_10m; => Terminal 2 test=# PROGRESS 9546; PLAN PROGRESS ----------------------------------------------------------------------------------- status: query: select distinct * from t_10m; time used (s): 2 Unique -> Sort => rows r/w merge 0/0 sort 0/5753440 0% tape blocks 33083 Sort Key: id, md5 -> Seq Scan on t_10m => rows 5778817/9134874 63% => blks 48157/83334 57% total disk space used (MB) 258 (8 rows) test=# 7/ Example 5 ============ =>> Example 5 => Terminal 1 test=# select t_10m.id, t_1m.id, t_10m.md5 from t_10m, t_1m where t_10m.md5 = t_1m.md5; => Terminal 2 test=# PROGRESS 9546; PLAN PROGRESS ----------------------------------------------------------------------------------------- status: query: select t_10m.id, t_1m.id, t_10m.md5 from t_10m, t_1m where t_10m.md5 = t_1m.md5; time used (s): 2 Hash Join => hashtable nbatch 256 kbytes r/w 0/392768, disk use (bytes) 402194432 Hash Cond: (t_1m.md5 = t_10m.md5) -> Seq Scan on t_1m => rows 1/1000000 0% => blks 8334/8334 100% -> Hash => hashtable nbatch 256 kbytes r/w 0/392768, disk use (bytes) 402194432 Buckets: 65536 Batches: 256 Memory Usage: 1868kB -> Seq Scan on t_10m => rows 7102241/9134874 77% => blks 59186/83334 71% total disk space used (MB) 767 (10 rows) test=# 8/ Example 6 ============ => Terminal 1 test=# select * from t_10m, t_1m where t_10m.md5 like '%cb%'; => Terminal 2 test=# PROGRESS 9546; PLAN PROGRESS ---------------------------------------------------------------------------------------------------------- status: query: select * from t_10m, t_1m where t_10m.md5 like '%cb%'; time used (s): 14 Nested Loop -> Seq Scan on t_1m => rows 13/1000000 0% => blks 8334/8334 100% -> Materialize => file read readptrcount=1 rows write=1189285 read=12750226 disk use (bytes) 53842965 -> Seq Scan on t_10m => rows 1145596/738172 155% Filter: (md5 ~~ '%cb%'::text) total disk space used (MB) 51 (9 rows) test=# Above Seq Scan on table t_1m shows the query will be very long to complete because it has used 14 seconds and only performed the loop for 13 rows out of 1000000. So this will be completed within days. 9/ Example 7 ============ => Terminal 1 test=# select * from t_10m where md5 in (select t_1m.md5 from t_1m where t_1m.id > t_10m.id order by t_1m.id); => Terminal 2 test=# PROGRESS 9546; PLAN PROGRESS ---------------------------------------------------------------------------------------------------------------- status: query: select * from t_10m where md5 in (select t_1m.md5 from t_1m where t_1m.id > t_10m.id order by t_1m.id); time used (s): 10 Seq Scan on t_10m => rows 0/4567437 0% => blks 1/83334 0% Filter: (SubPlan 1) SubPlan 1 -> Sort in memory loading tuples 0 Sort Key: t_1m.id -> Seq Scan on t_1m => rows 126/333333 0% => blks 2833/8334 33% Filter: (id > t_10m.id) total disk space used (B) 0 (11 rows) test=# 10/ Example 8 ============= => Terminal 1 test=# select * from t_10m, t_1m where t_10m.md5 like '%cb%'; => Terminal 2 test=# \watch PROGRESS 9546; Wed 10 May 2017 06:29:59 PM CEST (every 1s) PLAN PROGRESS --------------------------------------------------------------------------------------------------------- status: query: select * from t_10m, t_1m where t_10m.md5 like '%cb%'; time used (s): 10 Nested Loop -> Seq Scan on t_1m => rows 7/1000000 0% => blks 8334/8334 100% -> Materialize => file read readptrcount=1 rows write=1189285 read=6584854 disk use (bytes) 53842965 -> Seq Scan on t_10m => rows 1145596/738172 155% Filter: (md5 ~~ '%cb%'::text) total disk space used (MB) 51 (9 rows) Wed 10 May 2017 06:30:00 PM CEST (every 1s) PLAN PROGRESS --------------------------------------------------------------------------------------------------------- status: query: select * from t_10m, t_1m where t_10m.md5 like '%cb%'; time used (s): 11 Nested Loop -> Seq Scan on t_1m => rows 8/1000000 0% => blks 8334/8334 100% -> Materialize => file read readptrcount=1 rows write=1189285 read=7649991 disk use (bytes) 53842965 -> Seq Scan on t_10m => rows 1145596/738172 155% Filter: (md5 ~~ '%cb%'::text) total disk space used (MB) 51 (9 rows) Wed 10 May 2017 06:30:01 PM CEST (every 1s) PLAN PROGRESS --------------------------------------------------------------------------------------------------------- status: query: select * from t_10m, t_1m where t_10m.md5 like '%cb%'; time used (s): 12 Nested Loop -> Seq Scan on t_1m => rows 9/1000000 0% => blks 8334/8334 100% -> Materialize => file read readptrcount=1 rows write=1189285 read=8827496 disk use (bytes) 53842965 -> Seq Scan on t_10m => rows 1145596/738172 155% Filter: (md5 ~~ '%cb%'::text) total disk space used (MB) 51 (9 rows) ... 11/ Example 9 ============= Use with json output: => Terminal 1 test=# select * from t_10m, t_1m where t_10m.md5 like '%cb%'; => Terminal 2 test=# PROGRESS (FORMAT JSON) 9546; PLAN PROGRESS ---------------------------------------------------------------------- [ + "status": "", + "query": "select * from t_10m, t_1m where t_10m.md5 like '%cb%';",+ "time used (s)": 0, + "single worker": { + "Node Type": "Nested Loop", + "Partial Mode": "", + "Operation": "single worker", + "Parent Relationship": "single worker", + "Custom Plan Provider": "(@\u0004\u0001", + "Parallel Aware": false, + "Outer": { + "Node Type": "Seq Scan", + "Strategy": "", + "Partial Mode": "single worker", + "Operation": "Outer", + "Parent Relationship": "Outer", + "Custom Plan Provider": "(@\u0004\u0001", + "Parallel Aware": false, + "relation": "t_1m", + "rows fetched": 1, + "rows total": 1000000, + "rows percent": 0, + "blocks fetched": 8334, + "blocks total": 8334, + "blocks percent": 100 + }, + "Inner": { + "Node Type": "Materialize", + "Strategy": "", + "Partial Mode": "single worker", + "Operation": "Inner", + "Parent Relationship": "Inner", + "Custom Plan Provider": "(@\u0004\u0001", + "Parallel Aware": false, + "file store": "write", + "readptrcount": 1, + "rows write": 297256, + "rows read": 0, + "disk use (bytes)": 11911168, + "Outer": { + "Node Type": "Seq Scan", + "Strategy": "", + "Partial Mode": "Inner", + "Operation": "Outer", + "Parent Relationship": "Outer", + "Custom Plan Provider": "HtFH\b[]\u000f\u001f", + "Parallel Aware": false, + "relation": "t_10m", + "rows fetched": 253566, + "rows total": 738172, + "rows percent": 34, + "blocks fetched": 18436, + "blocks total": 83334, + "blocks percent": 22, + "Filter": "(md5 ~~ '%cb%'::text)" + } + } + }, + "unit": "MB", + "total disk space used": 11 + ] (1 row) test=#