...
| Auszug |
|---|
...
|
...
|
Um alle SQL Statements in alten Log4J-Konfiguration zu loggen, müssen folgende Zeilen in der log4j.properties hinzugefügt werden:
| Codeblock | ||
|---|---|---|
| ||
#SQL logging
log4j.logger.SQLLogger=DEBUG |
Die Datei log4j.propierties ist im "conf" Verzeichnis des Servers zu finden, zusammen mit den Dateien jdbc.properties und server.properties. Dabei werden mit folgenden Einstellungen des log4j-Loggers alle relevanten Informationen ausgegeben:
| Codeblock |
|---|
log4j.appender.stdout.layout.ConversionPattern=%d %-5p %-9t [%c{3}] - %m%n
log4j.rootLogger=INFO, stdout, logfile |
Die Ausgabe des SQL Statements vor der Ausführung erscheint dann in der Datei server.log im Verzeichnis logs und sieht z.B. folgendermaßen aus:
| Codeblock |
|---|
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] |
Zusätzlich kann noch die Zeit der einzelnen SQL-Statmens gemessen werden. Dazu muss der SQLTimer aktiviert werden:
| Codeblock |
|---|
#SQL logging
log4j.logger.SQLTimer=DEBUG |
Damit wird das SQL Statement nach der Ausführung zusammen mit der Dauer ausgegeben:
| Codeblock |
|---|
2013-06-27 14:44:09,599 DEBUG pool-2-thread-1 [SQLTimer] - 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]=(32 ms)
|
Hinweis: Es kann hilfreich sein, sowohl das Statement vor, als auch nach der Ausführung zu loggen. Insbesondere wenn Statements besonders lange dauern. Dafür werden einfach die beiden Zeilen kombiniert:
| Codeblock |
|---|
#SQL logging
log4j.logger.SQLLogger=DEBUG
log4j.logger.SQLTimer=DEBUG |
Dies funktioniert ab Nuclos 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):
| Codeblock |
|---|
private static boolean testForFullDebug(final ConnectionRunner<?> runner) {
final String debugSQL = "FROM T_MD_STATE";
....
} |
Außerdem lässt sich das StackTrace-Logging ganz allgemein für alle SQL-Statments in der log4j.propertier steuern:
| Codeblock |
|---|
#SQL logging
log4j.logger.SQLLogger=DEBUG
log4j.logger.ClientStackTrace=DEBUG
log4j.logger.ServerStackTrace=DEBUG |
Mit der Option "DEBUG" werden nur StackTrace Elemente, welche mit "org.nuclos" beginnen geloggt. Wenn alle Element ausgegeben werden sollen, dann sollte die Option "TRACE" verwenden werden:
| Codeblock |
|---|
#SQL logging
log4j.logger.SQLLogger=DEBUG
log4j.logger.ClientStackTrace=TRACE
log4j.logger.ServerStackTrace=TRACE |
Nuclos verwendete intern log4j Version 1.2.x für das Logging. Wenn Sie in Ihrer Installation die Datei <nuclos_home>/conf/log4j.properties anpassen, können Sie das Log Verhalten des Servers in weiten Bereichen konfigurieren. Auf diese Seite finden Sie verschiedene Beispielkonfigurationen, die
Weitergehende Informationen zu log4j finden Sie z.B. unter
| Info |
|---|
Die hier vorgestellte Methode, unterschiedliche Log Dateien zu erzeugen und/oder das Logging in eine Datenbank umzuleiten, funktionieren auch in weiteren Fällen. Beispielsweise ist es möglich, das client lifecycle logging auf dem Server entsprechend zu konfigurieren. Das zu konfigurierende Log Handle ist hierbei |
| Codeblock |
|---|
# standard log stuff
log4j.appender.logfile=org.apache.log4j.RollingFileAppender
log4j.appender.logfile.File=/home/tpasch2/nuclos4/logs/server.log
log4j.appender.logfile.MaxBackupIndex=1000
log4j.appender.logfile.MaxFileSize=1GB
log4j.appender.logfile.layout=org.apache.log4j.PatternLayout
log4j.appender.logfile.layout.ConversionPattern=%d %p [%c] - %m%n
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d %p [%c] - %m%n
log4j.rootLogger=INFO, stdout, logfile
# create another log file
log4j.appender.clientlifecycle=org.apache.log4j.RollingFileAppender
log4j.appender.clientlifecycle.File=/home/tpasch2/nuclos4/logs/clientlifecycle.log
log4j.appender.clientlifecycle.MaxBackupIndex=1000
log4j.appender.clientlifecycle.MaxFileSize=1GB
log4j.appender.clientlifecycle.layout=org.apache.log4j.PatternLayout
log4j.appender.clientlifecycle.layout.ConversionPattern=%d %p [%c] - %m%n
# use the file for a certain category
log4j.category.org.nuclos.server.web.ClientLifecycle=INFO, clientlifecycle
log4j.additivty.org.nuclos.server.web.ClientLifecycle=false
log4j.logger.org.nuclos.server.web.ClientLifecycle=INFO |
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):
Nuclos altes SQL Logging: log4j 1.2, log4j.properties, JDBCAppender, LOGS Tabelle, PostgreSQL, Oracle, SQLTimer. |
Sprache: Deutsch · English
SQL-Logging für Nuclos bis 4.5 (log4j 1.2) – JDBCAppender in die Datenbank und alte Standard-Konfiguration.
| Status | ||||
|---|---|---|---|---|
|
| Status | ||||
|---|---|---|---|---|
|
| Status | ||||
|---|---|---|---|---|
|
| Status | ||||
|---|---|---|---|---|
|
| Panel | ||||||
|---|---|---|---|---|---|---|
| ||||||
Auf dieser Seite
|
| Hinweis | ||
|---|---|---|
| ||
Diese Seite gilt für Nuclos bis 4.5 mit log4j 1.2 ( |
SELECT-Statements lassen sich direkt in eine (beliebige) Datenbank schreiben. Zuerst die Zieltabelle anlegen (PostgreSQL; bei Oracle MESSAGE als CLOB):
| 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) ); |
Dazu sind folgende Parameter in die o.g. log4j.propierties hinzuzufügen und entsprechend anzupassen.
...
Dann den JDBCAppender in log4j.properties konfigurieren:
| 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 |
...
| Tipp |
|---|
| 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 |
...
| ||
Log-Level möglichst hoch setzen, damit die DB nicht überlastet wird. Durch |
...
Entfernen von |
...
|
...
/ |
...
beschränken. |
Mit "SQLTimer" werden die Angaben zur verbrauchten Zeit an die Message gehängt. Um diese einfacher auszuwerten, kann folgendes DB-Statements durchgeführt werden:
| 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' |
Hinweis: Die Syntax der Statements ist PostgreSQL-Spezifisch. Für andere Datenbanken müssen die Statements angepasst werden.
Beispiel einer möglichen Auswertung:
| 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 |
...
...
Um alle SQL Statements zu loggen, müssen folgende Zeilen in der log4j.properties hinzugefügt werden:
...
| Codeblock | ||
|---|---|---|
|
#SQL logging
log4j.logger.org.nuclos.server.dblayer=DEBUG
log4j.logger.org.nuclos.server.dal.processor.jdbc.impl.standard.StandardSqlDBAccess=DEBUG |
...
Nach dem Ergänzen muss der Server neu gestartet werden; die Ausgabe erscheint im server.log.
Die Ausgabe erscheint dann in der Datei server.log im Verzeichnis logs und sieht z.B. folgendermaßen aus:
| Codeblock |
|---|
2013-02-11 10:02:28,208 DEBUG localhost-startStop-1 [impl.standard.StandardSqlDBAccess] - Query to execute:
SELECT * FROM (SELECT entity.INTID FROM T_MD_entity entity WHERE entity.STRentity = ?) WHERE ROWNUM <= 2
[PSDH_Typ] |
Wenn die Ausführung des SQL Statements länger als 0.1 Sekunden braucht, wird anschließend noch eine Zeitangabe (in Millisekunden) ausgegeben: