|
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 | +sub query_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(); |
0 commit comments