提交 96d51cc2 authored 作者: Thomas Mueller's avatar Thomas Mueller

Trace: slight performance improvement.

上级 c1e5b3cb
......@@ -179,7 +179,7 @@ public abstract class Command implements CommandInterface {
if (trace.isInfoEnabled()) {
long time = System.currentTimeMillis() - startTime;
if (time > Constants.SLOW_QUERY_LIMIT_MS) {
trace.info("slow query: " + time);
trace.info("slow query: {0} ms", time);
}
}
}
......
......@@ -219,7 +219,7 @@ public class CommandRemote implements CommandInterface {
try {
transfer.writeInt(SessionRemote.COMMAND_CLOSE).writeInt(id);
} catch (IOException e) {
trace.error("close", e);
trace.error(e, "close");
}
}
}
......@@ -232,7 +232,7 @@ public class CommandRemote implements CommandInterface {
}
}
} catch (DbException e) {
trace.error("close", e);
trace.error(e, "close");
}
parameters.clear();
}
......
......@@ -117,6 +117,7 @@ public class Database implements DataHandler {
private WriterThread writer;
private boolean starting;
private TraceSystem traceSystem;
private Trace trace;
private int fileLockMethod;
private Role publicRole;
private long modificationDataId;
......@@ -238,7 +239,7 @@ public class Database implements DataHandler {
SQLException e2 = (SQLException) e;
if (e2.getErrorCode() != ErrorCode.DATABASE_ALREADY_OPEN_1) {
// only write if the database is not already in use
traceSystem.getTrace(Trace.DATABASE).error("opening " + databaseName, e);
trace.error(e, "opening {0}", databaseName);
}
}
traceSystem.close();
......@@ -330,7 +331,7 @@ public class Database implements DataHandler {
if (old.getProperty("changePending") != null) {
return false;
}
getTrace().debug("wait before writing");
trace.debug("wait before writing");
Thread.sleep((int) (reconnectCheckDelay * 1.1));
Properties now = lock.load();
if (!now.equals(old)) {
......@@ -350,7 +351,7 @@ public class Database implements DataHandler {
reconnectCheckNext = System.currentTimeMillis() + 2 * reconnectCheckDelay;
old = lock.save();
if (pending) {
getTrace().debug("wait before writing again");
trace.debug("wait before writing again");
Thread.sleep((int) (reconnectCheckDelay * 1.1));
Properties now = lock.load();
if (!now.equals(old)) {
......@@ -365,7 +366,7 @@ public class Database implements DataHandler {
reconnectCheckNext = System.currentTimeMillis() + reconnectCheckDelay;
return true;
} catch (Exception e) {
getTrace().error("pending:"+ pending, e);
trace.error(e, "pending {0}", pending);
return false;
}
}
......@@ -514,8 +515,8 @@ public class Database implements DataHandler {
}
traceSystem.setLevelFile(traceLevelFile);
traceSystem.setLevelSystemOut(traceLevelSystemOut);
traceSystem.getTrace(Trace.DATABASE)
.info("opening " + databaseName + " (build " + Constants.BUILD_ID + ")");
trace = traceSystem.getTrace(Trace.DATABASE);
trace.info("opening {0} (build {1})", databaseName, Constants.BUILD_ID);
if (autoServerMode) {
if (readOnly || fileLockMethod == FileLock.LOCK_NO || fileLockMethod == FileLock.LOCK_SERIALIZED || fileLockMethod == FileLock.LOCK_FS) {
throw DbException.getUnsupportedException("autoServerMode && (readOnly || fileLockMethod == NO" +
......@@ -548,6 +549,7 @@ public class Database implements DataHandler {
writer = WriterThread.create(this, writeDelay);
} else {
traceSystem = new TraceSystem(null);
trace = traceSystem.getTrace(Trace.DATABASE);
}
systemUser = new User(this, 0, SYSTEM_USER_NAME, true);
mainSchema = new Schema(this, 0, Constants.SCHEMA_MAIN, systemUser, true);
......@@ -607,7 +609,7 @@ public class Database implements DataHandler {
}
}
systemSession.commit(true);
traceSystem.getTrace(Trace.DATABASE).info("opened " + databaseName);
trace.info("opened {0}", databaseName);
afterWriting();
}
......@@ -923,7 +925,7 @@ public class Database implements DataHandler {
}
Session session = new Session(this, user, ++nextSessionId);
userSessions.add(session);
traceSystem.getTrace(Trace.SESSION).info("connecting #" + session.getId() + " to " + databaseName);
trace.info("connecting session #{0} to {1}", session.getId(), databaseName);
if (delayedCloser != null) {
delayedCloser.reset();
delayedCloser = null;
......@@ -943,7 +945,7 @@ public class Database implements DataHandler {
}
userSessions.remove(session);
if (session != systemSession) {
traceSystem.getTrace(Trace.SESSION).info("disconnecting #" + session.getId());
trace.info("disconnecting session #{0}", session.getId());
}
}
if (userSessions.size() == 0 && session != systemSession) {
......@@ -959,7 +961,7 @@ public class Database implements DataHandler {
}
}
if (session != systemSession && session != null) {
traceSystem.getTrace(Trace.SESSION).info("disconnected #" + session.getId());
trace.info("disconnected session #{0}", session.getId());
}
}
......@@ -974,7 +976,7 @@ public class Database implements DataHandler {
s.rollback();
s.close();
} catch (DbException e) {
traceSystem.getTrace(Trace.SESSION).error("disconnecting #" + s.getId(), e);
trace.error(e, "disconnecting session #{0}", s.getId());
}
}
}
......@@ -1007,10 +1009,10 @@ public class Database implements DataHandler {
if (!fromShutdownHook) {
return;
}
traceSystem.getTrace(Trace.DATABASE).info("closing " + databaseName + " from shutdown hook");
trace.info("closing {0} from shutdown hook", databaseName);
closeAllSessionsException(null);
}
traceSystem.getTrace(Trace.DATABASE).info("closing " + databaseName);
trace.info("closing {0}", databaseName);
if (eventListener != null) {
// allow the event listener to connect to the database
closing = false;
......@@ -1044,7 +1046,7 @@ public class Database implements DataHandler {
try {
trigger.close();
} catch (SQLException e) {
traceSystem.getTrace(Trace.DATABASE).error("close", e);
trace.error(e, "close");
}
}
if (powerOffCount != -1) {
......@@ -1053,7 +1055,7 @@ public class Database implements DataHandler {
}
}
} catch (DbException e) {
traceSystem.getTrace(Trace.DATABASE).error("close", e);
trace.error(e, "close");
}
// remove all session variables
if (persistent) {
......@@ -1063,7 +1065,7 @@ public class Database implements DataHandler {
getLobStorage();
lobStorage.removeAllForTable(LobStorage.TABLE_ID_SESSION_VARIABLE);
} catch (DbException e) {
traceSystem.getTrace(Trace.DATABASE).error("close", e);
trace.error(e, "close");
}
}
}
......@@ -1071,9 +1073,9 @@ public class Database implements DataHandler {
try {
closeOpenFilesAndUnlock(true);
} catch (DbException e) {
traceSystem.getTrace(Trace.DATABASE).error("close", e);
trace.error(e, "close");
}
traceSystem.getTrace(Trace.DATABASE).info("closed");
trace.info("closed");
traceSystem.close();
if (closeOnExit != null) {
closeOnExit.reset();
......@@ -1126,12 +1128,12 @@ public class Database implements DataHandler {
e.printStackTrace();
}
}
traceSystem.getTrace(Trace.DATABASE).error("close", e);
trace.error(e, "close");
} catch (Throwable t) {
if (SysProperties.CHECK2) {
t.printStackTrace();
}
traceSystem.getTrace(Trace.DATABASE).error("close", t);
trace.error(t, "close");
}
}
}
......@@ -1157,7 +1159,7 @@ public class Database implements DataHandler {
try {
Thread.sleep((int) (reconnectCheckDelay * 1.1));
} catch (InterruptedException e) {
traceSystem.getTrace(Trace.DATABASE).error("close", e);
trace.error(e, "close");
}
}
lock.unlock();
......@@ -1174,7 +1176,7 @@ public class Database implements DataHandler {
}
}
} catch (DbException e) {
traceSystem.getTrace(Trace.DATABASE).error("close", e);
trace.error(e, "close");
}
}
......@@ -2026,10 +2028,6 @@ public class Database implements DataHandler {
return tempFileDeleter;
}
public Trace getTrace() {
return getTrace(Trace.DATABASE);
}
public PageStore getPageStore() {
if (pageStore == null) {
pageStore = new PageStore(this, databaseName + Constants.SUFFIX_PAGE_FILE, accessModeData, cacheSize);
......@@ -2103,14 +2101,14 @@ public class Database implements DataHandler {
break;
}
}
getTrace().debug("delay (change pending)");
trace.debug("delay (change pending)");
Thread.sleep(reconnectCheckDelay);
prop = lock.load();
}
reconnectLastLock = prop;
} catch (Exception e) {
// DbException, InterruptedException
getTrace().error("readOnly:" + readOnly, e);
trace.error(e, "readOnly {0}", readOnly);
// ignore
}
return true;
......@@ -2138,11 +2136,11 @@ public class Database implements DataHandler {
checkpointRunning = true;
}
synchronized (this) {
getTrace().debug("checkpoint start");
trace.debug("checkpoint start");
flushSequences();
checkpoint();
reconnectModified(false);
getTrace().debug("checkpoint end");
trace.debug("checkpoint end");
}
synchronized (reconnectSync) {
checkpointRunning = false;
......@@ -2262,7 +2260,7 @@ public class Database implements DataHandler {
pageStore.getLogMode() != PageStore.LOG_MODE_SYNC) {
// write the log mode in the trace file when enabling or
// disabling a dangerous mode
getTrace().error("log=" + log, null);
trace.error(null, "log {0}", log);
}
pageStore.setLogMode(log);
}
......
......@@ -83,7 +83,7 @@ public class DatabaseCloser extends Thread {
// if loading classes is no longer allowed
// it would throw an IllegalStateException
try {
trace.error("Could not close the database", e);
trace.error(e, "could not close the database");
// if this was successful, we ignore the exception
// otherwise not
} catch (RuntimeException e2) {
......
......@@ -14,7 +14,6 @@ import org.h2.constant.DbSettings;
import org.h2.constant.ErrorCode;
import org.h2.constant.SysProperties;
import org.h2.message.DbException;
import org.h2.message.Trace;
import org.h2.store.FileLock;
import org.h2.util.MathUtils;
import org.h2.util.New;
......@@ -189,7 +188,6 @@ public class Engine implements SessionFactory {
}
session.setAllowLiterals(false);
session.commit(true);
session.getDatabase().getTrace(Trace.SESSION).info("connected #" + session.getId());
return session;
}
......
......@@ -59,7 +59,7 @@ public class MetaRecord implements Comparable<MetaRecord> {
} catch (DbException e) {
e = e.addSQL(sql);
SQLException s = e.getSQLException();
db.getTrace(Trace.DATABASE).error(sql, s);
db.getTrace(Trace.DATABASE).error(s, sql);
if (listener != null) {
listener.exceptionThrown(s, sql);
// continue startup in this case
......
......@@ -145,7 +145,7 @@ public class SessionRemote extends SessionWithState implements DataHandler {
trans.writeInt(id);
trans.close();
} catch (IOException e) {
trace.debug("Could not cancel statement", e);
trace.debug(e, "could not cancel statement");
}
}
}
......@@ -496,7 +496,7 @@ public class SessionRemote extends SessionWithState implements DataHandler {
done(transfer);
transfer.close();
} catch (Exception e) {
trace.error("close", e);
trace.error(e, "close");
}
}
}
......@@ -580,7 +580,7 @@ public class SessionRemote extends SessionWithState implements DataHandler {
*/
public void traceOperation(String operation, int id) {
if (trace.isDebugEnabled()) {
trace.debug(operation + " " + id);
trace.debug("{0} {1}", operation, id);
}
}
......
......@@ -67,13 +67,13 @@ public class PageBtreeIndex extends PageIndex {
}
}
if (trace.isDebugEnabled()) {
trace.debug("opened " + getName() +" rows:"+ rowCount);
trace.debug("opened {0} rows: {1}", getName() , rowCount);
}
}
public void add(Session session, Row row) {
if (trace.isDebugEnabled()) {
trace.debug(getName() + " add " + row);
trace.debug("{0} add {1}", getName(), row);
}
// safe memory
SearchRow newRow = getSearchRow(row);
......@@ -92,7 +92,7 @@ public class PageBtreeIndex extends PageIndex {
break;
}
if (trace.isDebugEnabled()) {
trace.debug("split " + splitPoint);
trace.debug("split {0}", splitPoint);
}
SearchRow pivot = root.getRow(splitPoint - 1);
store.logUndo(root, root.data);
......@@ -214,7 +214,7 @@ public class PageBtreeIndex extends PageIndex {
public void remove(Session session, Row row) {
if (trace.isDebugEnabled()) {
trace.debug(getName() + " remove " + row);
trace.debug("{0} remove {1}", getName(), row);
}
if (tableData.getContainsLargeObject()) {
for (int i = 0, len = row.getColumnCount(); i < len; i++) {
......
......@@ -77,7 +77,7 @@ public class PageDataIndex extends PageIndex {
rowCount = root.getRowCount();
}
if (trace.isDebugEnabled()) {
trace.debug(this + " opened rows:" + rowCount);
trace.debug("{0} opened rows: {1}", this, rowCount);
}
table.setRowCount(rowCount);
// estimate the memory usage as follows:
......@@ -118,7 +118,7 @@ public class PageDataIndex extends PageIndex {
// when using auto-generated values, it's possible that multiple
// tries are required (specially if there was originally a primary key)
if (trace.isDebugEnabled()) {
trace.debug(getName() + " add " + row);
trace.debug("{0} add {1}", getName(), row);
}
long add = 0;
while (true) {
......@@ -163,7 +163,7 @@ public class PageDataIndex extends PageIndex {
break;
}
if (trace.isDebugEnabled()) {
trace.debug(this + " split");
trace.debug("{0} split", this);
}
long pivot = splitPoint == 0 ? row.getKey() : root.getKey(splitPoint - 1);
PageData page1 = root;
......@@ -312,7 +312,7 @@ public class PageDataIndex extends PageIndex {
}
}
if (trace.isDebugEnabled()) {
trace.debug(getName() + " remove " + row);
trace.debug("{0} remove {1}", getName(), row);
}
if (rowCount == 1) {
removeAllRows();
......@@ -344,7 +344,7 @@ public class PageDataIndex extends PageIndex {
public void remove(Session session) {
if (trace.isDebugEnabled()) {
trace.debug(this + " remove");
trace.debug("{0} remove", this);
}
removeAllRows();
store.free(rootPageId);
......@@ -353,7 +353,7 @@ public class PageDataIndex extends PageIndex {
public void truncate(Session session) {
if (trace.isDebugEnabled()) {
trace.debug(this + " truncate");
trace.debug("{0} truncate", this);
}
store.logTruncate(session, tableData.getId());
removeAllRows();
......@@ -448,7 +448,7 @@ public class PageDataIndex extends PageIndex {
public void close(Session session) {
if (trace.isDebugEnabled()) {
trace.debug(this + " close");
trace.debug("{0} close", this);
}
if (delta != null) {
delta.clear();
......
......@@ -59,7 +59,7 @@ implements ObjectFactory
//## Java 1.4 begin ##
public synchronized Object getObjectInstance(Object obj, Name name, Context nameCtx, Hashtable< ? , ? > environment) {
if (trace.isDebugEnabled()) {
trace.debug("getObjectInstance obj=" + obj + " name=" + name + " nameCtx=" + nameCtx + " environment=" + environment);
trace.debug("getObjectInstance obj={0} name={1} nameCtx={2} environment={3}", obj, name, nameCtx, environment);
}
if (obj instanceof Reference) {
Reference ref = (Reference) obj;
......
......@@ -529,11 +529,11 @@ implements XAConnection, XAResource
Trace trace = getTrace();
try {
if (!isClosed()) {
trace.error("Pooled connection not closed", openStackTrace);
trace.error(openStackTrace, "pooled connection not closed");
JdbcXAConnection.this.close();
}
} catch (SQLException e) {
trace.debug("finalize", e);
trace.debug(e, "finalize");
}
}
......
......@@ -6,6 +6,7 @@
*/
package org.h2.message;
import java.text.MessageFormat;
import org.h2.constant.SysProperties;
import org.h2.util.StringUtils;
......@@ -54,11 +55,6 @@ public class Trace {
*/
public static final String LOCK = "lock";
/**
* The trace module name for the transaction log.
*/
public static final String LOG = "log";
/**
* The trace module name for schemas.
*/
......@@ -148,11 +144,25 @@ public class Trace {
/**
* Write a message with trace level ERROR to the trace system.
*
* @param t the exception
* @param s the message
*/
public void error(Throwable t, String s) {
if (isEnabled(TraceSystem.ERROR)) {
traceWriter.write(TraceSystem.ERROR, module, s, t);
}
}
/**
* Write a message with trace level ERROR to the trace system.
*
* @param t the exception
* @param s the message
* @param params the parameters
*/
public void error(String s, Throwable t) {
public void error(Throwable t, String s, Object... params) {
if (isEnabled(TraceSystem.ERROR)) {
s = MessageFormat.format(s, (Object[]) params);
traceWriter.write(TraceSystem.ERROR, module, s, t);
}
}
......@@ -172,9 +182,22 @@ public class Trace {
* Write a message with trace level INFO to the trace system.
*
* @param s the message
* @param params the parameters
*/
public void info(String s, Object... params) {
if (isEnabled(TraceSystem.INFO)) {
s = MessageFormat.format(s, (Object[]) params);
traceWriter.write(TraceSystem.INFO, module, s, null);
}
}
/**
* Write a message with trace level INFO to the trace system.
*
* @param t the exception
* @param s the message
*/
void info(String s, Throwable t) {
void info(Throwable t, String s) {
if (isEnabled(TraceSystem.INFO)) {
traceWriter.write(TraceSystem.INFO, module, s, t);
}
......@@ -228,9 +251,11 @@ public class Trace {
* Write a message with trace level DEBUG to the trace system.
*
* @param s the message
* @param params the parameters
*/
public void debug(String s) {
public void debug(String s, Object... params) {
if (isEnabled(TraceSystem.DEBUG)) {
s = MessageFormat.format(s, (Object[]) params);
traceWriter.write(TraceSystem.DEBUG, module, s, null);
}
}
......@@ -239,14 +264,26 @@ public class Trace {
* Write a message with trace level DEBUG to the trace system.
*
* @param s the message
* @param params the parameters
*/
public void debug(String s) {
if (isEnabled(TraceSystem.DEBUG)) {
traceWriter.write(TraceSystem.DEBUG, module, s, null);
}
}
/**
* Write a message with trace level DEBUG to the trace system.
* @param t the exception
* @param s the message
*/
public void debug(String s, Throwable t) {
public void debug(Throwable t, String s) {
if (isEnabled(TraceSystem.DEBUG)) {
traceWriter.write(TraceSystem.DEBUG, module, s, t);
}
}
/**
* Write Java source code with trace level INFO to the trace system.
*
......
......@@ -403,9 +403,9 @@ public class TraceObject {
} else {
int errorCode = e.getErrorCode();
if (errorCode >= 23000 && errorCode < 24000) {
trace.info("SQLException", e);
trace.info(e, "exception");
} else {
trace.error("SQLException", e);
trace.error(e, "exception");
}
}
return e;
......
......@@ -12,12 +12,13 @@ import java.io.Writer;
import java.sql.DriverManager;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.HashMap;
import org.h2.constant.ErrorCode;
import org.h2.constant.SysProperties;
import org.h2.engine.Constants;
import org.h2.jdbc.JdbcSQLException;
import org.h2.util.IOUtils;
import org.h2.util.SmallLRUCache;
import org.h2.util.New;
/**
* The trace mechanism is the logging facility of this database. There is
......@@ -83,7 +84,7 @@ public class TraceSystem implements TraceWriter {
private int levelMax;
private int maxFileSize = DEFAULT_MAX_FILE_SIZE;
private String fileName;
private SmallLRUCache<String, Trace> traces;
private HashMap<String, Trace> traces;
private SimpleDateFormat dateFormat;
private Writer fileWriter;
private PrintWriter printWriter;
......@@ -119,14 +120,19 @@ public class TraceSystem implements TraceWriter {
}
/**
* Get or create a trace object for this module.
* Get or create a trace object for this module. Trace modules with names
* such as "JDBC[1]" are not cached (modules where the name ends with "]").
* All others are cached.
*
* @param module the module name
* @return the trace object
*/
public synchronized Trace getTrace(String module) {
if (module.endsWith("]")) {
new Trace(writer, module);
}
if (traces == null) {
traces = SmallLRUCache.newInstance(16);
traces = New.hashMap(16);
}
Trace t = traces.get(module);
if (t == null) {
......
......@@ -151,7 +151,7 @@ public class ResultRemote implements ResultInterface {
transfer.writeInt(SessionRemote.RESULT_CLOSE).writeInt(id);
}
} catch (IOException e) {
trace.error("close", e);
trace.error(e, "close");
} finally {
transfer = null;
session = null;
......@@ -164,7 +164,7 @@ public class ResultRemote implements ResultInterface {
try {
v.close();
} catch (DbException e) {
trace.error("delete lob " + v.getTraceSQL(), e);
trace.error(e, "delete lob {0}", v.getTraceSQL());
}
}
lobValues = null;
......
......@@ -163,7 +163,7 @@ public class FileLock implements Runnable {
serverSocket.close();
}
} catch (Exception e) {
trace.debug("unlock", e);
trace.debug(e, "unlock");
} finally {
fileName = null;
serverSocket = null;
......@@ -174,7 +174,7 @@ public class FileLock implements Runnable {
watchdog.interrupt();
}
} catch (Exception e) {
trace.debug("unlock", e);
trace.debug(e, "unlock");
}
}
......@@ -208,7 +208,7 @@ public class FileLock implements Runnable {
}
lastWrite = fs.getLastModified(fileName);
if (trace.isDebugEnabled()) {
trace.debug("save " + properties);
trace.debug("save {0}", properties);
}
return properties;
} catch (IOException e) {
......@@ -260,7 +260,7 @@ public class FileLock implements Runnable {
try {
Properties p2 = SortedProperties.loadProperties(fileName);
if (trace.isDebugEnabled()) {
trace.debug("load " + p2);
trace.debug("load {0}", p2);
}
return p2;
} catch (IOException e) {
......@@ -278,7 +278,7 @@ public class FileLock implements Runnable {
try {
Thread.sleep(2 * sleep);
} catch (Exception e) {
trace.debug("sleep", e);
trace.debug(e, "sleep");
}
return;
} else if (dist > TIME_GRANULARITY) {
......@@ -287,7 +287,7 @@ public class FileLock implements Runnable {
try {
Thread.sleep(SLEEP_GAP);
} catch (Exception e) {
trace.debug("sleep", e);
trace.debug(e, "sleep");
}
}
throw getExceptionFatal("Lock file recently modified", null);
......@@ -395,7 +395,7 @@ public class FileLock implements Runnable {
} catch (BindException e) {
throw getExceptionFatal("Bind Exception", null);
} catch (ConnectException e) {
trace.debug("Socket not connected to port " + port, e);
trace.debug(e, "socket not connected to port " + port);
} catch (IOException e) {
throw getExceptionFatal("IOException", null);
}
......@@ -415,7 +415,7 @@ public class FileLock implements Runnable {
properties.setProperty("ipAddress", ipAddress);
properties.setProperty("port", String.valueOf(port));
} catch (Exception e) {
trace.debug("lock", e);
trace.debug(e, "lock");
serverSocket = null;
lockFile();
return;
......@@ -496,7 +496,7 @@ public class FileLock implements Runnable {
} catch (NullPointerException e) {
// ignore
} catch (Exception e) {
trace.debug("watchdog", e);
trace.debug(e, "watchdog");
}
}
while (serverSocket != null) {
......@@ -505,11 +505,11 @@ public class FileLock implements Runnable {
Socket s = serverSocket.accept();
s.close();
} catch (Exception e) {
trace.debug("watchdog", e);
trace.debug(e, "watchdog");
}
}
} catch (Exception e) {
trace.debug("watchdog", e);
trace.debug(e, "watchdog");
}
trace.debug("watchdog end");
}
......
......@@ -109,7 +109,7 @@ public class PageInputStream extends InputStream {
}
}
if (trace.isDebugEnabled()) {
trace.debug("pageIn.readPage " + next);
trace.debug("pageIn.readPage {0}", next);
}
dataPage = -1;
data = null;
......
......@@ -179,7 +179,7 @@ public class PageLog {
* @param atEnd whether only pages at the end of the file should be used
*/
void openForWriting(int newFirstTrunkPage, boolean atEnd) {
trace.debug("log openForWriting firstPage:" + newFirstTrunkPage);
trace.debug("log openForWriting firstPage:{0}", newFirstTrunkPage);
this.firstTrunkPage = newFirstTrunkPage;
logKey++;
pageOut = new PageOutputStream(store, newFirstTrunkPage, undoAll, logKey, atEnd);
......@@ -252,7 +252,7 @@ public class PageLog {
*/
void recover(int stage) {
if (trace.isDebugEnabled()) {
trace.debug("log recover stage:" + stage);
trace.debug("log recover stage:{0}", stage);
}
if (stage == RECOVERY_STAGE_ALLOCATE) {
PageInputStream in = new PageInputStream(store, logKey, firstTrunkPage, firstDataPage);
......@@ -291,14 +291,14 @@ public class PageLog {
if (stage == RECOVERY_STAGE_UNDO) {
if (!undo.get(pageId)) {
if (trace.isDebugEnabled()) {
trace.debug("log undo " + pageId);
trace.debug("log undo {0}", pageId);
}
store.writePage(pageId, data);
undo.set(pageId);
undoAll.set(pageId);
} else {
if (trace.isDebugEnabled()) {
trace.debug("log undo skip " + pageId);
trace.debug("log undo skip {0}", pageId);
}
}
}
......@@ -311,12 +311,12 @@ public class PageLog {
} else if (stage == RECOVERY_STAGE_REDO) {
if (isSessionCommitted(sessionId, logId, pos)) {
if (trace.isDebugEnabled()) {
trace.debug("log redo + table:" + tableId + " s:" + sessionId + " " + row);
trace.debug("log redo + table: {0} s:{1} {2}", tableId, sessionId, row);
}
store.redo(pos, tableId, row, true);
} else {
if (trace.isDebugEnabled()) {
trace.debug("log ignore s:" + sessionId + " + table:" + tableId + " " + row);
trace.debug("log ignore s:{0} + table:{1} {2}", sessionId, tableId, row);
}
}
}
......@@ -327,12 +327,12 @@ public class PageLog {
if (stage == RECOVERY_STAGE_REDO) {
if (isSessionCommitted(sessionId, logId, pos)) {
if (trace.isDebugEnabled()) {
trace.debug("log redo - table:" + tableId + " key:" + key);
trace.debug("log redo - table:{0} key:{1}", tableId, key);
}
store.redoDelete(pos, tableId, key);
} else {
if (trace.isDebugEnabled()) {
trace.debug("log ignore s:" + sessionId + " - table:" + tableId + " key:" + key);
trace.debug("log ignore s:{0} - table:{1} key:{2}", sessionId, tableId, key);
}
}
}
......@@ -342,12 +342,12 @@ public class PageLog {
if (stage == RECOVERY_STAGE_REDO) {
if (isSessionCommitted(sessionId, logId, pos)) {
if (trace.isDebugEnabled()) {
trace.debug("log redo truncate table:" + tableId);
trace.debug("log redo truncate table:{0}", tableId);
}
store.redoTruncate(tableId);
} else {
if (trace.isDebugEnabled()) {
trace.debug("log ignore s:" + sessionId + " truncate table:" + tableId);
trace.debug("log ignore s:{0} truncate table:{1}", sessionId, tableId);
}
}
}
......@@ -355,7 +355,7 @@ public class PageLog {
int sessionId = in.readVarInt();
String transaction = in.readString();
if (trace.isDebugEnabled()) {
trace.debug("log prepare commit " + sessionId + " " + transaction + " pos:" + pos);
trace.debug("log prepare commit {0} {1} pos:{2}", sessionId, transaction, pos);
}
if (stage == RECOVERY_STAGE_UNDO) {
int page = pageIn.getDataPage();
......@@ -364,13 +364,13 @@ public class PageLog {
} else if (x == ROLLBACK) {
int sessionId = in.readVarInt();
if (trace.isDebugEnabled()) {
trace.debug("log rollback " + sessionId + " pos:" + pos);
trace.debug("log rollback {0} pos:{1}", sessionId, pos);
}
// ignore - this entry is just informational
} else if (x == COMMIT) {
int sessionId = in.readVarInt();
if (trace.isDebugEnabled()) {
trace.debug("log commit " + sessionId + " pos:" + pos);
trace.debug("log commit {0} pos:{1}", sessionId, pos);
}
if (stage == RECOVERY_STAGE_UNDO) {
setLastCommitForSession(sessionId, logId, pos);
......@@ -475,7 +475,7 @@ public class PageLog {
return;
}
if (trace.isDebugEnabled()) {
trace.debug("log undo " + pageId);
trace.debug("log undo {0}", pageId);
}
if (SysProperties.CHECK) {
if (page == null) {
......@@ -513,7 +513,7 @@ public class PageLog {
private void freeLogPages(IntArray pages) {
if (trace.isDebugEnabled()) {
trace.debug("log frees " + pages.get(0) + ".." + pages.get(pages.size() - 1));
trace.debug("log frees {0}..{1}", pages.get(0), pages.get(pages.size() - 1));
}
Data buffer = getBuffer();
buffer.writeByte((byte) FREE_LOG);
......@@ -537,7 +537,7 @@ public class PageLog {
*/
void commit(int sessionId) {
if (trace.isDebugEnabled()) {
trace.debug("log commit s:" + sessionId);
trace.debug("log commit s:{0}", sessionId);
}
if (store.getDatabase().getPageStore() == null) {
// database already closed
......@@ -560,7 +560,7 @@ public class PageLog {
*/
void prepareCommit(Session session, String transaction) {
if (trace.isDebugEnabled()) {
trace.debug("log prepare commit s:" + session.getId() + " " + transaction);
trace.debug("log prepare commit s:{0}, {1}", session.getId(), transaction);
}
if (store.getDatabase().getPageStore() == null) {
// database already closed
......@@ -596,8 +596,7 @@ public class PageLog {
*/
void logAddOrRemoveRow(Session session, int tableId, Row row, boolean add) {
if (trace.isDebugEnabled()) {
trace.debug("log " + (add?"+":"-") + " s:" + session.getId() + " table:" + tableId +
" row:" + row);
trace.debug("log {0} s:{1} table:{2} row:{3}", add ? "+" : "-", session.getId(), tableId, row);
}
session.addLogPos(logSectionId, logPos);
logPos++;
......@@ -641,7 +640,7 @@ public class PageLog {
*/
void logTruncate(Session session, int tableId) {
if (trace.isDebugEnabled()) {
trace.debug("log truncate s:" + session.getId() + " table:" + tableId);
trace.debug("log truncate s:{0} table:{1}", session.getId(), tableId);
}
session.addLogPos(logSectionId, logPos);
logPos++;
......@@ -714,7 +713,7 @@ public class PageLog {
* @return the trunk page of the data page to keep
*/
private int removeUntil(int trunkPage, int firstDataPageToKeep) {
trace.debug("log.removeUntil " + trunkPage + " " + firstDataPageToKeep);
trace.debug("log.removeUntil {0} {1}", trunkPage, firstDataPageToKeep);
while (true) {
Page p = store.getPage(trunkPage);
PageStreamTrunk t = (PageStreamTrunk) p;
......
......@@ -143,7 +143,7 @@ public class PageOutputStream {
private void storePage() {
if (trace.isDebugEnabled()) {
trace.debug("pageOut.storePage " + data);
trace.debug("pageOut.storePage {0}", data);
}
data.write();
}
......@@ -175,7 +175,7 @@ public class PageOutputStream {
*/
void fillPage() {
if (trace.isDebugEnabled()) {
trace.debug("pageOut.storePage fill " + data.getPos());
trace.debug("pageOut.storePage fill {0}", data.getPos());
}
reserve(data.getRemaining() + 1);
reserved -= data.getRemaining();
......
......@@ -423,7 +423,7 @@ public class PageStore implements CacheWriter {
freed.clear(i);
} else if (!freed.get(i)) {
if (trace.isDebugEnabled()) {
trace.debug("free " + i);
trace.debug("free {0}", i);
}
file.seek((long) i << pageSizeShift);
file.readFully(test, 0, 16);
......@@ -601,7 +601,7 @@ public class PageStore implements CacheWriter {
pageCount = newPageCount;
// the easiest way to remove superfluous entries
freeLists.clear();
trace.debug("pageCount:" + pageCount);
trace.debug("pageCount:{0}", pageCount);
long newLength = (long) pageCount << pageSizeShift;
if (file.length() != newLength) {
file.setLength(newLength);
......@@ -629,7 +629,7 @@ public class PageStore implements CacheWriter {
if (f != null) {
DbException.throwInternalError("not free: " + f);
}
trace.debug("swap " + a + " and " + b + " via " + free);
trace.debug("swap {0} and {1} via {2}", a, b, free);
Page pageA = null;
if (isUsed(a)) {
pageA = getPage(a);
......@@ -674,7 +674,7 @@ public class PageStore implements CacheWriter {
freePage(full);
}
} else {
trace.debug("move " + p.getPos() + " to " + free);
trace.debug("move {0} to {1}", p.getPos(), free);
try {
p.moveTo(systemSession, free);
} finally {
......@@ -900,7 +900,7 @@ public class PageStore implements CacheWriter {
*/
void setLogFirstPage(int logKey, int trunkPageId, int dataPageId) {
if (trace.isDebugEnabled()) {
trace.debug("setLogFirstPage key: " + logKey + " trunk: " + trunkPageId + " data: " + dataPageId);
trace.debug("setLogFirstPage key: {0} trunk: {1} data: {2}", logKey, trunkPageId, dataPageId);
}
this.logKey = logKey;
this.logFirstTrunkPage = trunkPageId;
......@@ -977,7 +977,7 @@ public class PageStore implements CacheWriter {
public void writeBack(CacheObject obj) {
Page record = (Page) obj;
if (trace.isDebugEnabled()) {
trace.debug("writeBack " + record);
trace.debug("writeBack {0}", record);
}
synchronized (database) {
record.write();
......@@ -1019,7 +1019,7 @@ public class PageStore implements CacheWriter {
synchronized (database) {
if (trace.isDebugEnabled()) {
if (!page.isChanged()) {
trace.debug("updateRecord " + page.toString());
trace.debug("updateRecord {0}", page.toString());
}
}
checkOpen();
......@@ -1214,7 +1214,7 @@ public class PageStore implements CacheWriter {
*/
void freeUnused(int pageId) {
if (trace.isDebugEnabled()) {
trace.debug("freeUnused " + pageId);
trace.debug("freeUnused {0}", pageId);
}
synchronized (database) {
cache.remove(pageId);
......@@ -1336,7 +1336,7 @@ public class PageStore implements CacheWriter {
if (reservedPages != null) {
for (int r : reservedPages.keySet()) {
if (trace.isDebugEnabled()) {
trace.debug("reserve " + r);
trace.debug("reserve {0}", r);
}
allocatePage(r);
}
......@@ -1586,7 +1586,7 @@ public class PageStore implements CacheWriter {
String[] ops = StringUtils.arraySplit(options, ',', false);
Index meta;
if (trace.isDebugEnabled()) {
trace.debug("addMeta id=" + id + " type=" + type + " root=" + rootPageId + " parent=" + parent + " columns=" + columnList);
trace.debug("addMeta id={0} type={1} root={2} parent={3} columns={4}", id, type, rootPageId, parent, columnList);
}
if (redo && rootPageId != 0) {
// ensure the page is empty, but not used by regular data
......
......@@ -87,7 +87,7 @@ public class WriterThread implements Runnable {
} catch (Exception e) {
TraceSystem traceSystem = database.getTraceSystem();
if (traceSystem != null) {
traceSystem.getTrace(Trace.LOG).error("flush", e);
traceSystem.getTrace(Trace.DATABASE).error(e, "flush");
}
}
// TODO log writer: could also flush the dirty cache
......
......@@ -137,7 +137,7 @@ public class RegularTable extends TableBase {
// this could happen, for example on failure in the storage
// but if that is not the case it means there is something wrong
// with the database
trace.error("Could not undo operation", e);
trace.error(e2, "could not undo operation");
throw e2;
}
DbException de = DbException.convert(e);
......@@ -259,7 +259,7 @@ public class RegularTable extends TableBase {
// this could happen, for example on failure in the storage
// but if that is not the case it means
// there is something wrong with the database
trace.error("Could not remove index", e);
trace.error(e2, "could not remove index");
throw e2;
}
throw e;
......@@ -364,7 +364,7 @@ public class RegularTable extends TableBase {
// this could happen, for example on failure in the storage
// but if that is not the case it means there is something wrong
// with the database
trace.error("Could not undo operation", e);
trace.error(e2, "could not undo operation");
throw e2;
}
throw DbException.convert(e);
......@@ -590,7 +590,7 @@ public class RegularTable extends TableBase {
private void traceLock(Session session, boolean exclusive, String s) {
if (traceLock.isDebugEnabled()) {
traceLock.debug(session.getId() + " " + (exclusive ? "exclusive write lock" : "shared read lock") + " " + s + " " + getName());
traceLock.debug("{0} {1} {2} {3}", session.getId(), exclusive ? "exclusive write lock" : "shared read lock", s, getName());
}
}
......
......@@ -415,7 +415,7 @@ public class TableLink extends Table {
*/
public PreparedStatement getPreparedStatement(String sql, boolean exclusive) {
if (trace.isDebugEnabled()) {
trace.debug(getName() + ":\n" + sql);
trace.debug("{0} :\n{1}", getName(), sql);
}
try {
if (conn == null) {
......
Markdown 格式
0%
您添加了 0 到此讨论。请谨慎行事。
请先完成此评论的编辑!
注册 或者 后发表评论