PL/pgSQL
Debugging
12
Copyright
© Postgres Professional, 2017–2021
Authors: Egor Rogov, Pavel Luzanov
Translated by Liudmila Mantrova
Usage of Course Materials
Non-commercial use of course materials (presentations, demonstrations) is
allowed on an unrestricted basis. Commercial use is only possible with prior
written permission of Postgres Professional company. Modification of course
materials is forbidden.
Contact Us
Please send your feedback to: edu@postgrespro.ru
Disclaimer
In no event shall Postgres Professional company be liable for any damages
or loss, including loss of profits, that arise from direct or indirect, special or
incidental use of course materials. Postgres Professional company
specifically disclaims any warranties on course materials. Course materials
are provided “as is,” and Postgres Professional company has no obligations
to provide maintenance, support, updates, enhancements, or modifications.
2
Agenda
Correctness checks
PL/pgSQL debugger
Debugging messages and their various implementations
Session tracing
3
Correctness Checks
Сompile-time and run-time checks
plpgsql.extra_warnings
plpgsql.extra_errors
additional checks provided by the plpgsql_check extension
Built-in checks
the ASSERT command
Testing
Debugging implies executing a program and analyzing the occurred issues,
typically by running a special debugger or by displaying debug messages.
But you can also avoid some particular error classes if you enable compile-
time and run-time verification of source code. It is controlled by
plpgsql.extra_warnings and plpgsql.extra_errors parameters, as explained
in the “PL/pgSQL. Executing Queries” lecture.
That lecture also introduces the plpgsql_check extension, which offers a
wider range of checks.
Another way to make your code more secure is to check for conditions that
must always hold true (the so-called sanity checks). A convenient way to do
it is to use the ASSERT command.
We must also mention the importance of testing the code. Apart from
making sure from the very beginning that the code works as expected,
testing also facilitates further maintenance: it ensures that the existing
functionality is not broken by the introduced changes. We will not expand
on this topic; but it’s worth noting that testing the code that accesses a
database can turn out to be quite tricky as you have to prepare test cases.
5
PL/pgSQL Debugger
Interface
the API is provided as an extension (pldbgapi)
built-in support is available in some GUI IDEs
Features
setting breakpoints
step-by-step execution
checking and setting variable values
no need to modify the code
debugging applications at run time
As its name suggests, PL/pgSQL Debugger is a debugging utility for
PL/pgSQL. It is delivered as the pldbgapi extension, which is officially
supported by PostgreSQL developers.
The pldbgapi extension is a collection of interface functions for the
PostgreSQL server that enable you to set breakpoints, execute the
application code step-by-step, check and set variable values.
There is no need to modify the source code of the application to debug,
so debugging can be performed at run time. In other words, you do not
have to restart the process with an attached debugger, you can simply
connect to the current session and start debugging it.
It is inconvenient to use these functions directly; they are mainly targeted
for IDEs with graphical user interface. Some of these IDEs (including
pgAdmin) have a convenient built-in debugging user interface. But in order
to use it, you still have to install the pldbgapi extension into the
corresponding database first.
The source code of pldbgapi is available at:
6
Debug Messages
Not only debugging
monitoring long-running processes
writing an application log
Implementation strategies
directing debug output to the terminal or to the server log file
saving messages in a table or in a file
passing information to other processes
Another debugging approach consists in adding debug messages to the key
parts of the code to provide the current context. As you analyze these
messages, you can understand what exactly has gone wrong.
Apart from the debugging itself, debug messages can also perform other
functions. They can indicate the execution stage of a long-running process.
Similar to a database system, an application can write its own log. Having
such a log with important data (e.g., report-related data: the name of the
report, the user who has collected it, date, parameters, etc.) can greatly
facilitate technical support.
We can single out several strategies of implementing debug messages in
PL/pgSQL. Apart from using the already familiar RAISE command, which
can display messages in the terminal (or save them into the server log), it is
also possible to send messages to another process, as well as write them
into a table or into a file.
When choosing the approach to use, you have to take a lot of different
aspects into account. Are messages transactional (are they sent before the
end of the transaction or only after it has been committed)? Can you send
them from several sessions simultaneously? How can you set up access to
the log file and clean up old log entries? How does logging affect
performance? Do you have to modify the source code?
7
RAISE Command
DEBUG
LOG
NOTICE
INFO
WARNING
RAISE
DEBUG INFO NOTICE WARNING ERROR LOG FATAL PANIC
log_min_messages
Server log
DEBUG LOG NOTICE WARNING ERROR FATAL PANIC
client_min_messages
Client
We are already familiar with the RAISE command. It can be used both to
raise exceptions (which is discussed in detail in lecture “PL/pgSQL. Error
Handling”) and to emit messages. Such messages can be either sent to the
client or written to the server log.
In a simple debugging case, you have to add RAISE NOTICE calls to the
function code, start the function execution (for example, in a psql session),
and analyze the received messages as the execution progresses. RAISE
messages are non-transactional: they are emitted asynchronously and do
not depend on the transaction status.
Message delivery is controlled by message levels (DEBUG, LOG, NOTICE,
INFO, WARNING) and server parameters. Parameter values determine
whether a message will be sent to the client (client_min_messages) and/or
written to the server log (log_min_messages). A message will be sent if the
RAISE command level is not lower than the value of the corresponding
parameter (is shown to the right of the parameter value on this slide).
In the default configuration, NOTICE messages are only sent to the client,
LOG messages are only written to the log file, and WARNING messages are
both sent to the client and written to the log file.
INFO messages are always sent to the client; they cannot be trapped using
the client_min_messages parameter.
9
Process→Process (IPC)
NOTIFY → LISTEN
SQL commands
transactional execution is inconvenient for debugging
Session status
the application_name parameter
is visible in the pg_stat_activity view and in the output of the ps
command
can be used in log messages
In PostgreSQL, server processes can communicate between each other.
Among the built-in solutions, the following are worth noting.
●
Sending messages via the NOTIFY command in one process and getting
them via LISTEN in another. But since these commands are
transactional, it is inconvenient to use them for debugging:
1. Messages are sent only at commit time, not right after the NOTIFY
command execution. So it is impossible to track the execution progress.
2. If the transaction fails, messages won’t be sent at all.
●
Using the application_name parameter.
A session with a long-running process can periodically write its execution
status into the application_name parameter. In a separate session, a
DBA can poll the pg_stat_activity view, which contains detailed
information about all active sessions. The application_name value is
usually also visible in the output of the ps command.
The application_name value can also be written to the server log (if you
set up the log_line_prefix parameter). As a result, relevant log entries will
be easier to find.
11
Process→Table
The dblink extension
is part of the server
incurs additional costs for opening a new connection
Autonomous transactions
commercial distributions (Postgres Pro Enterprise)
Another way to save debug messages is to write them into a database
table.
One of the advantages of this approach is that log access and concurrent
execution are managed by the database system itself.
But you have to make sure that insertion operations on this table are non-
transactional. It can be done using the dblink extension, which is provided
as part of the PostgreSQL server. This extension enables you to open
another connection to the same database, so insertion is performed in a
separate transaction.
As for the disadvantages, opening a new connection takes additional server
resources.
We cover dblink usage in more detail in the DEV2 course.
Commercial distributions, such as Postgres Pro Enterprise, implement
autonomous transactions, which incur lower overhead than dblink usage.
13
Process→File
The adminpack extension
is part of the server
among other things, allows writing text files
Untrusted languages
for example, PL/Perl
You can also write debug messages into an OS file.
It can be done using the adminpack extension, which allows writing data to
any file that can be accessed by the postgres OS user.
Another option is to create a function in an untrusted language (such as
PL/Perl—plperlu) that will perform the same task. Various server-side
programming languages are covered in the DEV2 course.
15
Tracing SQL
Standard tracing into the log file
logging overhead
a big size of the log file
profiling tools are required
access to the log file is required (security)
Settings
long-running statements log_min_duration_statement
the statements to log log_statement
message context log_line_prefix
…
In some cases, it may be useful to trace everything that happens in the
code. Using the built-in functionality, you can save the executed SQL
queries into the server log file. Make sure to take into account the following
specifics:
●
A high-load application can execute a huge number of queries. Writing
them into a file can affect performance of the I/O subsystem.
●
In most cases, you have to use special tools to analyze such data sets.
A de facto standard is pgBadger.
●
Application developers may have no access to the log file on the server.
Besides, in production systems, log files can contain commands with
confidential information.
PostgreSQL provides several parameters to configure tracing; the main
ones are listed on the slide. The full list is available here:
You do not have to set configuration parameters for the whole cluster. Their
scope can be limited to particular sessions using SET, ALTER DATABASE,
and ALTER ROLE commands (as we have explained in lectures “Basic
Tools. Installation and Management, psql” and “Data Organization. Logical
Structure”).
16
Tracing SQL
The auto_explain extension
logging execution plans
tracing nested statements
Settings
plans of long-running commands auto_explain.log_min_duration
nested statements auto_explain.log_nested_statements
…
When tracing is enabled, SQL commands make it into the log in their exact
form that has been sent to the server. If a PL/pgSQL routine was called, the
log will contain only this top-level call (for example, SELECT or CALL
operators), but not the commands executed within the routine.
To log nested queries in addition to top-level commands, you have to use
the auto_explain extension.
As suggested by its name, the main objective of this extension is to log both
the text of the command and its execution plan. It can turn out to be useful,
although it is not exactly tracing, but rather query optimization (which is
covered in the QPT course).
17
Tracing PL/pgSQL
The plpgsql_check extension
overhead incurred by logging
loads of returned data
The main settings
enabling tracing plpgsql_check.enable_tracer
plpgsql_check.tracer
message levels plpgsql_check.tracer_errlevel
To figure out which code has been executed as you are looking at the log,
you have to match SQL queries with PL/pgSQL routines, and it can be not
that easy. There are no built-in features for tracing PL/pgSQL code, but you
can do it with the help of the plpgsql_check extension developed by Pavel
Stehule (we have already mentioned this extension in lecture “PL/pgSQL.
Executing Queries”).
Such tracing causes significant overhead and should only be used for
debugging, not in production operations.
19
Summary
PL/pgSQL Debugger is a debugger API used in GUI IDEs
Debugging output can be displayed in the terminal, written into
the server log, a table, or a file; it can also be sent to other
processes
It is possible to trace a session
20
Practice
1. Modify the get_catalog function, so that the dynamically
constructed text of the query is written into the server log.
In the application, perform search several times by filling out
different fields; make sure that SQL commands are constructed
correctly.
2. Enable tracing of SQL statements at the server level.
Perform some actions in the application and check which
commands are logged.
Disable tracing.
Task 2. To enable tracing, set the log_min_duration_statement parameter to
0 and reload the configuration. All commands will be logged, together with
their execution time.
The easiest way to do it is to use the ALTER SYSTEM SET command. Other
ways of setting parameters are covered in lecture “Basic Tools. Installation
and Management, psql.” Remember to reload the server configuration file.
After having a look at the log file, you should reset
log_min_duration_statement to the default value (-1) to disable tracing. It is
convenient to use ALTER SYSTEM RESET for this purpose.
21
Practice
1. Enable tracing of the PL/pgSQL code using the
plpgsql_check extension; check how it works on the
example of several routines that call each other.
2. When getting debug messages from the PL/pgSQL code, it
is convenient to know the exact routine they are related to.
In the demo, the function name was entered manually.
Implement the functionality that automatically adds the
name of the current function or procedure to the message.
Task 1. To enable tracing, load the plpgsql_check extension into the session
memory using the LOAD command, and then set both the
plpgsql_check.enable_tracer and plpgsql_check.tracers parameters to “on”
at the session level.
Task 2. You can get the routine name by parsing the call stack. Use the
results of Task 3 that you have completed as part of the practice for the
“Error Handling” lecture.
