Plpgsql debugger

Z PostgreSQL
Skočit na navigaci Skočit na vyhledávání

Profiler a debugger pro PostgreSQL

Bez debuggeru a profileru se neobejde žádný zkušený programátor, tím spíše začátečník. Bez zkušeností nedokáže přesně odhadnout kritická místa a často zbytečně umisťuje ladící výpisy. I já jako relativně zkušený programátor se při hackingu bez debuggeru neobejdu. Zvlášť nedocenitelná je postmorten analýza core souboru a to natolik, že jsem se naučil používat gdb a zásadně používám debug verzi PostgreSQL[1]. Programování uložených procedur se v tomto ohledu neliší od klasického programování. Debugger a profiler přijde vhod. Až do loňského roku (2007) tyto nástroje pro PL/pgSQL chyběly. Proto se iniciativity ujala firma EnterpriseDB a její programátor Korry Douglas vytvořil nezbytné moduly pro PostgreSQL a GUI debuggeru pro klienta EnterpriseDB. O možnost krokovat a

ladit PL/pgSQL funkce byla rozšířena administrační konzole pgAdminIII.

Profiler

Začnu tím jednodušším a, dovolím si tvrdit, užitečnějším nástrojem - profilerem. Výsledkem profileru je tabulka zobrazující kolikrát byla vykonána určitá část programu a kolik času pro to bylo potřeba. Jelikož ani profiler a ani debugger není součástí distribuce PostgreSQL nejprve musíme doinstalovat chybějící moduly na server[2].

# zdrojové kódy PostgreSQL jsou v adreáři src/pgsql
cd src/pgsql/contrib
cvs -d :pserver:anonymous@cvs.pgfoundry.org:/cvsroot/edb-debugger login
cvs -d :pserver:anonymous@cvs.pgfoundry.org:/cvsroot/edb-debugger checkout server

Na výzvu o zadání hesla zadejte libovolný (neprázdný) řetězec, například mezeru.

cd server
make all
su -
make install
</pre?
Dále musíme zavést modul profileru:
<pre>
[pavel@localhost ~]$ psql postgres
Welcome to psql 8.3beta4, the PostgreSQL interactive terminal.

Type:  \copyright for distribution terms
       \h for help with SQL commands
       \? for help with psql commands
       \g or terminate with semicolon to execute query
       \q to quit

postgres=# LOAD '$libdir/plugins/plugin_profiler';
LOAD

Po zavedení modulu se vytvoří nová systémová proměnná plpgsql.profiler_tablename obsahující název tabulky do které se má ukládat profilační log. Implicitně tato proměnná obsahuje prázdný řetězec, což znamená, že je profiler neaktivní.

Potřebnou tabulku modul profileru vytvoří automaticky, pokud ještě neexistuje. Profiler tedy aktivujeme nastavením proměnné plpgsql.profiler_tablename.

postgres=# SET plpgsql.profiler_tablename = 'profil1';
SET

Budu profilovat funkci:

CREATE OR REPLACE FUNCTION foo()
RETURNS void AS $$
DECLARE a integer;  
BEGIN
  FOR i IN 1..1000 LOOP
    SELECT INTO a pk 
       FROM footab
      WHERE pk = i;
    -- do some
  END LOOP;
END;
$$ LANGUAGE plpgsql;

funkci spustíme příkazem SELECT foo() a po jejím dokončení se můžeme dotázat do tabulky profil1.

postgres=# SELECT line_number AS ln, sourcecode, 
                  exec_count AS count, time_total AS total, 
                  time_longest AS longest 
              FROM profil1 ORDER BY func_oid, line_number;
 ln |       sourcecode        | count |  total   | longest  
----+-------------------------+-------+----------+----------
  0 |                         |     1 |    2e-06 |    2e-06
  1 | DECLARE a integer;      |     0 |        0 |        0
  2 | BEGIN                   |     0 |        0 |        0
  3 |   FOR i IN 1..1000 LOOP |     1 | 0.039662 | 0.039662
  4 |     SELECT INTO a pk    |  1000 | 0.037785 |  0.00082
  5 |        FROM footab      |     0 |        0 |        0
  6 |       WHERE pk = i;     |     0 |        0 |        0
  7 |     -- do some          |     0 |        0 |        0
  8 |   END LOOP;             |     0 |        0 |        0
  9 | END;                    |     0 |        0 |        0
