Skip to content

Log and audit queries

This page explains why an enterprise database logs the queries it serves, and how to log each synchronous query, with its timing, memory use, and result size, by overriding .z.pg with the KX Logging module.

A database that serves many users needs a record of what it was asked. Two needs drive this in an enterprise environment:

  • Auditing. Regulators, security teams, and data owners ask who ran which query, and when. A query log answers that without relying on the client to report it.
  • Performance optimization. A q process serves one query at a time, so one slow or memory-intensive query delays every other client. A log that records how long each query took and how much memory it used shows you which queries to fix, rewrite, or move to another process.

q does not log queries by default. Every synchronous request a client sends over interprocess communication (IPC) passes through the .z.pg callback, whose default behavior is to evaluate the request with value. Replace .z.pg with a function that logs the request, evaluates it, logs the outcome, and returns the result. The function then records every synchronous query.

The example on this page writes the log with the KX Logging module, which adds a timestamp, a severity level, and other metadata to each message and can send messages to more than one destination.

Prerequisites

  • KDB-X installed, with the Logging module (kx.log) available to use
  • The Datagen module (kx.datagen.capmkts), to build the sample database in Verify results
  • Familiarity with IPC basics: opening a handle and sending a synchronous request

Create a logger

Load the Logging module and create a logger. createLog returns a dictionary of logging functions, one per level (trace, debug, info, warn, error, and fatal), plus functions to configure formats and destinations.

klog:use`kx.log
qlog:klog.createLog[]

The default format writes a timestamp, the level, the process ID, the host, and the message. In an enterprise deployment, many q processes run on each host, and the process ID changes every time a process restarts. A stable process name (probably passed by a command line parameter), such as hdb_eu_gov_3, tells you which process served a query. The log format includes the timestamp ($p, from .z.p), the level ($l), the host ($h, from .z.h), and the process name:

o:.Q.opt .z.x
...
procName:first o`name;
qlog.addfmt[`audit;"$p $l host[$h] proc[",procName,"] $m\n"];
qlog.setfmt`audit

By default, the logger writes trace to warn messages to standard output and error and fatal messages to standard error. To keep a permanent audit trail, also send messages at info level and above to a file:

qlog.add[hopen `:audit.log;`info`warn`error`fatal];

Override .z.pg

The following handler does four things for each synchronous query:

  1. Logs the query and the handle it arrived on (the logger adds the timestamp).
  2. Evaluates the query with .Q.ts, which returns the result together with the time in milliseconds and the space in bytes (the same as \ts). The handler keeps the result in a variable.
  3. Logs that the query finished, with the result's row and column counts, the time, and the space.
  4. Returns the result to the client.
/ rows and columns of a result; columns are null when the result is not a table
shape:{(count x;$[.Q.qt x;count cols x;0N])}

/ query as text: strings in full, other queries as .Q.s1 shows them
qtext:{$[10h=type x;x;.Q.s1 x]}

.z.pg:{[query]
  qlog.info ("query start: handle %r: %s";.z.w;qtext query);
  r:@[{(1b;.Q.ts[value;enlist x])};query;{(0b;x)}];
  if[not first r;
    qlog.error ("query failed: handle %r: '%s: %s";.z.w;r 1;qtext query);
    'r 1];
  ((ms;bytes);res):r 1;
  (rows;columns):shape res;
  qlog.info ("query end: handle %r: rows %r, columns %r, %r ms, %r bytes";.z.w;rows;columns;ms;bytes);
  res}

Log messages use printf-style placeholders: %r writes any q value as .Q.s1 would, and %s writes a string or symbol.

A few details of the handler:

  • A client can send a query as a string, such as "select from trade", or as a list that calls a function on the server, such as (`vwap;2026.11.03;`IBM). value evaluates both.
  • qtext logs a string query as it is. .Q.s1 truncates its output to the console width set by \c, so a long query logged with %r would end in .. and the audit trail would lose the end of it. A query sent as a list has no text of its own, so qtext uses .Q.s1 for it, and a very long one is still truncated. Raise the width with \c, up to 2000 characters, if your clients send long lists.
  • Trap catches an error in the query, so that the handler can log the failure. The handler then signals the same error, so the client sees the error it would have seen without the handler.
  • .Q.qt is true for tables and keyed tables. For any other result, such as an atom or a list, the handler logs the item count as the rows and a null for the columns.
  • A process serves one synchronous query at a time, so each query end line belongs to the query start line before it.

Verify results

To try the handler, you need a database to query. The Datagen module can build a date-partitioned Capital Markets database with trade, quote, and nbbo tables. For this demonstration, build one in /tmp/eugovhdb. In a q session, load the module and build the database:

q)([buildPersistedDB]): use `kx.datagen.capmkts
q)buildPersistedDB `:/tmp/eugovhdb

With the default parameters, the database covers the trading days of the last month, with about 50,000 trades and 500,000 quotes a day, and takes about 800 MB of disk.

Save the code from Create a logger and Override .z.pg as hdb.q, with code that loads the database given by the -db command-line parameter and a function for clients to call. .Q.lo loads the database without changing the working directory, so audit.log is written where you start the process:

o:.Q.opt .z.x
if[not `db in key o; -2 "usage: q hdb.q -db DIR [-name NAME]"; exit 1]

.Q.lo[hsym `$first o`db;0;0]

