Debug SQL queries¶

Warning

Query parameters can contain user-supplied values, including search terms, UUIDs, or filter values that qualify as PII in some jurisdictions. Logging them at INFO level and shipping those logs to aggregators such as Elasticsearch or Loki creates a data-leak risk.

Enable PGCATALOG_LOG_ALL_QUERIES only in development or for short-lived production debugging sessions, and review your log retention and aggregation policies before enabling it anywhere that logs leave the host.

Overview¶

PlonePGCatalog provides multiple ways to debug and monitor SQL queries generated from catalog searches. This is useful when troubleshooting performance issues or understanding how catalog queries are translated to PostgreSQL.

Environment variables¶

PGCATALOG_LOG_ALL_QUERIES¶

Log all SQL queries to the Python logger at INFO level.

Usage:

export PGCATALOG_LOG_ALL_QUERIES=1
# or
export PGCATALOG_LOG_ALL_QUERIES=true
# or
export PGCATALOG_LOG_ALL_QUERIES=yes

Log output format:

INFO plone.pgcatalog.search SQL catalog query (1.23 ms): SELECT zoid, path FROM object_state WHERE idx IS NOT NULL AND idx @> $1::jsonb | params: {'p_portal_type_1': {'portal_type': 'Document'}} | keys: ['portal_type']

Performance impact: Minimal when disabled (single environment variable check). When enabled, adds ~0.1ms per query for logging overhead.

Runtime toggle: The setting is read on every query, not cached at import time. You can enable and disable logging without restarting the process, for example via os.environ in a debug console.

Parameter truncation: The parameter string representation is truncated at 2000 characters with a ... (truncated) suffix. This keeps log lines bounded when a query has huge values (for example, path IN (...) with thousands of entries).

PGCATALOG_SLOW_QUERY_MS¶

Control the threshold for slow query logging (default: 10ms).

Usage:

export PGCATALOG_SLOW_QUERY_MS=100  # Log queries > 100ms
export PGCATALOG_SLOW_QUERY_MS=0.1  # Log all queries (via slow query system)

Slow queries are logged at WARNING level and stored in the pgcatalog_slow_queries table for analysis via the ZMI.

Debugging workflow¶

1. Enable query logging¶

For comprehensive debugging:

export PGCATALOG_LOG_ALL_QUERIES=1

For slow query analysis only:

export PGCATALOG_SLOW_QUERY_MS=50  # Adjust threshold as needed

2. Configure Python logging¶

Enable INFO level logging for the search module:

import logging
logging.getLogger('plone.pgcatalog.search').setLevel(logging.INFO)

Or in your zope.conf:

<logger>
  name plone.pgcatalog.search
  level info
</logger>

3. Run your problematic query¶

Execute the catalog search that’s causing issues:

# In Python/debug console
results = portal.portal_catalog.searchResults(
    portal_type='Document',
    review_state='published'
)

4. Analyze the logged SQL¶

The log output shows:

Duration: Query execution time in milliseconds
SQL: The actual PostgreSQL query
Params: Parameter values used in the query
Keys: Original catalog query keys

Example log entry:

INFO plone.pgcatalog.search SQL catalog query (1.23 ms): SELECT zoid, path FROM object_state WHERE idx IS NOT NULL AND idx @> $1::jsonb AND idx @> $2::jsonb | params: {'p_portal_type_1': {'portal_type': 'Document'}, 'p_review_state_2': {'review_state': 'published'}} | keys: ['portal_type', 'review_state']

5. Test the query directly in PostgreSQL¶

Copy the SQL and parameters to test directly:

-- Connect to your database
psql "dbname=zodb host=localhost port=5432 user=zodb"

-- Test the query with actual parameter values
SELECT zoid, path
FROM object_state
WHERE idx IS NOT NULL
  AND idx @> '{"portal_type": "Document"}'::jsonb
  AND idx @> '{"review_state": "published"}'::jsonb;

-- Analyze query performance
EXPLAIN ANALYZE SELECT zoid, path
FROM object_state
WHERE idx IS NOT NULL
  AND idx @> '{"portal_type": "Document"}'::jsonb
  AND idx @> '{"review_state": "published"}'::jsonb;

ZMI interface¶

Access the Slow Queries tab at /portal_catalog/manage_slowQueries to:

View aggregated slow query statistics
Get index suggestions for common slow queries
Run EXPLAIN plans on recorded slow queries
Create suggested indexes to improve performance

Production considerations¶

Recommended settings for production¶

# Log only genuinely slow queries
export PGCATALOG_SLOW_QUERY_MS=100

# Disable comprehensive query logging in production
# (omit PGCATALOG_LOG_ALL_QUERIES or set to 0/false)

Debugging specific issues¶

For temporary debugging in production:

Enable query logging with a time limit:

export PGCATALOG_LOG_ALL_QUERIES=1
# Restart application
# Reproduce the issue
# Disable logging and restart

Use PostgreSQL’s built-in logging:

-- Temporarily log all queries
ALTER SYSTEM SET log_statement = 'all';
SELECT pg_reload_conf();

-- Restore normal logging
ALTER SYSTEM RESET log_statement;
SELECT pg_reload_conf();