Postgresql – Java driver dont fire query-start probe in postgres 11

jdbcpostgresqlpostgresql-11

While using SystemTap to trace postgres session on PostgreSQL 11.2 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-36), 64-bit. 

global livequeries

probe process("/usr/pgsql-11/bin/postgres").mark("query-start"){
  printf("[%s] Query start on PID %d : %s \n", ctime(gettimeofday_s()), pid(), user_string($arg1) )
  livequeries[tid(),$arg1] = gettimeofday_us()
}

psql fires this probe but java driver dont.

REF: docs

Best Answer

I presume the difference between you running your queries via psql vs. from a Java program is that you use prepared statements in Java. Processing "simple statements" and prepared statements take different code paths in the Postgres backend (postgres.c).

"query-start" probe is only called when a simple statement is executed (exec_simple_query), while a prepared statement processing has two separate distinct stages: parse (exec_parse_message) and execute (exec_execute_message).

Both code paths converge when they call PortalRun in pquery.c, where the "query-execute" probe is called.

In other words, the two code paths look like this (omitting the "done" probes):

psql -> simple statement
  query-start probe
  query-parse-start probe
  query-parse-done probe      
  query-rewrite-start probe
  query-rewrite-done probe
  query-plan-start probe
  query-plan-done probe
  query-execute-start probe
  query-execute-done probe
  query-done probe

JDBC -> prepared statement
  prepare phase
    query-parse-start probe
    query-parse-done probe     
  execute phase 
    query-execute-start probe
    query-execute-done probe

If you're not particularly concerned about the query parsing and planning latency, you need to capture the "query-execute-*" probes. If you need the query text, capture also "query-parse-start".

Related Question