Versions Compared

Old Version 14

changes.mady.by.user Bob Swift

Saved on

compared with

New Version 15

changes.mady.by.user Jeff Pierce

Saved on

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

Table of Contents
maxlevel3
minlevel2
typeflat
separatorpipe

Log SQL statements

Administrators can optionally log all SQL statements used in sql macros. This option is enabled by adding configuration in the ../WEB-INF/classes/log4j.properties file. In addition, warnings are issued when the default row limit is exceeded. Timing logging is also available since version 5.1.0.

No Format
titleAdd to ../WEB-INF/classes/log4j.properties
# SQL statement logging
log4j.appender.sqlplugin=org.apache.log4j.RollingFileAppender
log4j.appender.sqlplugin.File=${catalina.home}/home/logs/sql-plugin.log
log4j.appender.sqlplugin.Threshold=INFO
log4j.appender.sqlplugin.MaxFileSize=20480KB
log4j.appender.sqlplugin.MaxBackupIndex=10
log4j.appender.sqlplugin.layout=com.atlassian.confluence.util.PatternLayoutWithContext
log4j.appender.sqlplugin.layout.ConversionPattern=%d [%t] %m%n

log4j.logger.org.swift.confluence.sql.SqlMacro.statement=INFO, sqlplugin
log4j.additivity.org.swift.confluence.sql.SqlMacro.statement=false

log4j.logger.org.swift.confluence.sql.SqlQueryMacro.statement=INFO, sqlplugin
log4j.additivity.org.swift.confluence.sql.SqlQueryMacro.statement=false

log4j.logger.org.swift.confluence.sql.SqlFileMacro.statement=INFO, sqlplugin
log4j.additivity.org.swift.confluence.sql.SqlFileMacro.statement=false
 
# SQL time logging
log4j.logger.org.swift.confluence.sql.SqlMacro.timing=INFO, sqlplugin
log4j.additivity.org.swift.confluence.sql.SqlMacro.timing=false

log4j.logger.org.swift.confluence.sql.SqlQueryMacro.timing=INFO, sqlplugin
log4j.additivity.org.swift.confluence.sql.SqlQueryMacro.timing=false
 
log4j.logger.org.swift.confluence.sql.SqlFileMacro.timing=INFO, sqlplugin
log4j.additivity.org.swift.confluence.sql.SqlFileMacro.timing=false


Tip
titleUsing another Windows drive

A direct Windows path can be specified with a drive but you must use forward slashes (or double back slashes) according to this reference).

Add INFO logging at runtime

  1. Go to Administration -> Logging and Profiling
  2. Find the Add new entry area
  3. Add INFO entries for the following: org.swift.confluence.sql.SqlMacro.statement and org.swift.confluence.sql.SqlQueryMacro.statement
  4. Log statements will appear in the standard confluence log file
  5. Logging will occur immediately, but only last until Confluence is restarted


Add DEBUG logging at runtime

  1. Go to Administration -> Logging and Profiling
  2. Find the Add new entry area near the top of the page
  3. Add the following entry for the Class/Package Name: org.swift.confluence.sql
  4. Select DEBUG for the New Level value and click Add entry 
  5. Log statements will appear in the standard confluence log file
  6. Logging will occur immediately, but only last until Confluence is restarted
  7. You will want to be sure and go back and remove the entry that was added after you have completed triaging your issue. 


Tip
titleUse logging when establishing or lowering row limit

Setting or lowering the row limit in an installation may cause a few existing SQL queries to show only the limited number of rows. Use logging to track usage that exceeds the limit. Investigate queries that exceed the default limit for correctness. If correct, use the limit parameter to prevent further warnings.


Tip
titleAdditivity

Setting additivity to false prevents sql being logged to your main confluence log.


Example log

No Format
2012-10-20 05:14:57,019 [http-8116-4] userId: admin, dataSource: testDS, contentId: 91816371, spaceKey: zsql, title: dateRows, sql: DELETE from test_date;
            INSERT INTO test_date VALUES (1, date '2009-09-30', timestamp '2009-09-30 01:00', timestamp '2009-09-30 01:00', time '05:45:01', time '14:20');
            INSERT INTO test_date VALUES (2, date '2010-08-10', timestamp '2010-08-10 13:00', timestamp '2010-08-10 13:00', time '13:45:01', time '02:20');
            INSERT INTO test_date VALUES (3, date '2008-12-31', timestamp '2010-08-10 01:01', timestamp '2010-08-10 01:01', time '13:05:00', time '14:35');
            INSERT INTO test_date VALUES (4, date '2010-03-01', timestamp '2010-08-10 01:00', timestamp '2010-08-10 01:00', time '23:55:00', time '11:35');
            INSERT INTO test_date VALUES (5, date '2010-03-05', timestamp '2009-08-10 01:00', timestamp '2009-08-10 01:00', time '11:55:00', time '02:55');
            INSERT INTO test_date VALUES (6, date '2008-01-30', timestamp '2009-08-10 01:00', timestamp '2009-08-10 02:00', time '08:00:01', time '02:10');
            INSERT INTO test_date VALUES (7, date '2009-03-01', timestamp '2009-08-10 01:00', timestamp '2009-08-10 01:00', time '07:45:01', time '23:59');
            SELECT * from test_date;
2012-10-20 05:14:58,137 [http-8116-4] userId: admin, dataSource: testDS, contentId: 91816372, spaceKey: zsql, title: dateSort, sql: SELECT * from test_date


No Format
titleTiming logging
2012-10-21 19:29:48,113 [http-8116-4] statement time: 2293 ms, total time: 2300 ms, sql: select ...

Interpreting Logging

Statements are logged prior to the database being called and include the space key and page title the macro was on.

Time is logged after the after the database operation completes. The fields are defined as follows:

statement time

Difference between making the request to the database and database completing the query and return a successful response
total timeDifference between making the request to the database and retrieving all result sets, constructing tables, and any wiki rendering required