📜 select * from 🚀 logfile with 🐘 file_fdw

In the first post of this series, I traced the calls to DocDB with yb_debug_log_docdb_requests. The log goes to the PostgreSQL logfile but not though the PostgreSQL functions. This means that you cannot get them into the client when setting client_min_messages. This is why I connected from the server I was connected to, getting the file name with pg_current_logfile() but then going to the OS. However, we can access the OS from the PostgreSQL session and here is an example with file_fdw.

I am connected to YugabyteDB, with and create a file_fdw server to access files through a FDW foreign table. I go though an awk script that decodes the timestamp (ts) and adds a linne number (nr) to have an order. It also transforms the information to a csv format. When I query it, I return all lines into one value (with string_add) to get one row, with the last timestamp as last_ts. I do this to use gset to keep track of it so that the next call will show only the new lines >:'last_ts'

This is what I run to create all that and prepare the query:

-- create privileges, extension, and FDW server
do $do$ begin execute $sql$ grant yb_extension,yb_fdw to $sql$ || user; end; $do$;
create extension if not exists file_fdw;
create server if not exists file_fdw foreign data wrapper file_fdw;
-- create FDW table on current logfile
drop foreign table current_logfile ;
create foreign table current_logfile (ts timestamptz, nr int, log text) server file_fdw options ( program $bash$ awk '
/^[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}[.][0-9]*/ { t=$1" "$2}
/^.[0-9]{4} [0-9]{2}:[0-9]{2}:[0-9]{2}[.][0-9]*/ { t=d" "$2}
{gsub(/"/,q q);print q t q "," q NR q "," q $0 q}
' q='"' d=$(date +%Y-%m-%d) '/home/opc/10.0.0.61/var/data/yb-data/tserver/logs/postgresql-2022-07-20_000000.log'
$bash$, format 'csv');
--
select now() as last_ts
\gset
deallocate logfile;
prepare logfile(timestamp) as
select
 max(ts) as last_ts,e'\n'||string_agg(log,e'\n' order by ts,nr) log
 from current_logfile where log like 'I%' and ts>$1
;
\pset format unaligned

With log like 'I%' I filter to get only the YugabyteDB information message. You can remove this to show all lines including the PostgreSQL messages.

Now, I can show the new lines since the last call with:

execute logfile(:'last_ts');\gset

Example

-- set start timestamp and enable log docdb requests
select now() as last_ts;\gset
set yb_debug_log_docdb_requests=true;

-- run query
select count(*) from demo;

--  show log since start timestamp and reset to last time
\pset format unaligned
execute logfile(:'last_ts');
\gset
\pset format aligned

This shows the read request to DocDB

I use this on a lab to understand better the calls from YSQL query layer to DocDB distributed storage and transactions