SQL Logging

...

Standard SQL Logging

Um alle SQL Statements zu loggen, müssen folgende Zeilen in der log4j.properties hinzugefügt werden:

...

2013-06-27 14:44:09,567 DEBUG pool-2-thread-1 [SQLLogger] - SELECT t.INTID, t.DATCREATED, t.STRCREATED, t.DATCHANGED, t.STRCHANGED, t.INTVERSION, t.INTNUCLETVERSION, t.STRPACKAGE, t.STRNAMESPACE, t.DESCRIPTION, t.NAME FROM T_AD_APPLICATION t WHERE (1=1 AND t.INTID IN (?))
=[40013466]

...

...

SQL Performance Logging

Zusätzlich kann noch die Zeit der einzelnen SQL-Statmens gemessen werden. Dazu muss der SQLTimer aktiviert werden:

...

#SQL logging
log4j.logger.SQLLogger=DEBUG
log4j.logger.SQLTimer=DEBUG

...

...

SQL StackTrace Logging 

Dies funktioniert ab Nuclos Logging (ab 3.14.9).

Es kann zusätzlich noch der StackTrace, sowohl vom Server, als auch vom Client, bis zur Ausführung des SQL-Statements geloggt werden. Das ist möglich für bestimmte SQL-Statements oder für alle SQL-Statements. Für bestimmte Statements kann in der ersten Methode der Klasse "DataSourceExecuter" ein String-Suchbegriff eingegeben werden (auch zur Laufzeit, wenn der Server im Debug-Modus gestertet wurde):

...

#SQL logging
log4j.logger.SQLLogger=DEBUG
log4j.logger.ClientStackTrace=TRACE
log4j.logger.ServerStackTrace=TRACE

...

...

JDBCAppender SQL Logging

Zusätzlich (oder alternativ) lassen sich die SELECT SQL Statements direkt in eine Datenbank schreiben. Dies erledigt das Apache log4j-Framework. Dazu braucht man eine Datenbank, die nicht notwendigerweise identisch mit der Nuclos-DB sein muss. Dort muss eine Tabelle angelegt werden, z.B. für PostgreSQL (bei Oracle sollte die Spalte "MESSAGE" ein CLOB sein):4a)

POSTGRESQL

...

Codeblock
CREATE TABLE <SCHEMA>.LOGS( DATED TIMESTAMP NOT NULL PRIMARY KEY, LOGGER VARCHAR(127) NOT NULL, LEVEL VARCHAR(15) NOT NULL, MESSAGE VARCHAR(10485760) NOT NULL, THREAD VARCHAR(4000) NOT NULL, TIME INTEGER, PARAMS VARCHAR(4000) );

...

ORACLE

...

Codeblock
CREATE TABLE <SCHEMA>.LOGS( "DATED" TIMESTAMP NOT NULL PRIMARY KEY, "LOGGER" VARCHAR(127) NOT NULL, "LEVEL" VARCHAR(15) NOT NULL, "MESSAGE" CLOB NOT NULL, "THREAD" VARCHAR(4000) NOT NULL, "TIME" NUMBER(11), "PARAMS" VARCHAR(4000) );

...

Dazu sind folgende Parameter in die o.g. log4j.propierties hinzuzufügen und entsprechend anzupassen.4c)

POSTGRESQL

...

Codeblock

#SQL logging log4j.logger.SQLLogger=DEBUG, DB log4j.logger.SQLTimer=DEBUG, DB   #JDBCAppender log4j.appender.DB=org.apache.log4j.jdbc.JDBCAppender log4j.appender.DB.driver=org.postgresql.Driver log4j.appender.DB.URL=jdbc\:postgresql\://datenbankip\:5432/postgres log4j.appender.DB.user=nuclos log4j.appender.DB.password=nuclos log4j.appender.DB.sql=INSERT INTO <SCHEMA>.LOGS VALUES('%d{yyyy-MM-dd HH:mm:ss.SSS}','%c','%p','%m','%t') log4j.appender.DB.layout=org.apache.log4j.PatternLayout

...

ORACLE

...

Codeblock

#SQL logging log4j.logger.SQLLogger=DEBUG, DB log4j.logger.SQLTimer=DEBUG, DB   #JDBCAppender log4j.appender.DB=org.apache.log4j.jdbc.JDBCAppender log4j.appender.DB.driver=oracle.jdbc.driver.OracleDriver log4j.appender.DB.URL=jdbc:oracle:thin:@datenbankip:1521:oracle log4j.appender.DB.user=nuclos log4j.appender.DB.password=nuclos log4j.appender.DB.sql=INSERT INTO <SCHEMA>.LOGS ("DATED", "LOGGER", "LEVEL", "MESSAGE", "THREAD", "TIME", "PARAMS") VALUES (to_timestamp('%d{yyyy-MM-dd HH:mm:ss.SSS}','YYYY-MM-DD HH24:MI:SS.FF3'),'%c','%p','%m','%t',0,'') log4j.appender.DB.layout=org.apache.log4j.PatternLayout log4j.appender.DB.commit=true

 

Es ist zu empfehlen, den Log-Level möglichst hoch zu setzten (wie hier "WARN") damit die DB beim Loggin nicht überlastet wird. Durch entfernen von "stdout" oder "logfile" kann das Logging auf die DB selber beschränkt werden. 5)

Auswertung der SQLTimer Werte aus der Datenbank

Mit "SQLTimer" werden die Angaben zur verbrauchten Zeit an die Message gehängt. Um diese einfacher auszuwerten, kann folgendes DB-Statements durchgeführt werden:5a)

POSTGRESQL

...

Codeblock
UPDATE <SCHEMA>.LOGS SET TIME = CAST(SUBSTRING( MESSAGE FROM POSITION('=(' IN MESSAGE)+2 FOR POSITION(' ms)' IN MESSAGE)-POSITION('=(' IN MESSAGE)-2) AS INTEGER), PARAMS = SUBSTRING(MESSAGE FROM POSITION('=[' IN MESSAGE)+2 FOR POSITION(']=' IN MESSAGE)-POSITION('=[' IN MESSAGE)-2), MESSAGE = RTRIM(SUBSTRING(MESSAGE FROM 0 FOR POSITION('=[' IN MESSAGE)-1)) WHERE LOGGER = 'SQLTimer'

...

Codeblock
DELETE FROM <SCHEMA>.LOGS WHERE LOGGER != 'SQLTimer' SELECT SUM(TIME) AS SUM, COUNT(TIME) AS COUNT, MESSAGE FROM <SCHEMA>.LOGS GROUP BY MESSAGE ORDER BY SUM DESC

...

...

Altes Standard SQL Logging (3.13.8 oder früher)

Um alle SQL Statements zu loggen, müssen folgende Zeilen in der log4j.properties hinzugefügt werden:

...