Search in sources :

Example 1 with LogCounter

use of org.apache.derby.impl.store.raw.log.LogCounter in project derby by apache.

the class FileLogger method logAndUndo.

/**
 *		Writes out a compensation log record to the log stream, and call its
 *		doMe method to undo the change of a previous log operation.
 *
 *		<P>MT - Not needed. A transaction must be single threaded thru undo, each
 *		RawTransaction has its own logger, therefore no need to synchronize.
 *		The RawTransaction must handle synchronizing with multiple threads
 *		during rollback.
 *
 *		@param xact the transaction logging the change
 *		@param compensation the compensation log operation
 *		@param undoInstant the log instant of the operation that is to be
 *		rolled back
 *		@param in optional data input for the compenastion doMe method
 *
 *		@return the instant in the log that can be used to identify the log
 *		record
 *
 *		@exception StandardException Derby Standard error policy
 */
public LogInstant logAndUndo(RawTransaction xact, Compensation compensation, LogInstant undoInstant, LimitObjectInput in) throws StandardException {
    boolean inUserCode = false;
    try {
        logOutputBuffer.reset();
        TransactionId transactionId = xact.getId();
        // write out the log header with the operation embedded
        logRecord.setValue(transactionId, compensation);
        inUserCode = true;
        logicalOut.writeObject(logRecord);
        inUserCode = false;
        // write out the undoInstant
        logicalOut.writeLong(((LogCounter) undoInstant).getValueAsLong());
        // in this implemetaion, there is no optional data for the
        // compensation operation.  Optional data for the rollback comes
        // from the undoable operation - and is passed into this call.
        int completeLength = logOutputBuffer.getPosition();
        long instant = 0;
        if (logFactory.databaseEncrypted()) {
            // we must pad the encryption data to be multiple of block
            // size, which is logFactory.getEncryptionBlockSize()
            int encryptedLength = completeLength;
            if ((encryptedLength % logFactory.getEncryptionBlockSize()) != 0)
                encryptedLength = encryptedLength + logFactory.getEncryptionBlockSize() - (encryptedLength % logFactory.getEncryptionBlockSize());
            if (encryptionBuffer == null || encryptionBuffer.length < encryptedLength)
                encryptionBuffer = new byte[encryptedLength];
            System.arraycopy(logOutputBuffer.getByteArray(), 0, encryptionBuffer, 0, completeLength);
            // do not bother to clear out the padding area
            int len = logFactory.encrypt(encryptionBuffer, 0, encryptedLength, encryptionBuffer, 0);
            if (SanityManager.DEBUG)
                SanityManager.ASSERT(len == encryptedLength, "encrypted log buffer length != log buffer len");
            instant = logFactory.appendLogRecord(encryptionBuffer, 0, encryptedLength, null, 0, 0);
        } else {
            instant = logFactory.appendLogRecord(logOutputBuffer.getByteArray(), 0, completeLength, null, 0, 0);
        }
        LogInstant logInstant = new LogCounter(instant);
        if (SanityManager.DEBUG) {
            if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                SanityManager.DEBUG(LogToFile.DBG_FLAG, "Write CLR: Xact: " + transactionId.toString() + "clrinstant: " + logInstant.toString() + " undoinstant " + undoInstant + "\n");
            }
        }
        try {
            // in and dataLength contains optional data that was written
            // to the log during a previous call to logAndDo.
            compensation.doMe(xact, logInstant, in);
        } catch (StandardException se) {
            throw logFactory.markCorrupt(StandardException.newException(SQLState.LOG_DO_ME_FAIL, se, compensation));
        } catch (IOException ioe) {
            throw logFactory.markCorrupt(StandardException.newException(SQLState.LOG_DO_ME_FAIL, ioe, compensation));
        }
        return logInstant;
    } catch (IOException ioe) {
        if (inUserCode) {
            throw StandardException.newException(SQLState.LOG_WRITE_LOG_RECORD, ioe, compensation);
        } else {
            throw StandardException.newException(SQLState.LOG_BUFFER_FULL, ioe, compensation);
        }
    }
}
Also used : StandardException(org.apache.derby.shared.common.error.StandardException) LogInstant(org.apache.derby.iapi.store.raw.log.LogInstant) LogCounter(org.apache.derby.impl.store.raw.log.LogCounter) IOException(java.io.IOException) TransactionId(org.apache.derby.iapi.store.raw.xact.TransactionId)

Example 2 with LogCounter

