2021-05-07 16:56:14 +02:00
|
|
|
|
2022-01-08 01:04:57 +01:00
|
|
|
# Copyright (c) 2021-2022, PostgreSQL Global Development Group
|
2021-05-07 16:56:14 +02:00
|
|
|
|
2021-01-24 20:59:33 +01:00
|
|
|
use strict;
|
|
|
|
use warnings;
|
|
|
|
|
2021-10-24 16:28:19 +02:00
|
|
|
use PostgreSQL::Test::Cluster;
|
|
|
|
use PostgreSQL::Test::Utils;
|
2022-02-11 20:54:44 +01:00
|
|
|
use Test::More;
|
2021-01-24 20:59:33 +01:00
|
|
|
|
2022-07-01 02:13:57 +02:00
|
|
|
# Runs the specified query and returns the emitted server log.
|
|
|
|
# If any parameters are specified, these are set in postgresql.conf,
|
|
|
|
# and reset after the query is run.
|
|
|
|
sub query_log
|
|
|
|
{
|
|
|
|
my ($node, $sql, $params) = @_;
|
|
|
|
$params ||= {};
|
|
|
|
|
|
|
|
if (keys %$params)
|
|
|
|
{
|
|
|
|
for my $key (keys %$params)
|
|
|
|
{
|
|
|
|
$node->append_conf('postgresql.conf', "$key = $params->{$key}\n");
|
|
|
|
}
|
|
|
|
$node->reload;
|
|
|
|
}
|
|
|
|
|
|
|
|
my $log = $node->logfile();
|
|
|
|
my $offset = -s $log;
|
|
|
|
|
|
|
|
$node->safe_psql("postgres", $sql);
|
|
|
|
|
|
|
|
my $log_contents = slurp_file($log, $offset);
|
|
|
|
|
|
|
|
if (keys %$params)
|
|
|
|
{
|
|
|
|
for my $key (keys %$params)
|
|
|
|
{
|
|
|
|
$node->adjust_conf('postgresql.conf', $key, undef);
|
|
|
|
}
|
|
|
|
$node->reload;
|
|
|
|
}
|
|
|
|
|
|
|
|
return $log_contents;
|
|
|
|
}
|
|
|
|
|
2021-10-24 16:28:19 +02:00
|
|
|
my $node = PostgreSQL::Test::Cluster->new('main');
|
2021-01-24 20:59:33 +01:00
|
|
|
$node->init;
|
|
|
|
$node->append_conf('postgresql.conf',
|
|
|
|
"shared_preload_libraries = 'auto_explain'");
|
|
|
|
$node->append_conf('postgresql.conf', "auto_explain.log_min_duration = 0");
|
|
|
|
$node->append_conf('postgresql.conf', "auto_explain.log_analyze = on");
|
|
|
|
$node->start;
|
|
|
|
|
2022-07-01 02:13:57 +02:00
|
|
|
# Simple query.
|
|
|
|
my $log_contents = query_log($node, "SELECT * FROM pg_class;");
|
2021-01-24 20:59:33 +01:00
|
|
|
|
2022-07-01 02:13:57 +02:00
|
|
|
like(
|
|
|
|
$log_contents,
|
|
|
|
qr/Query Text: SELECT \* FROM pg_class;/,
|
|
|
|
"query text logged, text mode");
|
2021-01-24 20:59:33 +01:00
|
|
|
|
|
|
|
like(
|
|
|
|
$log_contents,
|
|
|
|
qr/Seq Scan on pg_class/,
|
|
|
|
"sequential scan logged, text mode");
|
|
|
|
|
2022-07-01 02:13:57 +02:00
|
|
|
# Prepared query.
|
|
|
|
$log_contents = query_log($node,
|
|
|
|
q{PREPARE get_proc(name) AS SELECT * FROM pg_proc WHERE proname = $1; EXECUTE get_proc('int4pl');}
|
|
|
|
);
|
|
|
|
|
|
|
|
like(
|
|
|
|
$log_contents,
|
|
|
|
qr/Query Text: PREPARE get_proc\(name\) AS SELECT \* FROM pg_proc WHERE proname = \$1;/,
|
|
|
|
"prepared query text logged, text mode");
|
|
|
|
|
2021-01-24 20:59:33 +01:00
|
|
|
like(
|
|
|
|
$log_contents,
|
|
|
|
qr/Index Scan using pg_proc_proname_args_nsp_index on pg_proc/,
|
|
|
|
"index scan logged, text mode");
|
|
|
|
|
2022-07-01 02:13:57 +02:00
|
|
|
# JSON format.
|
|
|
|
$log_contents = query_log(
|
|
|
|
$node,
|
|
|
|
"SELECT * FROM pg_proc;",
|
|
|
|
{ "auto_explain.log_format" => "json" });
|
|
|
|
|
|
|
|
like(
|
|
|
|
$log_contents,
|
|
|
|
qr/"Query Text": "SELECT \* FROM pg_proc;"/,
|
|
|
|
"query text logged, json mode");
|
|
|
|
|
2021-01-24 20:59:33 +01:00
|
|
|
like(
|
|
|
|
$log_contents,
|
|
|
|
qr/"Node Type": "Seq Scan"[^}]*"Relation Name": "pg_proc"/s,
|
|
|
|
"sequential scan logged, json mode");
|
|
|
|
|
2022-07-01 02:13:57 +02:00
|
|
|
# Prepared query in JSON format.
|
|
|
|
$log_contents = query_log(
|
|
|
|
$node,
|
|
|
|
q{PREPARE get_class(name) AS SELECT * FROM pg_class WHERE relname = $1; EXECUTE get_class('pg_class');},
|
|
|
|
{ "auto_explain.log_format" => "json" });
|
|
|
|
|
|
|
|
like(
|
|
|
|
$log_contents,
|
|
|
|
qr/"Query Text": "PREPARE get_class\(name\) AS SELECT \* FROM pg_class WHERE relname = \$1;"/,
|
|
|
|
"prepared query text logged, json mode");
|
|
|
|
|
2021-01-24 20:59:33 +01:00
|
|
|
like(
|
|
|
|
$log_contents,
|
|
|
|
qr/"Node Type": "Index Scan"[^}]*"Index Name": "pg_class_relname_nsp_index"/s,
|
|
|
|
"index scan logged, json mode");
|
2022-02-11 20:54:44 +01:00
|
|
|
|
|
|
|
done_testing();
|