|
8 | 8 | use PostgreSQL::Test::Utils; |
9 | 9 | use Test::More; |
10 | 10 |
|
| 11 | +# Runs the specified query and returns the emitted server log. |
| 12 | +# params is an optional hash mapping GUC names to values; |
| 13 | +# any such settings are transmitted to the backend via PGOPTIONS. |
| 14 | +subquery_log |
| 15 | +{ |
| 16 | +my ($node,$sql,$params) =@_; |
| 17 | +$params ||= {}; |
| 18 | + |
| 19 | +local$ENV{PGOPTIONS} =join"", |
| 20 | +map {"-c$_=$params->{$_}" }keys%$params; |
| 21 | + |
| 22 | +my$log =$node->logfile(); |
| 23 | +my$offset =-s$log; |
| 24 | + |
| 25 | +$node->safe_psql("postgres",$sql); |
| 26 | + |
| 27 | +return slurp_file($log,$offset); |
| 28 | +} |
| 29 | + |
11 | 30 | my$node = PostgreSQL::Test::Cluster->new('main'); |
12 | 31 | $node->init; |
13 | 32 | $node->append_conf('postgresql.conf', |
14 | | -"shared_preload_libraries = 'auto_explain'"); |
| 33 | +"session_preload_libraries = 'auto_explain'"); |
15 | 34 | $node->append_conf('postgresql.conf',"auto_explain.log_min_duration = 0"); |
16 | 35 | $node->append_conf('postgresql.conf',"auto_explain.log_analyze = on"); |
17 | 36 | $node->start; |
18 | 37 |
|
19 | | -# run a couple of queries |
20 | | -$node->safe_psql("postgres","SELECT * FROM pg_class;"); |
21 | | -$node->safe_psql("postgres", |
22 | | -"SELECT * FROM pg_proc WHERE proname = 'int4pl';"); |
| 38 | +# Simple query. |
| 39 | +my$log_contents = query_log($node,"SELECT * FROM pg_class;"); |
23 | 40 |
|
24 | | -# emit some json too |
25 | | -$node->append_conf('postgresql.conf',"auto_explain.log_format = json"); |
26 | | -$node->reload; |
27 | | -$node->safe_psql("postgres","SELECT * FROM pg_proc;"); |
28 | | -$node->safe_psql("postgres", |
29 | | -"SELECT * FROM pg_class WHERE relname = 'pg_class';"); |
30 | | - |
31 | | -$node->stop('fast'); |
32 | | - |
33 | | -my$log =$node->logfile(); |
| 41 | +like( |
| 42 | +$log_contents, |
| 43 | +qr/Query Text: SELECT\* FROM pg_class;/, |
| 44 | +"query text logged, text mode"); |
34 | 45 |
|
35 | | -my$log_contents = slurp_file($log); |
| 46 | +unlike( |
| 47 | +$log_contents, |
| 48 | +qr/Query Parameters:/, |
| 49 | +"no query parameters logged when none, text mode"); |
36 | 50 |
|
37 | 51 | like( |
38 | 52 | $log_contents, |
39 | 53 | qr/Seq Scan on pg_class/, |
40 | 54 | "sequential scan logged, text mode"); |
41 | 55 |
|
| 56 | +# Prepared query. |
| 57 | +$log_contents = query_log($node, |
| 58 | +q{PREPARE get_proc(name) AS SELECT * FROM pg_proc WHERE proname = $1; EXECUTE get_proc('int4pl');} |
| 59 | +); |
| 60 | + |
| 61 | +like( |
| 62 | +$log_contents, |
| 63 | +qr/Query Text: PREPARE get_proc\(name\) AS SELECT\* FROM pg_proc WHERE proname =\$1;/, |
| 64 | +"prepared query text logged, text mode"); |
| 65 | + |
42 | 66 | like( |
43 | 67 | $log_contents, |
44 | 68 | qr/Index Scan using pg_proc_proname_args_nsp_index on pg_proc/, |
45 | 69 | "index scan logged, text mode"); |
46 | 70 |
|
| 71 | + |
| 72 | +# JSON format. |
| 73 | +$log_contents = query_log( |
| 74 | +$node, |
| 75 | +"SELECT * FROM pg_class;", |
| 76 | +{"auto_explain.log_format"=>"json" }); |
| 77 | + |
| 78 | +like( |
| 79 | +$log_contents, |
| 80 | +qr/"Query Text": "SELECT\* FROM pg_class;"/, |
| 81 | +"query text logged, json mode"); |
| 82 | + |
| 83 | +unlike( |
| 84 | +$log_contents, |
| 85 | +qr/"Query Parameters":/, |
| 86 | +"query parameters not logged when none, json mode"); |
| 87 | + |
47 | 88 | like( |
48 | 89 | $log_contents, |
49 | | -qr/"Node Type": "Seq Scan"[^}]*"Relation Name": "pg_proc"/s, |
| 90 | +qr/"Node Type": "Seq Scan"[^}]*"Relation Name": "pg_class"/s, |
50 | 91 | "sequential scan logged, json mode"); |
51 | 92 |
|
| 93 | +# Prepared query in JSON format. |
| 94 | +$log_contents = query_log( |
| 95 | +$node, |
| 96 | +q{PREPARE get_class(name) AS SELECT * FROM pg_class WHERE relname = $1; EXECUTE get_class('pg_class');}, |
| 97 | +{"auto_explain.log_format"=>"json" }); |
| 98 | + |
| 99 | +like( |
| 100 | +$log_contents, |
| 101 | +qr/"Query Text": "PREPARE get_class\(name\) AS SELECT\* FROM pg_class WHERE relname =\$1;"/, |
| 102 | +"prepared query text logged, json mode"); |
| 103 | + |
52 | 104 | like( |
53 | 105 | $log_contents, |
54 | 106 | qr/"Node Type": "Index Scan"[^}]*"Index Name": "pg_class_relname_nsp_index"/s, |
55 | 107 | "index scan logged, json mode"); |
56 | 108 |
|
| 109 | +# Check that PGC_SUSET parameters can be set by non-superuser if granted, |
| 110 | +# otherwise not |
| 111 | + |
| 112 | +$node->safe_psql( |
| 113 | +"postgres",q{ |
| 114 | +CREATE USER regress_user1; |
| 115 | +GRANT SET ON PARAMETER auto_explain.log_format TO regress_user1; |
| 116 | +}); |
| 117 | + |
| 118 | +$ENV{PGUSER} ="regress_user1"; |
| 119 | + |
| 120 | +$log_contents = query_log( |
| 121 | +$node, |
| 122 | +"SELECT * FROM pg_database;", |
| 123 | +{"auto_explain.log_format"=>"json" }); |
| 124 | + |
| 125 | +like( |
| 126 | +$log_contents, |
| 127 | +qr/"Query Text": "SELECT\* FROM pg_database;"/, |
| 128 | +"query text logged, json mode selected by non-superuser"); |
| 129 | + |
| 130 | +$log_contents = query_log( |
| 131 | +$node, |
| 132 | +"SELECT * FROM pg_database;", |
| 133 | +{"auto_explain.log_level"=>"log" }); |
| 134 | + |
| 135 | +like( |
| 136 | +$log_contents, |
| 137 | +qr/WARNING: permission denied to set parameter "auto_explain\.log_level"/, |
| 138 | +"permission failure logged"); |
| 139 | + |
| 140 | +$ENV{PGUSER} =undef; |
| 141 | + |
| 142 | +$node->safe_psql( |
| 143 | +"postgres",q{ |
| 144 | +REVOKE SET ON PARAMETER auto_explain.log_format FROM regress_user1; |
| 145 | +DROP USER regress_user1; |
| 146 | +}); |
| 147 | + |
57 | 148 | done_testing(); |