use of org.apache.derby.impl.store.raw.log.LogCounter in project derby by apache.

the class Scan method resetPosition.

/**
 *		Reset the scan to the given LogInstant.
 *
 *		@param instant the position to reset to
 *		@exception IOException scan cannot access the log at the new position.
 *		@exception StandardException standard Derby error policy
 */
public void resetPosition(LogInstant instant) throws IOException, StandardException {
    if (SanityManager.DEBUG)
        SanityManager.ASSERT(instant != null);
    long instant_long = ((LogCounter) instant).getValueAsLong();
    if ((instant_long == LogCounter.INVALID_LOG_INSTANT) || (stopAt != LogCounter.INVALID_LOG_INSTANT && (scanDirection == FORWARD && instant_long > stopAt) || (scanDirection == FORWARD && instant_long < stopAt))) {
        close();
        throw StandardException.newException(SQLState.LOG_RESET_BEYOND_SCAN_LIMIT, instant, new LogCounter(stopAt));
    } else {
        long fnum = ((LogCounter) instant).getLogFileNumber();
        if (fnum != currentLogFileNumber) {
            if (SanityManager.DEBUG) {
                if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                    SanityManager.DEBUG(LogToFile.DBG_FLAG, "Scan " + scanDirection + " resetting to " + instant + " need to switch log from " + currentLogFileNumber + " to " + fnum);
                }
            }
            scan.close();
            scan = logFactory.getLogFileAtPosition(instant_long);
            currentLogFileNumber = fnum;
            if (scanDirection == FORWARD) {
                // NOTE:
                // 
                // just get the length of the file without syncing.
                // this only works because the only place forward scan is used
                // right now is on recovery redo and nothing is being added to
                // the current log file.  When the forward scan is used for some
                // other purpose, need to sync access to the end of the log
                // 
                currentLogFileLength = scan.length();
            }
        } else {
            long fpos = ((LogCounter) instant).getLogFilePosition();
            scan.seek(fpos);
            // 
            // RESOLVE: Can this be optimized? Does it belong here.
            currentLogFileLength = scan.length();
            if (SanityManager.DEBUG) {
                if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                    SanityManager.DEBUG(LogToFile.DBG_FLAG, "Scan reset to " + instant);
                }
            }
        }
        currentInstant = instant_long;
        // scan is being reset, it is possibly that, scan is doing a random
        // access of the log file. set the knownGoodLogEnd to  the instant
        // scan 	is being reset to.
        // Note: reset gets called with undo forward scan for CLR processing during
        // recovery, if this value is not reset checks to find the end of log
        // getNextRecordForward() will fail because undoscan scans log file
        // back & forth to redo CLR's.
        knownGoodLogEnd = currentInstant;
        if (SanityManager.DEBUG) {
            if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                SanityManager.DEBUG(LogToFile.DBG_FLAG, "Scan.getInstant reset to " + currentInstant + LogCounter.toDebugString(currentInstant));
            }
        }
    }
}
Also used : LogCounter(org.apache.derby.impl.store.raw.log.LogCounter)

Example 3 with LogCounter

use of org.apache.derby.impl.store.raw.log.LogCounter in project derby by apache.

the class FileLogger method logAndDo.

/*
	** Methods of Logger
	*/
/**
 *		Writes out a log record to the log stream, and call its doMe method to
 *		apply the change to the rawStore.
 *		<BR>Any optional data the doMe method need is first written to the log
 *		stream using operation.writeOptionalData, then whatever is written to
 *		the log stream is passed back to the operation for the doMe method.
 *
 *		<P>MT - there could be multiple threads running in the same raw
 *		transactions and they can be calling the same logger to log different
 *		log operations.  This whole method is synchronized to make sure log
 *		records are logged one at a time.
 *
 *		@param xact the transaction logging the change
 *		@param operation the log operation
 *		@return the instant in the log that can be used to identify the log
 *		record
 *
 *		@exception StandardException Derby Standard error policy
 */
public synchronized LogInstant logAndDo(RawTransaction xact, Loggable operation) throws StandardException {
    boolean isLogPrepared = false;
    boolean inUserCode = false;
    byte[] preparedLog;
    try {
        logOutputBuffer.reset();
        // always use the short Id, only the BeginXact log record contains
        // the XactId (long form)
        TransactionId transactionId = xact.getId();
        // write out the log header with the operation embedded
        // this is by definition not a compensation log record,
        // those are called thru the logAndUndo interface
        logRecord.setValue(transactionId, operation);
        inUserCode = true;
        logicalOut.writeObject(logRecord);
        inUserCode = false;
        int optionalDataLength = 0;
        int optionalDataOffset = 0;
        int completeLength = 0;
        ByteArray preparedLogArray = operation.getPreparedLog();
        if (preparedLogArray != null) {
            preparedLog = preparedLogArray.getArray();
            optionalDataLength = preparedLogArray.getLength();
            optionalDataOffset = preparedLogArray.getOffset();
            // There is a race condition if the operation is a begin tran in
            // that between the time the beginXact log record is written to
            // disk and the time the transaction object is updated in the
            // beginXact.doMe method, other log records may be written.
            // This will render the transaction table in an inconsistent state
            // since it may think a later transaction is the earliest
            // transaction or it may think that there is no active transactions
            // where there is a bunch of them sitting on the log.
            // 
            // Similarly, there is a race condition for endXact, i.e.,
            // 1) endXact is written to the log,
            // 2) checkpoint gets that (committed) transaction as the
            // firstUpdateTransaction
            // 3) the transaction calls postComplete, nulling out itself
            // 4) checkpoint tries to access a closed transaction object
            // 
            // The solution is to sync between the time a begin tran or end
            // tran log record is sent to the log stream and its doMe method is
            // called to update the transaction table and in memory state
            // 
            // We only need to serialized the begin and end Xact log records
            // because once a transaction has been started and in the
            // transaction table, its order and transaction state does not
            // change.
            // 
            // Use the logFactory as the sync object so that a checkpoint can
            // take its snap shot of the undoLWM before or after a transaction
            // is started, but not in the middle. (see LogToFile.checkpoint)
            // 
            // now set the input limit to be the optional data.
            // This limits amount of data availiable to logIn that doMe can
            // use
            logIn.setData(preparedLog);
            logIn.setPosition(optionalDataOffset);
            logIn.setLimit(optionalDataLength);
            if (SanityManager.DEBUG) {
                if ((optionalDataLength) != logIn.available())
                    SanityManager.THROWASSERT(" stream not set correctly " + optionalDataLength + " != " + logIn.available());
            }
        } else {
            preparedLog = null;
            optionalDataLength = 0;
        }
        logicalOut.writeInt(optionalDataLength);
        completeLength = logOutputBuffer.getPosition() + optionalDataLength;
        LogInstant logInstant = null;
        // in case of encryption, we need to pad
        int encryptedLength = 0;
        try {
            if (logFactory.databaseEncrypted()) {
                // we must pad the encryption data to be multiple of block
                // size, which is logFactory.getEncryptionBlockSize()
                encryptedLength = completeLength;
                if ((encryptedLength % logFactory.getEncryptionBlockSize()) != 0)
                    encryptedLength = encryptedLength + logFactory.getEncryptionBlockSize() - (encryptedLength % logFactory.getEncryptionBlockSize());
                if (encryptionBuffer == null || encryptionBuffer.length < encryptedLength)
                    encryptionBuffer = new byte[encryptedLength];
                System.arraycopy(logOutputBuffer.getByteArray(), 0, encryptionBuffer, 0, completeLength - optionalDataLength);
                if (optionalDataLength > 0)
                    System.arraycopy(preparedLog, optionalDataOffset, encryptionBuffer, completeLength - optionalDataLength, optionalDataLength);
                // do not bother to clear out the padding area
                int len = logFactory.encrypt(encryptionBuffer, 0, encryptedLength, encryptionBuffer, 0);
                if (SanityManager.DEBUG)
                    SanityManager.ASSERT(len == encryptedLength, "encrypted log buffer length != log buffer len");
            }
            if ((operation.group() & (Loggable.FIRST | Loggable.LAST)) != 0) {
                synchronized (logFactory) {
                    long instant = 0;
                    if (logFactory.databaseEncrypted()) {
                        // encryption has completely drained both the the
                        // logOuputBuffer array and the preparedLog array
                        instant = logFactory.appendLogRecord(encryptionBuffer, 0, encryptedLength, null, -1, 0);
                    } else {
                        instant = logFactory.appendLogRecord(logOutputBuffer.getByteArray(), 0, completeLength, preparedLog, optionalDataOffset, optionalDataLength);
                    }
                    logInstant = new LogCounter(instant);
                    operation.doMe(xact, logInstant, logIn);
                }
            } else {
                long instant = 0;
                if (logFactory.databaseEncrypted()) {
                    // encryption has completely drained both the the
                    // logOuputBuffer array and the preparedLog array
                    instant = logFactory.appendLogRecord(encryptionBuffer, 0, encryptedLength, null, -1, 0);
                } else {
                    instant = logFactory.appendLogRecord(logOutputBuffer.getByteArray(), 0, completeLength, preparedLog, optionalDataOffset, optionalDataLength);
                }
                logInstant = new LogCounter(instant);
                operation.doMe(xact, logInstant, logIn);
            }
        } catch (StandardException se) {
            throw logFactory.markCorrupt(StandardException.newException(SQLState.LOG_DO_ME_FAIL, se, operation));
        } catch (IOException ioe) {
            throw logFactory.markCorrupt(StandardException.newException(SQLState.LOG_DO_ME_FAIL, ioe, operation));
        } finally {
            logIn.clearLimit();
        }
        if (SanityManager.DEBUG) {
            if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                SanityManager.DEBUG(LogToFile.DBG_FLAG, "Write log record: tranId=" + transactionId.toString() + " instant: " + logInstant.toString() + " length: " + completeLength + "\n" + operation + "\n");
            }
        }
        return logInstant;
    } catch (IOException ioe) {
        // error writing to the log buffer
        if (inUserCode) {
            throw StandardException.newException(SQLState.LOG_WRITE_LOG_RECORD, ioe, operation);
        } else {
            throw StandardException.newException(SQLState.LOG_BUFFER_FULL, ioe, operation);
        }
    }
}
Also used : StandardException(org.apache.derby.shared.common.error.StandardException) LogInstant(org.apache.derby.iapi.store.raw.log.LogInstant) ByteArray(org.apache.derby.iapi.util.ByteArray) LogCounter(org.apache.derby.impl.store.raw.log.LogCounter) IOException(java.io.IOException) TransactionId(org.apache.derby.iapi.store.raw.xact.TransactionId)

Example 4 with LogCounter

use of org.apache.derby.impl.store.raw.log.LogCounter in project derby by apache.

the class FileLogger method reprepare.

/**
 * During recovery re-prepare a transaction.
 * <p>
 * After redo() and undo(), this routine is called on all outstanding
 * in-doubt (prepared) transactions.  This routine re-acquires all
 * logical write locks for operations in the xact, and then modifies
 * the transaction table entry to make the transaction look as if it
 * had just been prepared following startup after recovery.
 * <p>
 *
 * @param t                 is the transaction performing the re-prepare
 * @param prepareId         is the transaction ID to be re-prepared
 * @param prepareStopAt     is where the log instant (inclusive) where the
 *                          re-prepare should stop.
 * @param prepareStartAt    is the log instant (inclusive) where re-prepare
 *                          should begin, this is normally the log instant
 *                          of the last log record of the transaction that
 *                          is to be re-prepare.  If null, then re-prepare
 *                          starts from the end of the log.
 *
 * @exception  StandardException  Standard exception policy.
 */
public void reprepare(RawTransaction t, TransactionId prepareId, LogInstant prepareStopAt, LogInstant prepareStartAt) throws StandardException {
    if (SanityManager.DEBUG) {
        if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
            if (prepareStartAt != null) {
                SanityManager.DEBUG(LogToFile.DBG_FLAG, "----------------------------------------------------\n" + "\nBegin of RePrepare : " + prepareId.toString() + "start at " + prepareStartAt.toString() + " stop at " + prepareStopAt.toString() + "\n----------------------------------------------------\n");
            } else {
                SanityManager.DEBUG(LogToFile.DBG_FLAG, "----------------------------------------------------\n" + "\nBegin of Reprepare: " + prepareId.toString() + "start at end of log stop at " + prepareStopAt.toString() + "\n----------------------------------------------------\n");
            }
        }
    }
    // statistics
    int clrskipped = 0;
    int logrecordseen = 0;
    RePreparable lop = null;
    // stream to read the log record - initial size 4096, scanLog needs
    // to resize if the log record is larger than that.
    ArrayInputStream rawInput = null;
    try {
        StreamLogScan scanLog;
        if (prepareStartAt == null) {
            // don't know where to start, scan from end of log
            scanLog = (StreamLogScan) logFactory.openBackwardsScan(prepareStopAt);
        } else {
            if (prepareStartAt.lessThan(prepareStopAt)) {
                // nothing to prepare!
                return;
            }
            scanLog = (StreamLogScan) logFactory.openBackwardsScan(((LogCounter) prepareStartAt).getValueAsLong(), prepareStopAt);
        }
        if (SanityManager.DEBUG)
            SanityManager.ASSERT(scanLog != null, "cannot open log for prepare");
        rawInput = new ArrayInputStream(new byte[4096]);
        LogRecord record;
        while ((record = scanLog.getNextRecord(rawInput, prepareId, 0)) != null) {
            if (SanityManager.DEBUG) {
                SanityManager.ASSERT(record.getTransactionId().equals(prepareId), "getNextRecord return unqualified log rec for prepare");
            }
            logrecordseen++;
            if (record.isCLR()) {
                clrskipped++;
                // the loggable is still in the input stream, get rid of it
                record.skipLoggable();
                // read the prepareInstant
                long prepareInstant = rawInput.readLong();
                if (SanityManager.DEBUG) {
                    if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                        SanityManager.DEBUG(LogToFile.DBG_FLAG, "Skipping over CLRs, reset scan to " + LogCounter.toDebugString(prepareInstant));
                    }
                }
                scanLog.resetPosition(new LogCounter(prepareInstant));
                continue;
            }
            if (record.requiresPrepareLocks()) {
                lop = record.getRePreparable();
            } else {
                continue;
            }
            if (lop != null) {
                // Reget locks based on log record.  reclaim all locks with
                // a serializable locking policy, since we are only
                // reclaiming write locks, isolation level does not matter
                // much.
                lop.reclaimPrepareLocks(t, t.newLockingPolicy(LockingPolicy.MODE_RECORD, TransactionController.ISOLATION_REPEATABLE_READ, true));
                if (SanityManager.DEBUG) {
                    if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                        SanityManager.DEBUG(LogToFile.DBG_FLAG, "Reprepare log record at instant " + scanLog.getInstant() + " : " + lop);
                    }
                }
            }
        }
    } catch (ClassNotFoundException cnfe) {
        throw logFactory.markCorrupt(StandardException.newException(SQLState.LOG_CORRUPTED, cnfe));
    } catch (IOException ioe) {
        throw logFactory.markCorrupt(StandardException.newException(SQLState.LOG_READ_LOG_FOR_UNDO, ioe));
    } catch (StandardException se) {
        throw logFactory.markCorrupt(StandardException.newException(SQLState.LOG_UNDO_FAILED, se, prepareId, lop, (Object) null));
    } finally {
        if (rawInput != null) {
            try {
                rawInput.close();
            } catch (IOException ioe) {
                throw logFactory.markCorrupt(StandardException.newException(SQLState.LOG_READ_LOG_FOR_UNDO, ioe, prepareId));
            }
        }
    }
    if (SanityManager.DEBUG) {
        if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
            SanityManager.DEBUG(LogToFile.DBG_FLAG, "Finish prepare" + ", clr skipped = " + clrskipped + ", record seen = " + logrecordseen + "\n");
        }
    }
    if (SanityManager.DEBUG) {
        if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
            SanityManager.DEBUG(LogToFile.DBG_FLAG, "----------------------------------------------------\n" + "End of recovery rePrepare\n" + ", clr skipped = " + clrskipped + ", record seen = " + logrecordseen + "\n----------------------------------------------------\n");
        }
    }
}
Also used : StandardException(org.apache.derby.shared.common.error.StandardException) RePreparable(org.apache.derby.iapi.store.raw.RePreparable) LogRecord(org.apache.derby.impl.store.raw.log.LogRecord) ArrayInputStream(org.apache.derby.iapi.services.io.ArrayInputStream) LogCounter(org.apache.derby.impl.store.raw.log.LogCounter) IOException(java.io.IOException) StreamLogScan(org.apache.derby.impl.store.raw.log.StreamLogScan)