(10 rows)

Překvapivě se zdá, že nejpomalejší je příkaz FOR (řádek 3). To ale není pravda, je to určité zkreslení, které vychází z interní struktury interpretu plpgsql, které poskytuje časy nikoliv na řádek, ale na příkaz. Tedy 0.045 sec zabralo vykonávání nikoliv řádku č. 3, ale příkazu FOR (a tedy hlavně jeho těla), v tomto případě 1000 provedení příkazu SELECT. Samotný řádek 3 zabral pouze 0.001ms = 0.045 - 0.044.

CREATE OR REPLACE FUNCTION foo()
RETURNS void AS $$
DECLARE a integer;  
BEGIN
  FOR a IN
     SELECT pk 
     FROM footab 
     WHERE pk BETWEEN 1 
              AND 1000 
  LOOP
    -- do some
  END LOOP;
END;
$$ LANGUAGE plpgsql;

DROP TABLE profil1;
SELECT foo();

postgres=# SELECT line_number AS ln, sourcecode, 
                  exec_count AS count, time_total AS total, 
                  time_longest AS longest 
              FROM profil1 ORDER BY func_oid, line_number;
 ln |        sourcecode        | count |  total   | longest  
----+--------------------------+-------+----------+---------
  0 |                          |     1 |    3e-06 |    3e-06
  1 | DECLARE a integer;       |     0 |        0 |        0
  2 | BEGIN                    |     0 |        0 |        0
  3 |   FOR a IN               |     1 | 0.003407 | 0.003407
  4 |      SELECT pk           |     0 |        0 |        0
  5 |      FROM footab         |     0 |        0 |        0
  6 |      WHERE pk BETWEEN 1  |     0 |        0 |        0
  7 |               AND 1000   |     0 |        0 |        0
  8 |   LOOP                   |     0 |        0 |        0
  9 |     -- do some           |     0 |        0 |        0
 10 |   END LOOP;              |     0 |        0 |        0
 11 | END;                     |     0 |        0 |        0
(12 rows)

Nyní cyklus zabere méně než desetinu předešlé varianty. Že rozdíl není 1000 násobný,s je zapříčiněno rozdílným prováděním příkazu SELECT v těchto dvou případech. Nicméně desetinásobné zrychlení rozhodně nepostrádá na smyslu (na zatížené databázi by zrychlení bylo znatelnější). Tento poměr je např. 10h a 1h nebo 10min a 1min nebo 10sec a 1sec. Profiler sám o sobě za nás žádnou práci neudělá, ale pomůže nám identifikovat místa, která má smysl měnit a snažit se optimalizovat (platí pravidlo 80/20, tj. 20% kódu je odpovědno za 80% potřeby času).

Debugger

Stejně jako profiler, tak i debugger má svůj modul, který běží na serveru. Pokud chceme používat globální breakpointy (body přerušení), tak tento modul musí být aktivován automaticky po startu serveru. To zařídíme nastavením konfiguračního parametru v postgresql.conf shared_preload_libraries (Nezapomeňte restartovat server).

shared_preload_libraries = 
  '$libdir/plugins/plugin_debugger.so'

dalším krokem je registrace funkcí debuggeru pro určitou databázi.

psql postgres
postgres=# \i /usr/local/pgsql/share/contrib/pldbgapi.sql 
CREATE TYPE
CREATE TYPE
CREATE TYPE
CREATE TYPE
...

Pokud nemáme nainstalovanou nejnovější verzi programu pgAdminIII můžeme ladit plpgsql z druhé konzole.

postgres=# \x
Expanded display is on.
postgres=# select * from pldbg_get_target_info('foo','f');
-[ RECORD 1 ]----------
target     | 41259
schema     | 2200
nargs      | 0
argtypes   | 
targetname | foo
argmodes   | 
argnames   | 
targetlang | 24578
fqname     | public.foo
returnsset | f
returntype | 2278

Výše uvedeným dotazem získáme popis funkce foo.

V dalším kroku vytvoříme tzv. listener. Vrácený handle použijeme v další funkci, kterou nastavujeme globální breakpoint:

