Jak mogę logować instrukcje `PREPARE` w PostgreSQL?

Question

Używam narzędzia bazy danych (Elixir's Ecto), które używa prepared statements dla większości zapytań PostgreSQL. Chcę dokładnie zobaczyć, jak i kiedy to zrobi.

Znalazłem poprawny plik konfiguracyjny Postgres, postgresql.conf, uruchamiając SHOW config_file; w psql. I edytowane go włączyć

log_statement = 'all' 

jak Dogbert zasugerował here.

Zgodnie z the PostgreSQL 9.6 docs to ustawienie powinno spowodować zarejestrowanie PREPARE instrukcji.

Po ponownym PostgreSQL, mogę tail -f swój plik dziennika (jeden określony przez flagą -r podczas uruchamiania postgres wykonywalny) i widzę wpisy tak:

LOG: execute ecto_728: SELECT i0."id", i0."store_id", i0."title", i0."description" 
    FROM "items" AS i0 WHERE (i0."description" LIKE $1) 
DETAIL: parameters: $1 = '%foo%' 

ta odpowiada zapytaniu (aczkolwiek wykonane przez protokół binarny, myślę) jak

EXECUTE ecto_728('%foo%'); 

Jednakże nie widzę oryginalny PREPARE że stworzony ecto_728.

Próbowałem upuszczając i odtwarzając bazę danych. Następnie ta sama kwerenda jest wykonywana jako ecto_578, więc wydaje się, że oryginalna przygotowana instrukcja została usunięta z bazy danych i utworzona została nowa.

Ale kiedy przeszukuję dziennik PostgreSQL dla ecto_578, widzę tylko, że jest on wykonywany, a nie tworzony.

Jak mogę zobaczyć instrukcje PREPARE w dzienniku PostgreSQL?

Answer 1

Jak już wspomniano, zapytania są przygotowywane za pomocą rozszerzonego protokołu zapytań, który różni się od instrukcji PREPARE. I zgodnie z docs dla log_statement:

Dla klientów korzystających z protokołu rozszerzonego kwerendy rejestrowania występuje, gdy Execute odebraniu wiadomości

(co znaczy, że rejestrowanie robi nie występuje, gdy Przetwarza lub odebraniu wiadomości Bind)

Jednakże, jeśli ustawisz log_min_duration_statement = 0, wówczas:.

Dla klientów korzystających z rozszerzonego protokołu zapytania, czasami trwania Analiza składni oprawę i wykonać kroki są rejestrowane niezależnie

Włączanie obu tych ustawieniach razem daje dwa wpisy dziennika za Execute (jeden z log_statement gdy wiadomość jest odbierany, a inny od log_min_duration_statement po zakończeniu wykonywania).

Answer 2

Nick's answer było poprawne; Po prostu odpowiadam, aby dodać to, czego się nauczyłem, próbując tego.

Po pierwsze, udało mi się zobaczyć trzy odrębne działania w dzienniku: a parse stworzyć przygotowane oświadczenie, o bind dać parametry dla niego, i execute mieć baza faktycznie jej przeprowadzenia i powrotu wyników. Jest to opisane in the PostgreSQL docs for the "extended query protocol".

LOG: duration: 0.170 ms parse ecto_918: SELECT i0."id", i0."store_id", 
    i0."title", i0."description" 
    FROM "items" AS i0 WHERE (i0."description" LIKE $1) 
LOG: duration: 0.094 ms bind ecto_918: SELECT i0."id", i0."store_id", 
    i0."title", i0."description" 
    FROM "items" AS i0 WHERE (i0."description" LIKE $1) 
DETAIL: parameters: $1 = '%priceless%' 
LOG: execute ecto_918: SELECT i0."id", i0."store_id", 
    i0."title", i0."description" 
    FROM "items" AS i0 WHERE (i0."description" LIKE $1) 
DETAIL: parameters: $1 = '%priceless%' 

Dane wyjściowe zostały wygenerowane podczas kilku automatycznych testów. Przy kolejnych uruchomieniach zobaczyłem to samo zapytanie o innej nazwie - np. ecto_1573. Było to bez upuszczania bazy danych, a nawet ponownego uruchamiania procesu PostgreSQL. The docs że

Jeśli pomyślnie utworzony, nazwany obiekt przygotowany-oświadczenie trwa do końca bieżącej sesji, o ile wyraźnie nie zniszczone.

Tak więc te instrukcje muszą zostać odtworzone w każdej sesji i prawdopodobnie mój pakiet testowy ma nową sesję podczas każdego uruchomienia.