Example 5 with LogCounter

use of org.apache.derby.impl.store.raw.log.LogCounter in project derby by apache.

the class FileLogger method redo.

/**
 *		Recovery Redo loop.
 *
 *		<P> The log stream is scanned from the beginning (or
 *		from the undo low water mark of a checkpoint) forward until the end.
 *		The purpose of the redo pass is to repeat history, i.e, to repeat
 *		exactly the same set of changes the rawStore went thru right before it
 *		stopped.   With each log record that is encountered in the redo pass:
 *		<OL>
 *		<LI>if it isFirst(), then the transaction factory is called upon to
 *		    create a new transaction object.
 *		<LI>if it needsRedo(), its doMe() is called (if it is a compensation
 *		    operation, then the undoable operation needs to be created first
 *            before the doMe is called).
 *		<LI>if it isComplete(), then the transaction object is closed.
 *		</OL>
 *
 *		<P> MT - caller provides synchronization
 *
 *		@param transFactory     - the transaction factory
 *		@param redoLWM          - if checkpoint seen, starting from this point
 *                                  on, apply redo if necessary
 *
 *		@return the log instant of the next log record (or the instant just
 *		after the last log record).  This is used to determine where the log
 *		truly ends
 *
 *		@exception StandardException Standard Derby error policy
 *		@exception IOException error reading log file
 *		@exception ClassNotFoundException log file corrupted
 *
 *		@see LogToFile#recover
 */