klog:use`kx.log
qlog:klog.createLog[]
procName:$[`name in key o;first o`name;"q"]
qlog.addfmt[`audit;"$p $l host[$h] proc[",procName,"] $m\n"];
qlog.setfmt`audit
qlog.add[hopen `:audit.log;`info`warn`error`fatal];

shape:{(count x;$[.Q.qt x;count cols x;0N])}

/ query as text: strings in full, other queries as .Q.s1 shows them
qtext:{$[10h=type x;x;.Q.s1 x]}

.z.pg:{[query]
  qlog.info ("query start: handle %r: %s";.z.w;qtext query);
  r:@[{(1b;.Q.ts[value;enlist x])};query;{(0b;x)}];
  if[not first r;
    qlog.error ("query failed: handle %r: '%s: %s";.z.w;r 1;qtext query);
    'r 1];
  ((ms;bytes);res):r 1;
  (rows;columns):shape res;
  qlog.info ("query end: handle %r: rows %r, columns %r, %r ms, %r bytes";.z.w;rows;columns;ms;bytes);
  res}

/ business logic:
vwap:{[d;s] select vwap:size wavg price by sym from trade where date=d, sym in s}

Start the HDB process with a process name and the database:

q hdb.q -name hdb_eu_gov_3 -db /tmp/eugovhdb -p 5000

From a second q session, send some queries, including one that fails:

q)h:hopen `::5000
q)h"select avg price by sym from trade where date=last date, sym in `AAPL`MSFT`IBM"
sym | price
----| --------
AAPL| 249.3074
IBM | 309.2741
MSFT| 558.8151
q)d:h"last date"
q)h"count trade"
1074789
q)h"select from trades where date=last date"
'2026.11.04T21:36:18.912 trades
  [0]  h"select from trades where date=last date"
       ^
q)h(`vwap;d;`AAPL`MSFT)
sym | vwap
----| --------
AAPL| 249.3131
MSFT| 558.7565
q)count h"select spread:avg ask-bid by sym from quote"
51

The client sees the same results and errors as without the handler. The HDB process writes these lines to its console and to audit.log:

2026.11.04D20:36:18.909313000 info host[hdb-server-01] proc[hdb_eu_gov_3] query start: handle 8i: select avg price by sym from trade where date=last date, sym in `AAPL`MSFT`IBM
2026.11.04D20:36:18.909734000 info host[hdb-server-01] proc[hdb_eu_gov_3] query end: handle 8i: rows 3, columns 2, 0 ms, 22928 bytes
2026.11.04D20:36:18.909943000 info host[hdb-server-01] proc[hdb_eu_gov_3] query start: handle 8i: last date
2026.11.04D20:36:18.910047000 info host[hdb-server-01] proc[hdb_eu_gov_3] query end: handle 8i: rows 1, columns 0N, 0 ms, 704 bytes
2026.11.04D20:36:18.910240000 info host[hdb-server-01] proc[hdb_eu_gov_3] query start: handle 8i: count trade
2026.11.04D20:36:18.911455000 info host[hdb-server-01] proc[hdb_eu_gov_3] query end: handle 8i: rows 1, columns 0N, 1 ms, 4960 bytes
2026.11.04D20:36:18.911846000 info host[hdb-server-01] proc[hdb_eu_gov_3] query start: handle 8i: select from trades where date=last date
2026.11.04D20:36:18.911939000 error host[hdb-server-01] proc[hdb_eu_gov_3] query failed: handle 8i: 'trades: select from trades where date=last date
2026.11.04D20:36:18.912173000 info host[hdb-server-01] proc[hdb_eu_gov_3] query start: handle 8i: (`vwap;2026.11.03;`AAPL`MSFT)
2026.11.04D20:36:18.912524000 info host[hdb-server-01] proc[hdb_eu_gov_3] query end: handle 8i: rows 2, columns 2, 0 ms, 52064 bytes
2026.11.04D20:36:18.912738000 info host[hdb-server-01] proc[hdb_eu_gov_3] query start: handle 8i: select spread:avg ask-bid by sym from quote
2026.11.04D20:36:18.955907000 info host[hdb-server-01] proc[hdb_eu_gov_3] query end: handle 8i: rows 51, columns 2, 43 ms, 30194928 bytes

Your data, dates, timestamps, host, handle, times, and sizes differ. The vwap line shows the date the client sent as a value, not the variable d, because the client evaluates d before it sends the list. The last query has no date constraint, so it reads every partition of quote: it used about 30 MB and the most time of any query to return 51 rows. That is the kind of line to look for when you hunt for slow or memory-intensive queries.

Considerations for production

  • Other entry points. .z.pg sees only synchronous IPC requests. Asynchronous messages arrive through .z.ps, HTTP requests through .z.ph and .z.pp, and WebSocket messages through .z.ws. Wrap each one your process accepts, or the audit trail has gaps. A .z.ps handler follows the same pattern, but has no result to return.
  • Combine with access control. If the process also restricts what clients can run through .z.pg, do both in one handler: log the query first, so that rejected queries are recorded too.
  • Sensitive data. The log contains each query in full, including any values a client passes as arguments. Protect the log file as you would the data, and consider what your retention rules allow.
  • Log volume. A query that carries large argument values writes a long log line. On a process that serves many small queries, logging every one at info adds I/O for every request. Raise the logger's level, for example with qlog.setlvl`warn, or log only queries above a time or space threshold.
  • Restore the default. Run \x .z.pg to remove the handler and return to the default behavior.

Next steps