diff --git a/log4j2.properties b/log4j2.properties index 59bff4ab..063eec24 100644 --- a/log4j2.properties +++ b/log4j2.properties @@ -11,8 +11,8 @@ logger.hsqldb.name = hsqldb.db logger.hsqldb.level = warn # Support optional, per-session HSQLDB debugging -logger.hsqldbDebug.name = org.qora.repository.hsqldb.HSQLDBRepository -logger.hsqldbDebug.level = debug +logger.hsqldbRepository.name = org.qora.repository.hsqldb +logger.hsqldbRepository.level = trace # Suppress extraneous Jersey warning logger.jerseyInject.name = org.glassfish.jersey.internal.inject.Providers diff --git a/src/main/java/org/qora/repository/AccountRepository.java b/src/main/java/org/qora/repository/AccountRepository.java index b29d36dc..a1533b2d 100644 --- a/src/main/java/org/qora/repository/AccountRepository.java +++ b/src/main/java/org/qora/repository/AccountRepository.java @@ -23,6 +23,9 @@ public interface AccountRepository { /** Returns account's flags or null if account not found. */ public Integer getFlags(String address) throws DataException; + /** Returns whether account exists. */ + public boolean accountExists(String address) throws DataException; + /** Returns number of accounts enabled to forge by given address. */ public int countForgingAccountsEnabledByAddress(String address) throws DataException; diff --git a/src/main/java/org/qora/repository/Repository.java b/src/main/java/org/qora/repository/Repository.java index efab17e5..a11fa1c8 100644 --- a/src/main/java/org/qora/repository/Repository.java +++ b/src/main/java/org/qora/repository/Repository.java @@ -33,6 +33,8 @@ public interface Repository extends AutoCloseable { public void rebuild() throws DataException; + public boolean getDebug(); + public void setDebug(boolean debugState); } diff --git a/src/main/java/org/qora/repository/hsqldb/HSQLDBAccountRepository.java b/src/main/java/org/qora/repository/hsqldb/HSQLDBAccountRepository.java index 625b4434..981df2dc 100644 --- a/src/main/java/org/qora/repository/hsqldb/HSQLDBAccountRepository.java +++ b/src/main/java/org/qora/repository/hsqldb/HSQLDBAccountRepository.java @@ -85,6 +85,15 @@ public class HSQLDBAccountRepository implements AccountRepository { } } + @Override + public boolean accountExists(String address) throws DataException { + try { + return this.repository.exists("Accounts", "account = ?", address); + } catch (SQLException e) { + throw new DataException("Unable to check for account in repository", e); + } + } + @Override public int countForgingAccountsEnabledByAddress(String address) throws DataException { try (ResultSet resultSet = this.repository.checkedExecute("SELECT COUNT(*) FROM Accounts WHERE forging_enabler = ? LIMIT 1", address)) { @@ -96,16 +105,33 @@ public class HSQLDBAccountRepository implements AccountRepository { @Override public void ensureAccount(AccountData accountData) throws DataException { - HSQLDBSaver saveHelper = new HSQLDBSaver("Accounts"); + byte[] publicKey = accountData.getPublicKey(); - saveHelper.bind("account", accountData.getAddress()); + try (ResultSet resultSet = this.repository.checkedExecute("SELECT public_key FROM Accounts WHERE account = ?", accountData.getAddress())) { + if (resultSet != null) { + // We know account record exists at this point. + // If accountData has no public key then we're done. + // If accountData's public key matches repository's public key then we're done. + if (publicKey == null || Arrays.equals(resultSet.getBytes(1), publicKey)) + return; + } - byte[] publicKey = accountData.getPublicKey(); - if (publicKey != null) - saveHelper.bind("public_key", publicKey); + // No record exists, or we have a public key to set + HSQLDBSaver saveHelper = new HSQLDBSaver("Accounts"); + + saveHelper.bind("account", accountData.getAddress()); + + if (publicKey != null) + saveHelper.bind("public_key", publicKey); + + // XXX TMP DEBUGGING + boolean priorDebug = this.repository.getDebug(); + this.repository.setDebug(true); - try { saveHelper.execute(this.repository); + + // XXX TMP DEBUGGING + this.repository.setDebug(priorDebug); } catch (SQLException e) { throw new DataException("Unable to ensure minimal account in repository", e); } @@ -122,7 +148,14 @@ public class HSQLDBAccountRepository implements AccountRepository { saveHelper.bind("public_key", publicKey); try { + // XXX TMP DEBUGGING + boolean priorDebug = this.repository.getDebug(); + this.repository.setDebug(true); + saveHelper.execute(this.repository); + + // XXX TMP DEBUGGING + this.repository.setDebug(priorDebug); } catch (SQLException e) { throw new DataException("Unable to save account's last reference into repository", e); } @@ -139,7 +172,14 @@ public class HSQLDBAccountRepository implements AccountRepository { saveHelper.bind("public_key", publicKey); try { + // XXX TMP DEBUGGING + boolean priorDebug = this.repository.getDebug(); + this.repository.setDebug(true); + saveHelper.execute(this.repository); + + // XXX TMP DEBUGGING + this.repository.setDebug(priorDebug); } catch (SQLException e) { throw new DataException("Unable to save account's default group ID into repository", e); } @@ -156,7 +196,14 @@ public class HSQLDBAccountRepository implements AccountRepository { saveHelper.bind("public_key", publicKey); try { + // XXX TMP DEBUGGING + boolean priorDebug = this.repository.getDebug(); + this.repository.setDebug(true); + saveHelper.execute(this.repository); + + // XXX TMP DEBUGGING + this.repository.setDebug(priorDebug); } catch (SQLException e) { throw new DataException("Unable to save account's flags into repository", e); } @@ -173,7 +220,14 @@ public class HSQLDBAccountRepository implements AccountRepository { saveHelper.bind("public_key", publicKey); try { + // XXX TMP DEBUGGING + boolean priorDebug = this.repository.getDebug(); + this.repository.setDebug(true); + saveHelper.execute(this.repository); + + // XXX TMP DEBUGGING + this.repository.setDebug(priorDebug); } catch (SQLException e) { throw new DataException("Unable to save account's forging enabler into repository", e); } diff --git a/src/main/java/org/qora/repository/hsqldb/HSQLDBRepository.java b/src/main/java/org/qora/repository/hsqldb/HSQLDBRepository.java index 31c9a809..090378fa 100644 --- a/src/main/java/org/qora/repository/hsqldb/HSQLDBRepository.java +++ b/src/main/java/org/qora/repository/hsqldb/HSQLDBRepository.java @@ -44,15 +44,33 @@ public class HSQLDBRepository implements Repository { protected boolean debugState = false; protected Long slowQueryThreshold = null; protected List sqlStatements; + protected long sessionId; // NB: no visibility modifier so only callable from within same package - HSQLDBRepository(Connection connection) { + HSQLDBRepository(Connection connection) throws DataException { this.connection = connection; this.savepoints = new ArrayDeque<>(3); this.slowQueryThreshold = Settings.getInstance().getSlowQueryThreshold(); if (this.slowQueryThreshold != null) this.sqlStatements = new ArrayList(); + + // Find out our session ID + try (Statement stmt = this.connection.createStatement()) { + if (!stmt.execute("SELECT SESSION_ID()")) + throw new DataException("Unable to fetch session ID from repository"); + + try (ResultSet resultSet = stmt.getResultSet()) { + if (resultSet == null || !resultSet.next()) + LOGGER.warn("Unable to fetch session ID from repository"); + + this.sessionId = resultSet.getLong(1); + } + } catch (SQLException e) { + throw new DataException("Unable to fetch session ID from repository", e); + } + + assertEmptyTransaction("connection creation"); } @Override @@ -109,6 +127,9 @@ public class HSQLDBRepository implements Repository { } finally { this.savepoints.clear(); + // Before clearing statements so we can log what led to assertion error + assertEmptyTransaction("transaction commit"); + if (this.sqlStatements != null) this.sqlStatements.clear(); } @@ -123,6 +144,9 @@ public class HSQLDBRepository implements Repository { } finally { this.savepoints.clear(); + // Before clearing statements so we can log what led to assertion error + assertEmptyTransaction("transaction commit"); + if (this.sqlStatements != null) this.sqlStatements.clear(); } @@ -172,21 +196,7 @@ public class HSQLDBRepository implements Repository { } try (Statement stmt = this.connection.createStatement()) { - // Diagnostic check for uncommitted changes - if (!stmt.execute("SELECT transaction, transaction_size FROM information_schema.system_sessions")) // TRANSACTION_SIZE() broken? - throw new DataException("Unable to check repository status during close"); - - try (ResultSet resultSet = stmt.getResultSet()) { - if (resultSet == null || !resultSet.next()) - LOGGER.warn("Unable to check repository status during close"); - - boolean inTransaction = resultSet.getBoolean(1); - int transactionCount = resultSet.getInt(2); - if (inTransaction && transactionCount != 0) { - LOGGER.warn("Uncommitted changes (" + transactionCount + ") during repository close", new Exception("Uncommitted repository changes")); - logStatements(); - } - } + assertEmptyTransaction("connection close"); // give connection back to the pool this.connection.close(); @@ -200,6 +210,11 @@ public class HSQLDBRepository implements Repository { public void rebuild() throws DataException { } + @Override + public boolean getDebug() { + return this.debugState; + } + @Override public void setDebug(boolean debugState) { this.debugState = debugState; @@ -210,7 +225,7 @@ public class HSQLDBRepository implements Repository { */ public PreparedStatement prepareStatement(String sql) throws SQLException { if (this.debugState) - LOGGER.debug(sql); + LOGGER.debug(String.format("[%d] %s", this.sessionId, sql)); if (this.sqlStatements != null) this.sqlStatements.add(sql); @@ -227,6 +242,8 @@ public class HSQLDBRepository implements Repository { if (this.sqlStatements == null) return; + LOGGER.info("HSQLDB SQL statements leading up to this were:"); + for (String sql : this.sqlStatements) LOGGER.info(sql); } @@ -461,6 +478,29 @@ public class HSQLDBRepository implements Repository { return e; } + private void assertEmptyTransaction(String context) throws DataException { + try (Statement stmt = this.connection.createStatement()) { + // Diagnostic check for uncommitted changes + if (!stmt.execute("SELECT transaction, transaction_size FROM information_schema.system_sessions WHERE session_id = " + this.sessionId)) // TRANSACTION_SIZE() broken? + throw new DataException("Unable to check repository status after " + context); + + try (ResultSet resultSet = stmt.getResultSet()) { + if (resultSet == null || !resultSet.next()) + LOGGER.warn("Unable to check repository status after " + context); + + boolean inTransaction = resultSet.getBoolean(1); + int transactionCount = resultSet.getInt(2); + + if (inTransaction && transactionCount != 0) { + LOGGER.warn(String.format("Uncommitted changes (%d) after %s, session [%d]", transactionCount, context, this.sessionId), new Exception("Uncommitted repository changes")); + logStatements(); + } + } + } catch (SQLException e) { + throw new DataException("Error checking repository status after " + context, e); + } + } + /** Converts milliseconds from epoch to OffsetDateTime needed for TIMESTAMP WITH TIME ZONE columns. */ /* package */ static OffsetDateTime toOffsetDateTime(long timestamp) { return OffsetDateTime.ofInstant(Instant.ofEpochMilli(timestamp), ZoneOffset.UTC);