Module:DB Pool Logging Utilities

Introduction

DB Pool Logging Utilities is a community module that provides the ability of generating log for some events of database Pool.

It is primarily intended to be used by developers to facilitate them to pinpoint the code that is causing performance issues related to database queries/connections.

This information is logged in standard openbravo log.

Requirements

• Depends on Openbravo 3.0PR17Q1.
• It can only generate log for Tomcat DB Pool.

Performance considerations

When installing this module, especially in production environments, take into account that, depending on how it is configured, it can cause an overhead in terms of performance. Read carefully Configuration section to select the settings before using it. You can find here some measures taken regarding this overhead.

What to log

Slow Queries

Logging slow queries is important to fine tune them. DB logs (ie. min_duration_statements in PostgreSQL) allows to log them, but sometimes it is not easy from those logs to reach the code that triggered the query. Adding stack traces to logged slow queries helps to easily know the code behind the queries.

Connections

Some times, it is useful also to know all the connections that are present in the pool, understanding where they were borrowed for last time.

Configuration

This module is highly configurable in order to exactly determine what to log. Note that by default the module is not enabled, so even it is installed in the Openbravo instance, it will not log anything until it is configured.

There are two ways to configure the settings for this module: Openbravo.properties and MBeans.

How to set parameters

Openbravo.properties

Note after any change in Openbravo.properties, you will need to compile and restart Tomcat in order to make it effective.

All parameters described in Configuration section can be set through Openbravo.properties file. The properties are named db.pool.logger. followed the parameter name to configure starting in lowercase. For example to enable logging, use: db.pool.logger.enabled=true.

Settings defined in Openbravo.properties are applied when Tomcat starts.

MBeans

It is also possible to change logging configuration in a live instance using JMX MBeans. The MBean is registered in Openbravo:contextName-name=DBPoolLogger where contextName is the application's context name.

There are different clients to connect to JMX MBeans:

• JConsole which is included in JDK.
• jmxterm command line client

Parameters

• Enabled. Default false. Enables or disabled pool logging, when it is not enabled, none of the rest of parameter values is take into account. When logging is disabled, its overhead in performance is negligible.

Settings for logging statements:

• MinDurationStatements. Default -1. Defines the minimum time in milliseconds to log statements. Whenever a query takes longer than this threshold to be executed in database in will be logged including the time it took to be executed. -1 indicates that no statement will be logged. 0 will log ALL statements. Note that setting a low value for this parameter will produce too much log, adding overall overhead to execution times.
• QuerySubstrings. Default empty. List of substrings in sensitive case queries are compared to in order to log. If this list is empty, all queries taking more than MinDurationStatements will be logged; if there are values in this list, only queries that match any of these substrings will be logged in case they take more than MinDurationStatements to execute.
  • AllQuerySubstrings. This parameter can be set to provide a full list of substring queries separated by #.
  • addQuerySubstring. Only as JMX operation. Allows to add a new query substring to the existing list.
  • resetQuerySubstrings. Only as JMX operation. Removes all query substrings, so from this moment all queries will be electable to logged.
• LogParamValues. Default false. When enabled, if logged statements contain parameters, their values will be also logged.
• LogStatementStackTrace. Default true. When enabled, logged statements will include a stack trace making in this manner possible to know which is the code that executed the query.

Stack trace configuration:

• MaxStackTraceLength. Default 8. Maximum number of lines to be logged in stack traces. Stack traces can be very long but to get to the relevant piece, usually it is not required to have it complete in order to get to the code executing the query. Note than having here a big number and a low MinDurationStatements value can generate a very verbose log.
• UseStackTraceBlackList. Default true. When it is true, some classes/packages are excluded from stack trace logs. There are some common infrastructure packages that are not usually interesting in logs, that's why are excluded by default. The complete list is:
  • org.apache.catalina.core.ApplicationFilterChain
  • org.apache.tomcat
  • org.openbravo.apachejdbcconnectionpool
  • org.openbravo.util.db
  • org.hibernate
  • com.sun.proxy

Settings for logging connections:

• LogMultipleConnectionsPerThread: Default false. When it is active, a warning message will appear in log if a thread borrows at the same time more than one connection from the pool. In this message will appear for each not returned connection the stack trace from where it was borrowed. Having at the same time several connections in the same thread can be problematic as described in 35855. Note that enabling this feature in production environments can cause performance degradation because for every borrowed connection it is needed store thread information and its stack trace and also to check if there are any other connection already borrowed in the same thread.
• TrackConnections: Default false. When enabled, for each connection in the pool it is saved the stack trace for the last time it was borrowed. Its purpose is to be able to log on demand through JMX MBeans. Note if this is enabled having already pooled idle connections, stack traces will not be available for them till they are not borrowed again. Take into account tracking connections can cause performance degradation in production environments, as per each connection that is borrowed, stack traces are saved.

Logging connections, these features are only available through JMX MBeans in case TrackConnections is set to true:

• logActiveConnections: will log all connections that are currently active. A connection is considered to be active in case it has been borrowed and not returned yet to the pool. Log includes stack traces of the moment each connection was borrowed from pool, as well as current stack traces.
• logAllConnections: logs all connections in the pool, including both active and idle connections. In the log, it is included the stack trace of the connection when it was borrowed from the pool.