SELECT * 
   FROM pldbg_set_global_breakpoint(1, 41259, NULL, NULL);

Druhý parametr je oid laděné funkce. Třetí volitelný parametr je číslo řádku. Poslední volitelný parametr určuje, u kterého procesu se má breakpoint aplikovat. Pokud není zadán breakpoint bude platit pro všechny procesy, které spustí laděnou funkci (Pozor na používání debuggeru na provozních serverech!).

 SELECT * FROM pldbg_wait_for_target(1);

Volání funkce pldbg_wait_for_target způsobí čekání na dosažení breakpointu. Z druhé konzoli spustím funkci foo:

SELECT foo(); -- konzole B

poté se mi uvolní konzole A, odkud mohu ladit funkci foo:

postgres=# SELECT * FROM pldbg_wait_for_target(1);
-[ RECORD 1 ]---------+------
pldbg_wait_for_target | 20123

Dotazem na listener zjistíme, který breakpoint aktivoval přerušení.

postgres=# SELECT * FROM pldbg_wait_for_breakpoint(1);
-[ RECORD 1 ]-----
func       | 41259
linenumber | 4
targetname | foo

Další dotazy slouží k získání popisu laděné funkce:

postgres=# SELECT * FROM pldbg_get_source(1, 41259);
-[ RECORD 1 ]----+-----------------------------------------
pldbg_get_source | 
                 : DECLARE a integer;  
                 : BEGIN
                 :   FOR a IN 
                 :           SELECT pk 
                 :              FROM footab 
                 :             WHERE pk BETWEEN 1 AND 1000 
                 :   LOOP
                 :     -- do some
                 :   END LOOP;
                 : END;
                 : 

postgres=# \x
Expanded display is off.
postgres=# SELECT name, value from pldbg_get_variables(1);
 name | value 
------+-------
 a    | NULL
(1 row)

Voláním funkcí pldbg_step_into(handler), call pldbg_step_over(handler) nebo pldbg_continue(handler) můžeme krokovat laděnou funkci. Posloupnost volání funkcí získáme dotazem:

postgres=# select * from pldbg_get_stack(1);
 level | targetname | func  | linenumber | args 
-------+------------+-------+------------+------
     0 | foo        | 41259 |          3 | 
(1 row)

Ladění můžeme ukončit funkcí pldbg_abort_target(handler);

Ladění funkce bez GUI není příliš pohodlné, proto se o tuto funkci rozšířil pgAdminIII. Nainstalujte si nejnovější verzi, protože pouze ta obsahuje debugger.

Spustíme pgAdminIII a připojíme se k naší databázi. Potom v levém stromu objektů vybereme funkci foo. Pokud je vše v pořádku[3], tak v kontextovém menu (na pravém tlačítku myši) máme volbu Debugging. Toto políčko menu má submenu Debug a Set breakpoint. Pokud vybereme Debug, tak se nám otevře okno debuggeru a my můžeme interaktivně ladit funkci foo. Pokud vybereme Set breakpoint, pak se zobrazí modální dialogové okno, které nás informuje, že pgAdminIII čeká na vykonání funkce.


Otevřeme si konzolu a z ní spustíme funkci foo. Poté pgAdminIII ukončí čekání a aktivuje GUI debuggeru. Jak debugger, tak profiler jsou jednoduché nástroje, které nabízí pouze základní funkce a je znát určitá nevyzrálost těchto nástrojů. Nicméně tyto nástroje tady jsou a je možné je používat.

Poznámky

  1. Tuto verzi získáte vlastním překladem zdrojových kódů a nastavením přepínačů --enable-debug a --enable-cassert. S tímto nastavením aktivujete vnitřní kontroly, jejichž provedení má negativní vliv na výkon (cca 50%), takže pokud zrovna nepíšete SPI doplňky nebo neřešíte nějaký problém, tak tuto verzi nepoužívejte.
  2. Nejedná se o komplikovanou záležitost, kterou bych také ovšem neoznačil jako triviální.
  3. Pokud nemáte povolenou volbu Debugging, tak a) nemáte nainstalován modul debuggeru na serveru, b) nemáte zaregistrovány funkce debuggeru v databázi, ke které jste se připojili.