protected long redo(RawTransaction recoveryTransaction, TransactionFactory transFactory, StreamLogScan redoScan, long redoLWM, long ttabInstant) throws IOException, StandardException, ClassNotFoundException {
    // begin debug info
    if (SanityManager.DEBUG) {
        if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
            SanityManager.DEBUG(LogToFile.DBG_FLAG, "In recovery redo, redoLWM = " + redoLWM);
        }
    }
    int scanCount = 0;
    int redoCount = 0;
    int prepareCount = 0;
    int clrCount = 0;
    int btranCount = 0;
    int etranCount = 0;
    // end debug info
    TransactionId tranId = null;
    // the current log instant
    long instant = LogCounter.INVALID_LOG_INSTANT;
    // ////////////////////////////////////////////////////////////////////
    // During redo time, the byte array in the logOutputBuffer is not used.
    // Use it to read the log record - if it is not big enough, scan
    // will resize it.  We could create a brand new log input stream that
    // has nothing to do with logIn or logOutputBuffer but that seem like
    // a waste of memory.
    // ////////////////////////////////////////////////////////////////////
    logIn.setData(logOutputBuffer.getByteArray());
    // use this scan to reconstitute operation to be undone
    // when we see a CLR in the redo scan
    StreamLogScan undoScan = null;
    Loggable op = null;
    // we need to determine the log's true end
    long logEnd = 0;
    try {
        // scan the log forward in redo pass and go to the end
        LogRecord record;
        while ((record = redoScan.getNextRecord(logIn, null, 0)) != null) {
            scanCount++;
            long undoInstant = 0;
            // last known good instant
            instant = redoScan.getInstant();
            // last known good log end
            logEnd = redoScan.getLogRecordEnd();
            // NOTE NOTE
            if (SanityManager.DEBUG) {
                if (SanityManager.DEBUG_ON(LogToFile.DUMP_LOG_ONLY) || SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                    if (SanityManager.DEBUG_ON(LogToFile.DUMP_LOG_ONLY))
                        SanityManager.DEBUG_SET(LogToFile.DBG_FLAG);
                    op = record.getLoggable();
                    tranId = record.getTransactionId();
                    if (record.isCLR()) {
                        // !!!!!!! this moves the file pointer
                        undoInstant = logIn.readLong();
                        SanityManager.DEBUG(LogToFile.DBG_FLAG, "scanned " + tranId + " : " + op + " instant = " + LogCounter.toDebugString(instant) + " undoInstant : " + LogCounter.toDebugString(undoInstant));
                    } else {
                        SanityManager.DEBUG(LogToFile.DBG_FLAG, "scanned " + tranId + " : " + op + " instant = " + LogCounter.toDebugString(instant) + " logEnd = " + LogCounter.toDebugString(logEnd) + " logIn at " + logIn.getPosition() + " available " + logIn.available());
                    }
                    // we only want to dump the log, don't touch it
                    if (SanityManager.DEBUG_ON(LogToFile.DUMP_LOG_ONLY))
                        continue;
                }
            }
            // already been flushed by checkpoint
            if (redoLWM != LogCounter.INVALID_LOG_INSTANT && instant < redoLWM) {
                if (!(record.isFirst() || record.isComplete() || record.isPrepare())) {
                    continue;
                }
            }
            // get the transaction
            tranId = record.getTransactionId();
            // otherwise, make it known to the transaction factory
            if (!transFactory.findTransaction(tranId, recoveryTransaction)) {
                if (redoLWM != LogCounter.INVALID_LOG_INSTANT && instant < redoLWM && (record.isPrepare() || record.isComplete())) {
                    // What is happening here is that a transaction that
                    // started before the undoLWM has commited by the time
                    // the checkpoint undoLWM was taken.  Hence, we only
                    // see the tail end of its log record and its endXact
                    // record.
                    // 
                    // NOTE:
                    // Since we didn't see its beginXact, we cannot do the
                    // endXact's doMe either.  Also if the endXact, is
                    // actually just a prepare, we don't need to do
                    // anything as the transaction will commit or abort
                    // prior to point we are recovering to.
                    // If it is deemed necessary to do the endXact's doMe,
                    // then we should start the transaction right here.
                    // For now, just completely ignore this transaction
                    // 
                    etranCount++;
                    continue;
                }
                if ((ttabInstant == LogCounter.INVALID_LOG_INSTANT) && !record.isFirst()) {
                    throw StandardException.newException(SQLState.LOG_UNEXPECTED_RECOVERY_PROBLEM, MessageService.getTextMessage(MessageId.LOG_RECORD_NOT_FIRST, tranId));
                }
                if (SanityManager.DEBUG) {
                    // instant, error.
                    if (ttabInstant != LogCounter.INVALID_LOG_INSTANT) {
                        if (instant > ttabInstant && !record.isFirst()) {
                            SanityManager.THROWASSERT("log record is Not first but transaction " + "is not in transaction table (2) : " + tranId);
                        }
                    // If we dump the transaction table and the table
                    // does not have the transaction, and we see this
                    // beginXact before the ttab instant, we could have
                    // igored it because we "know" that we should see
                    // the endXact before the ttab instant also.
                    // Leave it in just in case.
                    }
                }
                btranCount++;
                // the long transaction ID is embedded in the beginXact log
                // record.  The short ID is stored in the log record.
                recoveryTransaction.setTransactionId(record.getLoggable(), tranId);
            } else {
                if ((ttabInstant == LogCounter.INVALID_LOG_INSTANT) && record.isFirst()) {
                    throw StandardException.newException(SQLState.LOG_UNEXPECTED_RECOVERY_PROBLEM, MessageService.getTextMessage(MessageId.LOG_RECORD_FIRST, tranId));
                }
                if (SanityManager.DEBUG) {
                    if (ttabInstant != LogCounter.INVALID_LOG_INSTANT && instant > ttabInstant && record.isFirst()) {
                        SanityManager.THROWASSERT("log record is first but transaction is " + "already in transaction table (3): " + tranId);
                    }
                    if (record.isPrepare())
                        prepareCount++;
                }
                // 
                if (record.isFirst()) {
                    btranCount++;
                    continue;
                }
            }
            op = record.getLoggable();
            if (SanityManager.DEBUG) {
                if (!record.isCLR()) {
                    if (logIn.available() < 4) {
                        SanityManager.THROWASSERT("not enough bytes read in : " + logIn.available() + " for " + op + " instant " + LogCounter.toDebugString(instant));
                    }
                }
            }
            if (SanityManager.DEBUG) {
                SanityManager.ASSERT(!recoveryTransaction.handlesPostTerminationWork(), "recovery transaction handles post termination work");
            }
            if (op.needsRedo(recoveryTransaction)) {
                redoCount++;
                if (record.isCLR()) {
                    clrCount++;
                    if (SanityManager.DEBUG)
                        SanityManager.ASSERT(op instanceof Compensation);
                    // this value may be set by sanity xxxx
                    if (undoInstant == 0)
                        undoInstant = logIn.readLong();
                    if (undoScan == null) {
                        undoScan = (StreamLogScan) logFactory.openForwardsScan(undoInstant, (LogInstant) null);
                    } else {
                        undoScan.resetPosition(new LogCounter(undoInstant));
                    }
                    // undoScan now positioned at the beginning of the log
                    // record was rolled back by this CLR.
                    // The scan is a forward one so getNextRecord will get
                    // the log record that needs to be rolled back.
                    // reuse the buffer in logIn and logIn since CLR
                    // has no optional data and has no use for them anymore
                    logIn.clearLimit();
                    LogRecord undoRecord = undoScan.getNextRecord(logIn, null, 0);
                    Undoable undoOp = undoRecord.getUndoable();
                    if (SanityManager.DEBUG) {
                        SanityManager.DEBUG(LogToFile.DBG_FLAG, "Redoing CLR: undoInstant = " + LogCounter.toDebugString(undoInstant) + " clrinstant = " + LogCounter.toDebugString(instant));
                        SanityManager.ASSERT(undoRecord.getTransactionId().equals(tranId));
                        SanityManager.ASSERT(undoOp != null);
                    }
                    ((Compensation) op).setUndoOp(undoOp);
                }
                if (SanityManager.DEBUG) {
                    if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
                        SanityManager.DEBUG(LogToFile.DBG_FLAG, "redoing " + op + " instant = " + LogCounter.toDebugString(instant));
                    }
                }
                int dataLength = logIn.readInt();
                logIn.setLimit(dataLength);
                // even though the log has already been written, we need to
                // tie the page to the log stream so that if redo failed
                // for some reasons, the log factory's corruption will stop
                // the corrupt page from flushing to disk.
                op.doMe(recoveryTransaction, new LogCounter(instant), logIn);
                op.releaseResource(recoveryTransaction);
                op = null;
            }
            // has written any transaction, so in this case, it is a noop.
            if (record.isComplete()) {
                etranCount++;
                if (SanityManager.DEBUG)
                    SanityManager.ASSERT(!recoveryTransaction.handlesPostTerminationWork(), "recovery xact handles post termination work");
                recoveryTransaction.commit();
            }
        }
        // while redoScan.getNextRecord() != null
        // If the scan ended in an empty file, update logEnd to reflect that
        // in order to avoid to continue logging to an older file
        long end = redoScan.getLogRecordEnd();
        if (end != LogCounter.INVALID_LOG_INSTANT && (LogCounter.getLogFileNumber(logEnd) < LogCounter.getLogFileNumber(end))) {
            logEnd = end;
        }
    } catch (StandardException se) {
        throw StandardException.newException(SQLState.LOG_REDO_FAILED, se, op);
    } finally {
        // close all the io streams
        redoScan.close();
        redoScan = null;
        if (undoScan != null) {
            undoScan.close();
            undoScan = null;
        }
        if (op != null)
            op.releaseResource(recoveryTransaction);
    }
    if (SanityManager.DEBUG) {
        if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
            SanityManager.DEBUG(LogToFile.DBG_FLAG, "----------------------------------------------------\n" + "End of recovery redo\n" + "Scanned = " + scanCount + " log records" + ", redid = " + redoCount + " ( clr = " + clrCount + " )" + " begintran = " + btranCount + " endtran = " + etranCount + " preparetran = " + prepareCount + "\n log ends at " + LogCounter.toDebugString(logEnd) + "\n----------------------------------------------------\n");
        }
    }
    if (SanityManager.DEBUG) {
        // make sure logEnd and instant is consistent
        if (instant != LogCounter.INVALID_LOG_INSTANT) {
            SanityManager.ASSERT(LogCounter.getLogFileNumber(instant) < LogCounter.getLogFileNumber(logEnd) || (LogCounter.getLogFileNumber(instant) == LogCounter.getLogFileNumber(logEnd) && LogCounter.getLogFilePosition(instant) <= LogCounter.getLogFilePosition(logEnd)));
        } else {
            SanityManager.ASSERT(logEnd == LogCounter.INVALID_LOG_INSTANT);
        }
    }
    // logEnd is the last good log record position in the log
    return logEnd;
}
Also used : Undoable(org.apache.derby.iapi.store.raw.Undoable) StandardException(org.apache.derby.shared.common.error.StandardException) Loggable(org.apache.derby.iapi.store.raw.Loggable) LogRecord(org.apache.derby.impl.store.raw.log.LogRecord) Compensation(org.apache.derby.iapi.store.raw.Compensation) LogCounter(org.apache.derby.impl.store.raw.log.LogCounter) StreamLogScan(org.apache.derby.impl.store.raw.log.StreamLogScan) TransactionId(org.apache.derby.iapi.store.raw.xact.TransactionId)

Aggregations

LogCounter (org.apache.derby.impl.store.raw.log.LogCounter)6 StandardException (org.apache.derby.shared.common.error.StandardException)5 IOException (java.io.IOException)4 TransactionId (org.apache.derby.iapi.store.raw.xact.TransactionId)3 LogRecord (org.apache.derby.impl.store.raw.log.LogRecord)3 StreamLogScan (org.apache.derby.impl.store.raw.log.StreamLogScan)3 ArrayInputStream (org.apache.derby.iapi.services.io.ArrayInputStream)2 Compensation (org.apache.derby.iapi.store.raw.Compensation)2 Undoable (org.apache.derby.iapi.store.raw.Undoable)2 LogInstant (org.apache.derby.iapi.store.raw.log.LogInstant)2 Loggable (org.apache.derby.iapi.store.raw.Loggable)1 RePreparable (org.apache.derby.iapi.store.raw.RePreparable)1 ByteArray (org.apache.derby.iapi.util.ByteArray)1