Michael Platzer's SQL Logging patch, with millisecond timeing and a few stylistic changes.
This commit is contained in:
parent
183e222f67
commit
156ad8f721
1 changed files with 104 additions and 36 deletions
|
@ -18,7 +18,6 @@ package helma.objectmodel.db;
|
||||||
|
|
||||||
import helma.framework.core.Application;
|
import helma.framework.core.Application;
|
||||||
import helma.objectmodel.*;
|
import helma.objectmodel.*;
|
||||||
import helma.util.CacheMap;
|
|
||||||
|
|
||||||
import java.io.IOException;
|
import java.io.IOException;
|
||||||
import java.io.Reader;
|
import java.io.Reader;
|
||||||
|
@ -513,10 +512,6 @@ public final class NodeManager {
|
||||||
String nameField = dbm.getNameField();
|
String nameField = dbm.getNameField();
|
||||||
String prototypeField = dbm.getPrototypeField();
|
String prototypeField = dbm.getPrototypeField();
|
||||||
|
|
||||||
if (logSql) {
|
|
||||||
app.logEvent("### insertNode: " + insertString);
|
|
||||||
}
|
|
||||||
|
|
||||||
try {
|
try {
|
||||||
int stmtNumber = 1;
|
int stmtNumber = 1;
|
||||||
|
|
||||||
|
@ -553,7 +548,15 @@ public final class NodeManager {
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
stmt.executeUpdate();
|
stmt.executeUpdate();
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = java.lang.System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL INSERT", dbm.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, insertString);
|
||||||
|
}
|
||||||
} finally {
|
} finally {
|
||||||
if (stmt != null) {
|
if (stmt != null) {
|
||||||
try {
|
try {
|
||||||
|
@ -651,10 +654,6 @@ public final class NodeManager {
|
||||||
Connection con = dbm.getConnection();
|
Connection con = dbm.getConnection();
|
||||||
PreparedStatement stmt = con.prepareStatement(b.toString());
|
PreparedStatement stmt = con.prepareStatement(b.toString());
|
||||||
|
|
||||||
if (logSql) {
|
|
||||||
app.logEvent("### updateNode: " + b.toString());
|
|
||||||
}
|
|
||||||
|
|
||||||
int stmtNumber = 0;
|
int stmtNumber = 0;
|
||||||
|
|
||||||
try {
|
try {
|
||||||
|
@ -677,7 +676,16 @@ public final class NodeManager {
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
stmt.executeUpdate();
|
stmt.executeUpdate();
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL UPDATE", dbm.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, b.toString());
|
||||||
|
}
|
||||||
|
|
||||||
} finally {
|
} finally {
|
||||||
if (stmt != null) {
|
if (stmt != null) {
|
||||||
try {
|
try {
|
||||||
|
@ -723,11 +731,17 @@ public final class NodeManager {
|
||||||
.toString();
|
.toString();
|
||||||
|
|
||||||
st = con.createStatement();
|
st = con.createStatement();
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
st.executeUpdate(str);
|
st.executeUpdate(str);
|
||||||
|
|
||||||
if (logSql) {
|
if (logSql) {
|
||||||
app.logEvent("### deleteNode: " + str);
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL DELETE", dbm.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, str);
|
||||||
}
|
}
|
||||||
|
|
||||||
} finally {
|
} finally {
|
||||||
if (st != null) {
|
if (st != null) {
|
||||||
try {
|
try {
|
||||||
|
@ -761,8 +775,16 @@ public final class NodeManager {
|
||||||
|
|
||||||
stmt = con.createStatement();
|
stmt = con.createStatement();
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
ResultSet rs = stmt.executeQuery(q);
|
ResultSet rs = stmt.executeQuery(q);
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_MAX", map.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, q);
|
||||||
|
}
|
||||||
|
|
||||||
// check for empty table
|
// check for empty table
|
||||||
if (!rs.next()) {
|
if (!rs.next()) {
|
||||||
long currMax = map.getNewID(0);
|
long currMax = map.getNewID(0);
|
||||||
|
@ -803,8 +825,16 @@ public final class NodeManager {
|
||||||
|
|
||||||
stmt = con.createStatement();
|
stmt = con.createStatement();
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
ResultSet rs = stmt.executeQuery(q);
|
ResultSet rs = stmt.executeQuery(q);
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_NEXTVAL", map.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, q);
|
||||||
|
}
|
||||||
|
|
||||||
if (!rs.next()) {
|
if (!rs.next()) {
|
||||||
throw new SQLException("Error creating ID from Sequence: empty recordset");
|
throw new SQLException("Error creating ID from Sequence: empty recordset");
|
||||||
}
|
}
|
||||||
|
@ -876,18 +906,22 @@ public final class NodeManager {
|
||||||
true)).toString();
|
true)).toString();
|
||||||
}
|
}
|
||||||
|
|
||||||
if (logSql) {
|
|
||||||
app.logEvent("### getNodeIDs: " + q);
|
|
||||||
}
|
|
||||||
|
|
||||||
stmt = con.createStatement();
|
stmt = con.createStatement();
|
||||||
|
|
||||||
if (rel.maxSize > 0) {
|
if (rel.maxSize > 0) {
|
||||||
stmt.setMaxRows(rel.maxSize);
|
stmt.setMaxRows(rel.maxSize);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
ResultSet result = stmt.executeQuery(q);
|
ResultSet result = stmt.executeQuery(q);
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_IDS", table,
|
||||||
|
logTimeStart, logTimeStop, q);
|
||||||
|
}
|
||||||
|
|
||||||
// problem: how do we derive a SyntheticKey from a not-yet-persistent Node?
|
// problem: how do we derive a SyntheticKey from a not-yet-persistent Node?
|
||||||
Key k = (rel.groupby != null) ? home.getKey() : null;
|
Key k = (rel.groupby != null) ? home.getKey() : null;
|
||||||
|
|
||||||
|
@ -969,16 +1003,20 @@ public final class NodeManager {
|
||||||
true));
|
true));
|
||||||
}
|
}
|
||||||
|
|
||||||
if (logSql) {
|
|
||||||
app.logEvent("### getNodes: " + q.toString());
|
|
||||||
}
|
|
||||||
|
|
||||||
if (rel.maxSize > 0) {
|
if (rel.maxSize > 0) {
|
||||||
stmt.setMaxRows(rel.maxSize);
|
stmt.setMaxRows(rel.maxSize);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
ResultSet rs = stmt.executeQuery(q.toString());
|
ResultSet rs = stmt.executeQuery(q.toString());
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_ALL", dbm.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, q.toString());
|
||||||
|
}
|
||||||
|
|
||||||
while (rs.next()) {
|
while (rs.next()) {
|
||||||
// create new Nodes.
|
// create new Nodes.
|
||||||
Node node = createNode(rel.otherType, rs, columns, 0);
|
Node node = createNode(rel.otherType, rs, columns, 0);
|
||||||
|
@ -1078,13 +1116,15 @@ public final class NodeManager {
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
if (logSql) {
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
app.logEvent("### prefetchNodes: " + q.toString());
|
|
||||||
}
|
|
||||||
|
|
||||||
ResultSet rs = stmt.executeQuery(q.toString());
|
ResultSet rs = stmt.executeQuery(q.toString());
|
||||||
|
|
||||||
;
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_PREFETCH", dbm.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, q.toString());
|
||||||
|
}
|
||||||
|
|
||||||
String groupbyProp = null;
|
String groupbyProp = null;
|
||||||
HashMap groupbySubnodes = null;
|
HashMap groupbySubnodes = null;
|
||||||
|
@ -1231,14 +1271,18 @@ public final class NodeManager {
|
||||||
false)).toString();
|
false)).toString();
|
||||||
}
|
}
|
||||||
|
|
||||||
if (logSql) {
|
|
||||||
app.logEvent("### countNodes: " + q);
|
|
||||||
}
|
|
||||||
|
|
||||||
stmt = con.createStatement();
|
stmt = con.createStatement();
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
ResultSet rs = stmt.executeQuery(q);
|
ResultSet rs = stmt.executeQuery(q);
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_COUNT", table,
|
||||||
|
logTimeStart, logTimeStop, q);
|
||||||
|
}
|
||||||
|
|
||||||
if (!rs.next()) {
|
if (!rs.next()) {
|
||||||
retval = 0;
|
retval = 0;
|
||||||
} else {
|
} else {
|
||||||
|
@ -1306,12 +1350,16 @@ public final class NodeManager {
|
||||||
|
|
||||||
stmt = con.createStatement();
|
stmt = con.createStatement();
|
||||||
|
|
||||||
if (logSql) {
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
app.logEvent("### getPropertyNames: " + q);
|
|
||||||
}
|
|
||||||
|
|
||||||
ResultSet rs = stmt.executeQuery(q.toString());
|
ResultSet rs = stmt.executeQuery(q.toString());
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_ACCESSNAMES", table,
|
||||||
|
logTimeStart, logTimeStop, q.toString());
|
||||||
|
}
|
||||||
|
|
||||||
while (rs.next()) {
|
while (rs.next()) {
|
||||||
String n = rs.getString(1);
|
String n = rs.getString(1);
|
||||||
|
|
||||||
|
@ -1378,12 +1426,16 @@ public final class NodeManager {
|
||||||
|
|
||||||
dbm.addJoinConstraints(q, " AND ");
|
dbm.addJoinConstraints(q, " AND ");
|
||||||
|
|
||||||
if (logSql) {
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
app.logEvent("### getNodeByKey: " + q.toString());
|
|
||||||
}
|
|
||||||
|
|
||||||
ResultSet rs = stmt.executeQuery(q.toString());
|
ResultSet rs = stmt.executeQuery(q.toString());
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_BYKEY", dbm.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, q.toString());
|
||||||
|
}
|
||||||
|
|
||||||
if (!rs.next()) {
|
if (!rs.next()) {
|
||||||
return null;
|
return null;
|
||||||
}
|
}
|
||||||
|
@ -1476,14 +1528,18 @@ public final class NodeManager {
|
||||||
false));
|
false));
|
||||||
}
|
}
|
||||||
|
|
||||||
if (logSql) {
|
|
||||||
app.logEvent("### getNodeByRelation: " + q.toString());
|
|
||||||
}
|
|
||||||
|
|
||||||
stmt = con.createStatement();
|
stmt = con.createStatement();
|
||||||
|
|
||||||
|
long logTimeStart = logSql ? System.currentTimeMillis() : 0;
|
||||||
|
|
||||||
ResultSet rs = stmt.executeQuery(q.toString());
|
ResultSet rs = stmt.executeQuery(q.toString());
|
||||||
|
|
||||||
|
if (logSql) {
|
||||||
|
long logTimeStop = System.currentTimeMillis();
|
||||||
|
logSqlStatement("SQL SELECT_BYRELATION", dbm.getTableName(),
|
||||||
|
logTimeStart, logTimeStop, q.toString());
|
||||||
|
}
|
||||||
|
|
||||||
if (!rs.next()) {
|
if (!rs.next()) {
|
||||||
return null;
|
return null;
|
||||||
}
|
}
|
||||||
|
@ -1979,4 +2035,16 @@ public final class NodeManager {
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
private void logSqlStatement(String type, String table,
|
||||||
|
long logTimeStart, long logTimeStop, String statement) {
|
||||||
|
app.logEvent(new StringBuffer().append(type)
|
||||||
|
.append(" ")
|
||||||
|
.append(table)
|
||||||
|
.append(" ")
|
||||||
|
.append((logTimeStop - logTimeStart))
|
||||||
|
.append(": ")
|
||||||
|
.append(statement.toString())
|
||||||
|
.toString());
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|
Loading…
Add table
Reference in a new issue