0001: /*
0002:
0003: Derby - Class org.apache.derby.impl.store.raw.log.Scan
0004:
0005: Licensed to the Apache Software Foundation (ASF) under one or more
0006: contributor license agreements. See the NOTICE file distributed with
0007: this work for additional information regarding copyright ownership.
0008: The ASF licenses this file to you under the Apache License, Version 2.0
0009: (the "License"); you may not use this file except in compliance with
0010: the License. You may obtain a copy of the License at
0011:
0012: http://www.apache.org/licenses/LICENSE-2.0
0013:
0014: Unless required by applicable law or agreed to in writing, software
0015: distributed under the License is distributed on an "AS IS" BASIS,
0016: WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
0017: See the License for the specific language governing permissions and
0018: limitations under the License.
0019:
0020: */
0021:
0022: package org.apache.derby.impl.store.raw.log;
0023:
0024: import org.apache.derby.iapi.reference.SQLState;
0025:
0026: import org.apache.derby.iapi.services.io.ArrayInputStream;
0027:
0028: import org.apache.derby.iapi.services.sanity.SanityManager;
0029:
0030: import org.apache.derby.iapi.error.StandardException;
0031:
0032: import org.apache.derby.iapi.store.raw.log.LogInstant;
0033:
0034: import org.apache.derby.iapi.store.raw.xact.TransactionId;
0035:
0036: import org.apache.derby.impl.store.raw.log.LogCounter;
0037: import org.apache.derby.impl.store.raw.log.LogRecord;
0038: import org.apache.derby.impl.store.raw.log.StreamLogScan;
0039:
0040: import org.apache.derby.io.StorageRandomAccessFile;
0041:
0042: import java.io.IOException;
0043: import org.apache.derby.iapi.store.raw.Loggable;
0044:
0045: /**
0046:
0047: Scan the the log which is implemented by a series of log files.n
0048: This log scan knows how to move across log file if it is positioned at
0049: the boundary of a log file and needs to getNextRecord.
0050:
0051: <PRE>
0052: 4 bytes - length of user data, i.e. N
0053: 8 bytes - long representing log instant
0054: N bytes of supplied data
0055: 4 bytes - length of user data, i.e. N
0056: </PRE>
0057:
0058: */
0059:
0060: public class Scan implements StreamLogScan {
0061:
0062: // value for scanDirection
0063: public static final byte FORWARD = 1;
0064: public static final byte BACKWARD = 2;
0065: public static final byte BACKWARD_FROM_LOG_END = 4;
0066:
0067: private StorageRandomAccessFile scan; // an output stream to the log file
0068: private LogToFile logFactory; // log factory knows how to to skip
0069: // from log file to log file
0070:
0071: private long currentLogFileNumber; // the log file the scan is currently on
0072:
0073: private long currentLogFileLength; // the size of the current log file
0074: // used only for FORWARD scan to determine when
0075: // to switch the next log file
0076:
0077: private long knownGoodLogEnd; // For FORWARD scan only
0078: // during recovery, we need to determine the end
0079: // of the log. Everytime a complete log record
0080: // is read in, knownGoodLogEnd is set to the
0081: // log instant of the next log record if it is
0082: // on the same log file.
0083: //
0084: // only valid afer a successfull getNextRecord
0085: // on a FOWARD scan.
0086:
0087: private long currentInstant; // the log instant the scan is
0088: // currently on - only valid after a
0089: // successful getNextRecord
0090:
0091: private long stopAt; // scan until we find a log record whose
0092: // log instance < stopAt if we scan BACKWARD
0093: // log instance > stopAt if we scan FORWARD
0094: // log instance >= stopAt if we scan FORWARD_FLUSHED
0095:
0096: private byte scanDirection; // BACKWARD or FORWARD
0097:
0098: private boolean fuzzyLogEnd = false; //get sets to true during forward scan
0099:
0100: //for recovery, if there were
0101: //partial writes at the end of the log before crash;
0102: //during forward scan for recovery.
0103:
0104: /**
0105: For backward scan, we expect a scan positioned at the end of the next log record.
0106: For forward scan, we expect a scan positioned at the beginning of the next log record.
0107:
0108: For forward flushed scan, we expect stopAt to be the instant for the
0109: first not-flushed log record. Like any forward scan, we expect a scan
0110: positioned at the beginning of the next log record.
0111:
0112: @exception StandardException Standard Cloudscape error policy
0113: @exception IOException cannot access the log at the new position.
0114: */
0115: public Scan(LogToFile logFactory, long startAt, LogInstant stopAt,
0116: byte direction) throws IOException, StandardException {
0117: if (SanityManager.DEBUG)
0118: SanityManager.ASSERT(
0119: startAt != LogCounter.INVALID_LOG_INSTANT,
0120: "cannot start scan on an invalid log instant");
0121:
0122: this .logFactory = logFactory;
0123: currentLogFileNumber = LogCounter.getLogFileNumber(startAt);
0124: currentLogFileLength = -1;
0125: knownGoodLogEnd = LogCounter.INVALID_LOG_INSTANT;// set at getNextRecord for FORWARD scan
0126: currentInstant = LogCounter.INVALID_LOG_INSTANT; // set at getNextRecord
0127: if (stopAt != null)
0128: this .stopAt = ((LogCounter) stopAt).getValueAsLong();
0129: else
0130: this .stopAt = LogCounter.INVALID_LOG_INSTANT;
0131:
0132: switch (direction) {
0133: case FORWARD:
0134: scan = logFactory.getLogFileAtPosition(startAt);
0135: scanDirection = FORWARD;
0136:
0137: if (SanityManager.DEBUG)
0138: if (scan == null)
0139: SanityManager.THROWASSERT("scan null at "
0140: + LogCounter.toDebugString(startAt));
0141:
0142: // NOTE: just get the length of the file without syncing.
0143: // this only works because the only place forward scan is used
0144: // right now is on recovery redo and nothing is being added to
0145: // the current log file. When the forward scan is used for some
0146: // other purpose, need to sync access to the end of the log
0147: currentLogFileLength = scan.length();
0148: break;
0149:
0150: case BACKWARD:
0151: // startAt is at the front of the log record, for backward
0152: // scan we need to be positioned at the end of the log record
0153: scan = logFactory.getLogFileAtPosition(startAt);
0154: int logsize = scan.readInt();
0155:
0156: // skip forward over the log record and all the overhead, but remember
0157: // we just read an int off the overhead
0158: scan.seek(scan.getFilePointer() + logsize
0159: + LogToFile.LOG_RECORD_OVERHEAD - 4);
0160: scanDirection = BACKWARD;
0161: break;
0162:
0163: case BACKWARD_FROM_LOG_END:
0164: // startAt is at the end of the log, no need to skip the log record
0165: scan = logFactory.getLogFileAtPosition(startAt);
0166: scanDirection = BACKWARD;
0167: break;
0168:
0169: }
0170: }
0171:
0172: /*
0173: ** Methods of StreamLogScan
0174: */
0175:
0176: /**
0177: Read the next log record.
0178: Switching log to a previous log file if necessary,
0179: Resize the input stream byte array if necessary.
0180: @see StreamLogScan#getNextRecord
0181:
0182: @return the next LogRecord, or null if the end of the
0183: scan has been reached.
0184:
0185: @exception StandardException Standard Cloudscape error policy
0186: */
0187: public LogRecord getNextRecord(ArrayInputStream input,
0188: TransactionId tranId, int groupmask)
0189: throws StandardException {
0190: if (scan == null)
0191: return null;
0192:
0193: if (SanityManager.DEBUG)
0194: SanityManager.ASSERT(scanDirection != 0,
0195: "scan has been secretly closed!");
0196:
0197: LogRecord lr = null;
0198: try {
0199: if (scanDirection == BACKWARD)
0200: lr = getNextRecordBackward(input, tranId, groupmask);
0201: else if (scanDirection == FORWARD)
0202: lr = getNextRecordForward(input, tranId, groupmask);
0203:
0204: return lr;
0205:
0206: } catch (IOException ioe) {
0207: if (SanityManager.DEBUG)
0208: ioe.printStackTrace();
0209:
0210: throw logFactory.markCorrupt(StandardException
0211: .newException(SQLState.LOG_CORRUPTED, ioe));
0212: } catch (ClassNotFoundException cnfe) {
0213: if (SanityManager.DEBUG)
0214: cnfe.printStackTrace();
0215:
0216: throw logFactory.markCorrupt(StandardException
0217: .newException(SQLState.LOG_CORRUPTED, cnfe));
0218: } finally {
0219: if (lr == null)
0220: close(); // no more log record, close the scan
0221: }
0222:
0223: }
0224:
0225: /**
0226: Read the previous log record.
0227: Switching log to a previous log file if necessary,
0228: Resize the input stream byte array if necessary.
0229: @see StreamLogScan#getNextRecord
0230:
0231: Side effects include:
0232: on a successful read, setting currentInstant.
0233: on a log file switch, setting currentLogFileNumber.
0234:
0235: @return the previous LogRecord, or null if the end of the
0236: scan has been reached.
0237: */
0238: private LogRecord getNextRecordBackward(ArrayInputStream input,
0239: TransactionId tranId, int groupmask)
0240: throws StandardException, IOException,
0241: ClassNotFoundException {
0242: if (SanityManager.DEBUG)
0243: SanityManager.ASSERT(scanDirection == BACKWARD,
0244: "can only called by backward scan");
0245:
0246: // scan is positioned just past the last byte of the record, or
0247: // right at the beginning of the file (end of the file header)
0248: // may need to switch log file
0249:
0250: boolean candidate;
0251: // if we have filtering, peek at the group and/or the transaction id,
0252: // do them in one read rather than 2 reads.
0253: int peekAmount = LogRecord.formatOverhead()
0254: + LogRecord.maxGroupStoredSize();
0255: if (tranId != null)
0256: peekAmount += LogRecord.maxTransactionIdStoredSize(tranId);
0257:
0258: int readAmount; // the number of bytes actually read
0259:
0260: LogRecord lr;
0261: long curpos = scan.getFilePointer();
0262:
0263: do {
0264: // this log record is a candidate unless proven otherwise
0265: candidate = true;
0266: lr = null;
0267: readAmount = -1;
0268:
0269: if (curpos == LogToFile.LOG_FILE_HEADER_SIZE) {
0270: // don't go thru the trouble of switching log file if we
0271: // will have gone past stopAt
0272: if (stopAt != LogCounter.INVALID_LOG_INSTANT
0273: && LogCounter.getLogFileNumber(stopAt) == currentLogFileNumber) {
0274: if (SanityManager.DEBUG) {
0275: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
0276: SanityManager.DEBUG(LogToFile.DBG_FLAG,
0277: "stopping at "
0278: + currentLogFileNumber);
0279: }
0280: }
0281:
0282: return null; // no more log record
0283: }
0284:
0285: // figure out where the last log record is in the previous
0286: // log file
0287: scan
0288: .seek(LogToFile.LOG_FILE_HEADER_PREVIOUS_LOG_INSTANT_OFFSET);
0289: long previousLogInstant = scan.readLong();
0290: scan.close();
0291:
0292: if (SanityManager.DEBUG) {
0293: SanityManager
0294: .ASSERT(
0295: previousLogInstant != LogCounter.INVALID_LOG_INSTANT,
0296: "scanning backward beyond the first log file");
0297: if (currentLogFileNumber != LogCounter
0298: .getLogFileNumber(previousLogInstant) + 1)
0299: SanityManager
0300: .THROWASSERT("scanning backward but get incorrect log file number "
0301: + "expected "
0302: + (currentLogFileNumber - 1)
0303: + "get "
0304: + LogCounter
0305: .getLogFileNumber(previousLogInstant));
0306:
0307: SanityManager
0308: .ASSERT(
0309: LogCounter
0310: .getLogFilePosition(previousLogInstant) > LogToFile.LOG_FILE_HEADER_SIZE,
0311: "scanning backward encounter completely empty log file");
0312:
0313: SanityManager
0314: .DEBUG(
0315: LogToFile.DBG_FLAG,
0316: "scanning backwards from log file "
0317: + currentLogFileNumber
0318: + ", switch to ("
0319: + LogCounter
0320: .getLogFileNumber(previousLogInstant)
0321: + ","
0322: + LogCounter
0323: .getLogFilePosition(previousLogInstant)
0324: + ")");
0325: }
0326:
0327: // log file switch, set this.currentLogFileNumber
0328: currentLogFileNumber = LogCounter
0329: .getLogFileNumber(previousLogInstant);
0330:
0331: scan = logFactory
0332: .getLogFileAtPosition(previousLogInstant);
0333:
0334: // scan is located right past the last byte of the last log
0335: // record in the previous log file. currentLogFileNumber is
0336: // set. We asserted that the scan is not located right at the
0337: // end of the file header, in other words, there is at least
0338: // one log record in this log file.
0339: curpos = scan.getFilePointer();
0340:
0341: // if the log file happens to be empty skip and proceed.
0342: // ideally this case should never occur because log switch is
0343: // not suppose to happen on an empty log file.
0344: // But it is safer to put following check incase if it ever
0345: // happens to avoid any recovery issues.
0346: if (curpos == LogToFile.LOG_FILE_HEADER_SIZE)
0347: continue;
0348: }
0349:
0350: scan.seek(curpos - 4);
0351: int recordLength = scan.readInt(); // get the length after the log record
0352:
0353: // calculate where this log record started.
0354: // include the eight bytes for the long log instant at the front
0355: // the four bytes of length in the front and the four bytes we just read
0356: long recordStartPosition = curpos - recordLength
0357: - LogToFile.LOG_RECORD_OVERHEAD;
0358:
0359: if (SanityManager.DEBUG) {
0360: if (recordStartPosition < LogToFile.LOG_FILE_HEADER_SIZE)
0361: SanityManager.THROWASSERT("next position "
0362: + recordStartPosition + " recordLength "
0363: + recordLength + " current file position "
0364: + scan.getFilePointer());
0365:
0366: scan.seek(recordStartPosition);
0367:
0368: // read the length before the log record and check it against the
0369: // length after the log record
0370: int checkLength = scan.readInt();
0371:
0372: if (checkLength != recordLength) {
0373: long inst = LogCounter.makeLogInstantAsLong(
0374: currentLogFileNumber, recordStartPosition);
0375:
0376: throw logFactory.markCorrupt(StandardException
0377: .newException(
0378: SQLState.LOG_RECORD_CORRUPTED,
0379: new Long(checkLength), new Long(
0380: recordLength), new Long(
0381: inst), new Long(
0382: currentLogFileNumber)));
0383: }
0384: } else {
0385: // skip over the length in insane
0386: scan.seek(recordStartPosition + 4);
0387: }
0388:
0389: // scan is positioned just before the log instant
0390: // read the current log instant - this is the currentInstant if we have not
0391: // exceeded the scan limit
0392: currentInstant = scan.readLong();
0393:
0394: if (SanityManager.DEBUG) {
0395: // sanity check the current instant against the scan position
0396: if (LogCounter.getLogFileNumber(currentInstant) != currentLogFileNumber
0397: || LogCounter
0398: .getLogFilePosition(currentInstant) != recordStartPosition)
0399: SanityManager
0400: .THROWASSERT("Wrong LogInstant on log record "
0401: + LogCounter
0402: .toDebugString(currentInstant)
0403: + " version real position ("
0404: + currentLogFileNumber
0405: + ","
0406: + recordStartPosition + ")");
0407: }
0408:
0409: // if stopAt == INVALID_LOG_INSTANT, no stop instant, read till
0410: // nothing more can be read. Else check scan limit
0411: if (currentInstant < stopAt
0412: && stopAt != LogCounter.INVALID_LOG_INSTANT) {
0413: currentInstant = LogCounter.INVALID_LOG_INSTANT;
0414: return null; // we went past the stopAt
0415: }
0416:
0417: byte[] data = input.getData();
0418:
0419: if (data.length < recordLength) {
0420: // make a new array of sufficient size and reset the arrary
0421: // in the input stream
0422: data = new byte[recordLength];
0423: input.setData(data);
0424: }
0425:
0426: // If the log is encrypted, we must do the filtering after reading
0427: // and decrypting the record.
0428: if (logFactory.databaseEncrypted()) {
0429: scan.readFully(data, 0, recordLength);
0430: int len = logFactory.decrypt(data, 0, recordLength,
0431: data, 0);
0432: if (SanityManager.DEBUG)
0433: SanityManager.ASSERT(len == recordLength);
0434: input.setLimit(0, recordLength);
0435: } else // no need to decrypt, only get the group and tid if we filter
0436: {
0437: if (groupmask == 0 && tranId == null) {
0438: // no filter, get the whole thing
0439: scan.readFully(data, 0, recordLength);
0440: input.setLimit(0, recordLength);
0441: } else {
0442: // Read only enough so that group and the tran id is in
0443: // the data buffer. Group is stored as compressed int
0444: // and tran id is stored as who knows what. read min
0445: // of peekAmount or recordLength
0446: readAmount = (recordLength > peekAmount) ? peekAmount
0447: : recordLength;
0448:
0449: // in the data buffer, we now have enough to peek
0450: scan.readFully(data, 0, readAmount);
0451: input.setLimit(0, readAmount);
0452: }
0453: }
0454:
0455: lr = (LogRecord) input.readObject();
0456:
0457: // skip the checksum log records, there is no need to look at them
0458: // during backward scans. They are used only in forwardscan during recovery.
0459: if (lr.isChecksum()) {
0460: candidate = false;
0461: } else if (groupmask != 0 || tranId != null) {
0462:
0463: // skip the checksum log records
0464: if (lr.isChecksum())
0465: candidate = false;
0466:
0467: if (candidate && groupmask != 0
0468: && (groupmask & lr.group()) == 0)
0469: candidate = false; // no match, throw this log record out
0470:
0471: if (candidate && tranId != null) {
0472: TransactionId tid = lr.getTransactionId();
0473: if (!tid.equals(tranId)) // nomatch
0474: candidate = false; // throw this log record out
0475: }
0476:
0477: // if this log record is not filtered out, we need to read
0478: // in the rest of the log record to the input buffer.
0479: // Except if it is an encrypted database, in which case the
0480: // entire log record have already be read in for
0481: // decryption.
0482: if (candidate && !logFactory.databaseEncrypted()) {
0483: // read the rest of the log into the buffer
0484: if (SanityManager.DEBUG)
0485: SanityManager.ASSERT(readAmount > 0);
0486:
0487: if (readAmount < recordLength) {
0488: // Need to remember where we are because the log
0489: // record may have read part of it off the input
0490: // stream already and that position is lost when we
0491: // set limit again.
0492: int inputPosition = input.getPosition();
0493:
0494: scan.readFully(data, readAmount, recordLength
0495: - readAmount);
0496:
0497: input.setLimit(0, recordLength);
0498: input.setPosition(inputPosition);
0499: }
0500: }
0501: }
0502:
0503: // go back to the start of the log record so that the next time
0504: // this method is called, it is positioned right past the last byte
0505: // of the record.
0506: curpos = recordStartPosition;
0507: scan.seek(curpos);
0508:
0509: } while (candidate == false);
0510:
0511: return lr;
0512:
0513: }
0514:
0515: /**
0516: Read the next log record.
0517: Switching log to a previous log file if necessary,
0518: Resize the input stream byte array if necessary.
0519: @see StreamLogScan#getNextRecord
0520:
0521: Side effects include:
0522: on a successful read, setting currentInstant, knownGoodLogEnd
0523: on a log file switch, setting currentLogFileNumber, currentLogFileLength.
0524: on detecting a fuzzy log end that needs clearing, it will call
0525: logFactory to clear the fuzzy log end.
0526:
0527: @return the next LogRecord, or null if the end of the
0528: scan has been reached.
0529: */
0530: private LogRecord getNextRecordForward(ArrayInputStream input,
0531: TransactionId tranId, int groupmask)
0532: throws StandardException, IOException,
0533: ClassNotFoundException {
0534: if (SanityManager.DEBUG)
0535: SanityManager.ASSERT(scanDirection == FORWARD,
0536: "can only called by forward scan");
0537:
0538: // NOTE:
0539: //
0540: // if forward scan, scan is positioned at the first byte of the
0541: // next record, or the end of file - note the the 'end of file'
0542: // is defined at the time the scan is initialized. If we are
0543: // on the current log file, it may well have grown by now...
0544: //
0545: // This is not a problem in reality because the only forward
0546: // scan on the log now is recovery redo and the log does not
0547: // grow. If in the future, a foward scan of the log is used
0548: // for some other reasons, need to keep this in mind.
0549: //
0550:
0551: // first we need to make sure the entire log record is on the
0552: // log, or else this is a fuzzy log end.
0553:
0554: // RESOLVE: can get this from knownGoodLogEnd if this is not the first
0555: // time getNext is called. Probably just as fast to call
0556: // scan.getFilePointer though...
0557: long recordStartPosition = scan.getFilePointer();
0558:
0559: boolean candidate;
0560:
0561: // if we have filtering, peek at the group and/or the transaction id,
0562: // do them in one read rather than 2 reads.
0563: int peekAmount = LogRecord.formatOverhead()
0564: + LogRecord.maxGroupStoredSize();
0565: if (tranId != null)
0566: peekAmount += LogRecord.maxTransactionIdStoredSize(tranId);
0567:
0568: int readAmount; // the number of bytes actually read
0569:
0570: LogRecord lr;
0571:
0572: do {
0573: // this log record is a candidate unless proven otherwise
0574: candidate = true;
0575: lr = null;
0576: readAmount = -1;
0577:
0578: // if we are not right at the end but this position + 4 is at
0579: // or exceeds the end, we know we don't have a complete log
0580: // record. This is the log file and chalk it up as the fuzzy
0581: // end.
0582: if (recordStartPosition + 4 > currentLogFileLength) {
0583: // since there is no end of log file marker, we are at the
0584: // end of the log.
0585: if (SanityManager.DEBUG) {
0586: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
0587: SanityManager.DEBUG(LogToFile.DBG_FLAG,
0588: "detected fuzzy log end on log file "
0589: + currentLogFileNumber
0590: + " record start position "
0591: + recordStartPosition
0592: + " file length "
0593: + currentLogFileLength);
0594: }
0595: }
0596:
0597: //if recordStartPosition == currentLogFileLength
0598: //there is NO fuzz, it just a properly ended log
0599: //without the end marker.
0600: if (recordStartPosition != currentLogFileLength)
0601: fuzzyLogEnd = true;
0602:
0603: // don't bother to write the end of log file marker because
0604: // if it is not overwritten by the next log record then
0605: // the next time the database is recovered it will come
0606: // back right here
0607: return null;
0608: }
0609:
0610: // read in the length before the log record
0611: int recordLength = scan.readInt();
0612:
0613: while (recordLength == 0
0614: || recordStartPosition + recordLength
0615: + LogToFile.LOG_RECORD_OVERHEAD > currentLogFileLength) {
0616: // if recordLength is zero or the log record goes beyond the
0617: // current file, then we have detected the end of a log file.
0618: //
0619: // If recordLength == 0 then we know that this log file has either
0620: // been properly switched or it had a 1/2 written log record which
0621: // was subsequently cleared by clearFuzzyEnd.
0622: //
0623: // If recordLength != 0 but log record goes beyond the current log
0624: // file, we have detected a fuzzy end. This is the last log file
0625: // since we will clear it by clearFuzzyEnd.
0626:
0627: if (recordLength != 0) // this is a fuzzy log end
0628: {
0629: if (SanityManager.DEBUG) {
0630: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
0631: SanityManager.DEBUG(LogToFile.DBG_FLAG,
0632: "detected fuzzy log end on log file "
0633: + currentLogFileNumber
0634: + " record start position "
0635: + recordStartPosition
0636: + " file length "
0637: + currentLogFileLength
0638: + " recordLength="
0639: + recordLength);
0640: }
0641: }
0642:
0643: fuzzyLogEnd = true;
0644: scan.close();
0645: scan = null;
0646:
0647: return null;
0648: }
0649:
0650: // recordLength == 0
0651:
0652: if (SanityManager.DEBUG) {
0653: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
0654: if (recordStartPosition + 4 == currentLogFileLength) {
0655: SanityManager.DEBUG(LogToFile.DBG_FLAG,
0656: "detected proper log end on log file "
0657: + currentLogFileNumber);
0658: } else {
0659: SanityManager.DEBUG(LogToFile.DBG_FLAG,
0660: "detected zapped log end on log file "
0661: + currentLogFileNumber
0662: + " end marker at "
0663: + recordStartPosition
0664: + " real end at "
0665: + currentLogFileLength);
0666: }
0667: }
0668: }
0669:
0670: // don't go thru the trouble of switching log file if we
0671: // have will have gone past stopAt if we want to stop here
0672: if (stopAt != LogCounter.INVALID_LOG_INSTANT
0673: && LogCounter.getLogFileNumber(stopAt) == currentLogFileNumber) {
0674: return null;
0675: }
0676:
0677: //
0678: // we have a log end marker and we don't want to stop yet, switch
0679: // log file
0680: //
0681: scan.close();
0682:
0683: // set this.currentLogFileNumber
0684: scan = logFactory
0685: .getLogFileAtBeginning(++currentLogFileNumber);
0686: if (scan == null) // we have seen the last log file
0687: {
0688: return null;
0689: }
0690:
0691: // scan is position just past the log header
0692: recordStartPosition = scan.getFilePointer();
0693:
0694: // Verify that the header of the new log file refers
0695: // to the end of the log record of the previous file
0696: // (Rest of header has been verified by getLogFileAtBeginning)
0697: scan
0698: .seek(LogToFile.LOG_FILE_HEADER_PREVIOUS_LOG_INSTANT_OFFSET);
0699: long previousLogInstant = scan.readLong();
0700: if (previousLogInstant != knownGoodLogEnd) {
0701: // If there is a mismatch, something is wrong and
0702: // we return null to stop the scan. The same
0703: // behavior occurs when getLogFileAtBeginning
0704: // detects an error in the other fields of the header.
0705: if (SanityManager.DEBUG) {
0706: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
0707: SanityManager
0708: .DEBUG(
0709: LogToFile.DBG_FLAG,
0710: "log file "
0711: + currentLogFileNumber
0712: + ": previous log record: "
0713: + previousLogInstant
0714: + " known previous log record: "
0715: + knownGoodLogEnd);
0716: }
0717: }
0718: return null;
0719: }
0720:
0721: scan.seek(recordStartPosition);
0722:
0723: if (SanityManager.DEBUG) {
0724: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
0725: SanityManager.DEBUG(LogToFile.DBG_FLAG,
0726: "switched to next log file "
0727: + currentLogFileNumber);
0728: }
0729: }
0730:
0731: // Advance knownGoodLogEnd to make sure that if this
0732: // log file is the last log file and empty, logging
0733: // continues in this file, not the old file.
0734: knownGoodLogEnd = LogCounter.makeLogInstantAsLong(
0735: currentLogFileNumber, recordStartPosition);
0736:
0737: // set this.currentLogFileLength
0738: currentLogFileLength = scan.length();
0739:
0740: if (recordStartPosition + 4 >= currentLogFileLength) // empty log file
0741: {
0742: if (SanityManager.DEBUG) {
0743: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
0744: SanityManager.DEBUG(LogToFile.DBG_FLAG,
0745: "log file " + currentLogFileNumber
0746: + " is empty");
0747: }
0748: }
0749:
0750: return null;
0751: }
0752:
0753: // we have successfully switched to the next log file.
0754: // scan is positioned just before the next log record
0755: // see if this one is written in entirety
0756: recordLength = scan.readInt();
0757: }
0758:
0759: // we know the entire log record is on this log file
0760:
0761: // read the current log instant
0762: currentInstant = scan.readLong();
0763:
0764: /*check if the current instant happens is less than the last one.
0765: *This can happen if system crashed before writing the log instant
0766: *completely. If the instant is partially written it will be less
0767: *than the last one and should be the last record that was suppose to
0768: *get written. Currentlt preallocated files are filled with zeros,
0769: *this should hold good.
0770: *Note: In case of Non-preallocated files earlier check with log
0771: * file lengths should have found the end. But in prellocated files, log file
0772: *length is not sufficiant to find the log end. This check
0773: *is must to find the end in preallocated log files.
0774: */
0775: if (currentInstant < knownGoodLogEnd) {
0776: fuzzyLogEnd = true;
0777: return null;
0778: }
0779:
0780: // sanity check it
0781: if (SanityManager.DEBUG) {
0782: if (LogCounter.getLogFileNumber(currentInstant) != currentLogFileNumber
0783: || LogCounter
0784: .getLogFilePosition(currentInstant) != recordStartPosition)
0785: SanityManager
0786: .THROWASSERT("Wrong LogInstant on log record "
0787: + LogCounter
0788: .toDebugString(currentInstant)
0789: + " version real position ("
0790: + currentLogFileNumber
0791: + ","
0792: + recordStartPosition + ")");
0793: }
0794:
0795: // if stopAt == INVALID_LOG_INSTANT, no stop instant, read till
0796: // nothing more can be read. Else check scan limit
0797: if (stopAt != LogCounter.INVALID_LOG_INSTANT
0798: && currentInstant > stopAt) {
0799: currentInstant = LogCounter.INVALID_LOG_INSTANT;
0800: return null; // we went past the stopAt
0801: }
0802:
0803: // read in the log record
0804: byte[] data = input.getData();
0805:
0806: if (data.length < recordLength) {
0807: // make a new array of sufficient size and reset the arrary
0808: // in the input stream
0809: data = new byte[recordLength];
0810: input.setData(data);
0811: }
0812:
0813: // If the log is encrypted, we must do the filtering after
0814: // reading and decryptiong the record.
0815:
0816: if (logFactory.databaseEncrypted()) {
0817: scan.readFully(data, 0, recordLength);
0818: int len = logFactory.decrypt(data, 0, recordLength,
0819: data, 0);
0820: if (SanityManager.DEBUG)
0821: SanityManager.ASSERT(len == recordLength);
0822:
0823: input.setLimit(0, len);
0824: } else // no need to decrypt, only get the group and tid if we filter
0825: {
0826: if (groupmask == 0 && tranId == null) {
0827: // no filter, get the whole thing
0828: scan.readFully(data, 0, recordLength);
0829: input.setLimit(0, recordLength);
0830: } else {
0831: // Read only enough so that group and the tran id is in
0832: // the data buffer. Group is stored as compressed int
0833: // and tran id is stored as who knows what. read min
0834: // of peekAmount or recordLength
0835: readAmount = (recordLength > peekAmount) ? peekAmount
0836: : recordLength;
0837:
0838: // in the data buffer, we now have enough to peek
0839: scan.readFully(data, 0, readAmount);
0840: input.setLimit(0, readAmount);
0841: }
0842: }
0843:
0844: lr = (LogRecord) input.readObject();
0845: if (groupmask != 0 || tranId != null) {
0846: if (groupmask != 0 && (groupmask & lr.group()) == 0)
0847: candidate = false; // no match, throw this log record out
0848:
0849: if (candidate && tranId != null) {
0850: TransactionId tid = lr.getTransactionId();
0851: if (!tid.equals(tranId)) // nomatch
0852: candidate = false; // throw this log record out
0853: }
0854:
0855: // if this log record is not filtered out, we need to read
0856: // in the rest of the log record to the input buffer.
0857: // Except if it is an encrypted database, in which case the
0858: // entire log record have already be read in for
0859: // decryption.
0860: if (candidate && !logFactory.databaseEncrypted()) {
0861: // read the rest of the log into the buffer
0862: if (SanityManager.DEBUG)
0863: SanityManager.ASSERT(readAmount > 0);
0864:
0865: if (readAmount < recordLength) {
0866: // Need to remember where we are because the log
0867: // record may have read part of it off the input
0868: // stream already and that position is lost when we
0869: // set limit again.
0870: int inputPosition = input.getPosition();
0871:
0872: scan.readFully(data, readAmount, recordLength
0873: - readAmount);
0874:
0875: input.setLimit(0, recordLength);
0876: input.setPosition(inputPosition);
0877: }
0878: }
0879: }
0880:
0881: /*check if the logrecord length written before and after the
0882: *log record are equal, if not the end of of the log is reached.
0883: *This can happen if system crashed before writing the length field
0884: *in the end of the records completely. If the length is partially
0885: *written or not written at all it will not match with length written
0886: *in the beginning of the log record. Currentlt preallocated files
0887: *are filled with zeros, log record length can never be zero;
0888: *if the lengths are not matching, end of the properly written log
0889: *is reached.
0890: *Note: In case of Non-preallocated files earlier fuzzy case check with log
0891: * file lengths should have found the end. But in prellocated files, log file
0892: *length is not sufficiant to find the log end. This check
0893: *is must to find the end in preallocated log files.
0894: */
0895: // read the length after the log record and check it against the
0896: // length before the log record, make sure we go to the correct
0897: // place for skipped log record.
0898: if (!candidate)
0899: scan.seek(recordStartPosition - 4);
0900: int checkLength = scan.readInt();
0901: if (checkLength != recordLength
0902: && checkLength < recordLength) {
0903:
0904: //lengh written in the end of the log record should be always
0905: //less then the length written in the beginning if the log
0906: //record was half written before the crash.
0907: if (checkLength < recordLength) {
0908: fuzzyLogEnd = true;
0909: return null;
0910: } else {
0911:
0912: //If checklength > recordLength then it can be not be a partial write
0913: //probablly it is corrupted for some reason , this should never
0914: //happen throw error in debug mode. In non debug case , let's
0915: //hope it's only is wrong and system can proceed.
0916:
0917: if (SanityManager.DEBUG) {
0918: throw logFactory
0919: .markCorrupt(StandardException
0920: .newException(
0921: SQLState.LOG_RECORD_CORRUPTED,
0922: new Long(checkLength),
0923: new Long(recordLength),
0924: new Long(currentInstant),
0925: new Long(
0926: currentLogFileNumber)));
0927:
0928: }
0929:
0930: //In non debug case, do nothing , let's hope it's only
0931: //length part that is incorrect and system can proceed.
0932: }
0933:
0934: }
0935:
0936: // next record start position is right after this record
0937: recordStartPosition += recordLength
0938: + LogToFile.LOG_RECORD_OVERHEAD;
0939: knownGoodLogEnd = LogCounter.makeLogInstantAsLong(
0940: currentLogFileNumber, recordStartPosition);
0941:
0942: if (SanityManager.DEBUG) {
0943: if (recordStartPosition != scan.getFilePointer())
0944: SanityManager.THROWASSERT("calculated end "
0945: + recordStartPosition + " != real end "
0946: + scan.getFilePointer());
0947: } else {
0948: // seek to the start of the next log record
0949: scan.seek(recordStartPosition);
0950: }
0951:
0952: // the scan is now positioned just past this log record and right
0953: // at the beginning of the next log record
0954:
0955: /** if the current log record is a checksum log record then
0956: * using the information available in this record validate
0957: * that data in the log file by matching the checksum in
0958: * checksum log record and by recalculating the checksum for the
0959: * specified length of the data in the log file. cheksum values
0960: * should match unless the right was incomplete before the crash.
0961: */
0962: if (lr.isChecksum()) {
0963: // checksum log record should not be returned to the logger recovery redo
0964: // routines, it is just used to identify the incomplete log writes.
0965:
0966: candidate = false;
0967: Loggable op = lr.getLoggable();
0968: if (SanityManager.DEBUG) {
0969: if (SanityManager.DEBUG_ON(LogToFile.DUMP_LOG_ONLY)
0970: || SanityManager
0971: .DEBUG_ON(LogToFile.DBG_FLAG))
0972:
0973: SanityManager
0974: .DEBUG(
0975: LogToFile.DBG_FLAG,
0976: "scanned "
0977: + "Null"
0978: + " : "
0979: + op
0980: + " instant = "
0981: + LogCounter
0982: .toDebugString(currentInstant)
0983: + " logEnd = "
0984: + LogCounter
0985: .toDebugString(knownGoodLogEnd));
0986: }
0987:
0988: ChecksumOperation clop = (ChecksumOperation) op;
0989: int ckDataLength = clop.getDataLength();
0990: // resize the buffer to be size of checksum data length if required.
0991: if (data.length < ckDataLength) {
0992: // make a new array of sufficient size and reset the arrary
0993: // in the input stream
0994: data = new byte[ckDataLength];
0995: input.setData(data);
0996: input.setLimit(0, ckDataLength);
0997: }
0998:
0999: boolean validChecksum = false;
1000: // check if the expected number of bytes by the checksum log
1001: // record actually exist in the file and then verify if checksum
1002: // is valid to identify any incomplete out of order writes.
1003: if ((recordStartPosition + ckDataLength) <= currentLogFileLength) {
1004: // read the data into the buffer
1005: scan.readFully(data, 0, ckDataLength);
1006: // verify the checksum
1007: if (clop.isChecksumValid(data, 0, ckDataLength))
1008: validChecksum = true;
1009: }
1010:
1011: if (!validChecksum) {
1012: // declare that the end of the transaction log is fuzzy, checksum is invalid
1013: // only when the writes are incomplete; this can happen
1014: // only when writes at the end of the log were partially
1015: // written before the crash.
1016:
1017: if (SanityManager.DEBUG) {
1018: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
1019: SanityManager
1020: .DEBUG(
1021: LogToFile.DBG_FLAG,
1022: "detected fuzzy log end on log file while doing checksum checks "
1023: + currentLogFileNumber
1024: + " checksum record start position "
1025: + recordStartPosition
1026: + " file length "
1027: + currentLogFileLength
1028: + " checksumDataLength="
1029: + ckDataLength);
1030: }
1031:
1032: }
1033:
1034: fuzzyLogEnd = true;
1035: scan.close();
1036: scan = null;
1037: return null;
1038: }
1039:
1040: // reset the scan to the start of the next log record
1041: scan.seek(recordStartPosition);
1042: }
1043:
1044: } while (candidate == false);
1045:
1046: return lr;
1047: }
1048:
1049: /**
1050: Reset the scan to the given LogInstant.
1051:
1052: @param instant the position to reset to
1053: @exception IOException scan cannot access the log at the new position.
1054: @exception StandardException cloudscape standard error policy
1055: */
1056:
1057: public void resetPosition(LogInstant instant) throws IOException,
1058: StandardException {
1059: if (SanityManager.DEBUG)
1060: SanityManager.ASSERT(instant != null);
1061:
1062: long instant_long = ((LogCounter) instant).getValueAsLong();
1063:
1064: if ((instant_long == LogCounter.INVALID_LOG_INSTANT)
1065: || (stopAt != LogCounter.INVALID_LOG_INSTANT
1066: && (scanDirection == FORWARD && instant_long > stopAt) || (scanDirection == FORWARD && instant_long < stopAt))) {
1067: close();
1068:
1069: throw StandardException.newException(
1070: SQLState.LOG_RESET_BEYOND_SCAN_LIMIT, instant,
1071: new LogCounter(stopAt));
1072: } else {
1073: long fnum = ((LogCounter) instant).getLogFileNumber();
1074:
1075: if (fnum != currentLogFileNumber) {
1076: if (SanityManager.DEBUG) {
1077: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
1078: SanityManager.DEBUG(LogToFile.DBG_FLAG, "Scan "
1079: + scanDirection + " resetting to "
1080: + instant + " need to switch log from "
1081: + currentLogFileNumber + " to " + fnum);
1082: }
1083: }
1084:
1085: scan.close();
1086: scan = logFactory.getLogFileAtPosition(instant_long);
1087:
1088: currentLogFileNumber = fnum;
1089:
1090: if (scanDirection == FORWARD) {
1091: // NOTE:
1092: //
1093: // just get the length of the file without syncing.
1094: // this only works because the only place forward scan is used
1095: // right now is on recovery redo and nothing is being added to
1096: // the current log file. When the forward scan is used for some
1097: // other purpose, need to sync access to the end of the log
1098: //
1099: currentLogFileLength = scan.length();
1100: }
1101: } else
1102:
1103: {
1104: long fpos = ((LogCounter) instant).getLogFilePosition();
1105: scan.seek(fpos);
1106:
1107: //
1108: //RESOLVE: Can this be optimized? Does it belong here.
1109: currentLogFileLength = scan.length();
1110:
1111: if (SanityManager.DEBUG) {
1112: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
1113: SanityManager.DEBUG(LogToFile.DBG_FLAG,
1114: "Scan reset to " + instant);
1115: }
1116: }
1117: }
1118:
1119: currentInstant = instant_long;
1120:
1121: //scan is being reset, it is possibly that, scan is doing a random
1122: //access of the log file. set the knownGoodLogEnd to the instant
1123: //scan is being reset to.
1124: //Note: reset gets called with undo forward scan for CLR processing during
1125: //recovery, if this value is not reset checks to find the end of log
1126: //getNextRecordForward() will fail because undoscan scans log file
1127: //back & forth to redo CLR's.
1128: knownGoodLogEnd = currentInstant;
1129:
1130: if (SanityManager.DEBUG) {
1131: if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
1132: SanityManager
1133: .DEBUG(
1134: LogToFile.DBG_FLAG,
1135: "Scan.getInstant reset to "
1136: + currentInstant
1137: + LogCounter
1138: .toDebugString(currentInstant));
1139: }
1140: }
1141: }
1142: }
1143:
1144: /**
1145: Return the log instant (as an integer) the scan is currently on - this is the log
1146: instant of the log record that was returned by getNextRecord.
1147: */
1148: public long getInstant() {
1149: return currentInstant;
1150: }
1151:
1152: /**
1153: Return the log instant at the end of the log record on the current
1154: LogFile in the form of a log instant.
1155: After the scan has been closed, the end of the last log record will be
1156: returned except when the scan ended in an empty log file. In that
1157: case, the start of this empty log file will be returned. (This is
1158: done to make sure new log records are inserted into the newest log
1159: file.)
1160: */
1161: public long getLogRecordEnd() {
1162: return knownGoodLogEnd;
1163: }
1164:
1165: /**
1166: returns true if there is partially writen log records before the crash
1167: in the last log file. Partiall wrires are identified during forward
1168: redo scans for log recovery.
1169: */
1170: public boolean isLogEndFuzzy() {
1171: return fuzzyLogEnd;
1172: }
1173:
1174: /**
1175: Return the log instant the scan is currently on - this is the log
1176: instant of the log record that was returned by getNextRecord.
1177: */
1178: public LogInstant getLogInstant() {
1179: if (currentInstant == LogCounter.INVALID_LOG_INSTANT)
1180: return null;
1181: else
1182: return new LogCounter(currentInstant);
1183: }
1184:
1185: /**
1186: Close the scan.
1187: */
1188: public void close() {
1189: if (scan != null) {
1190: try {
1191: scan.close();
1192: } catch (IOException ioe) {
1193: }
1194:
1195: scan = null;
1196: }
1197:
1198: logFactory = null;
1199: currentLogFileNumber = -1;
1200: currentLogFileLength = -1;
1201: // Do not reset knownGoodLogEnd, it needs to be available after the
1202: // scan has closed.
1203: currentInstant = LogCounter.INVALID_LOG_INSTANT;
1204: stopAt = LogCounter.INVALID_LOG_INSTANT;
1205: scanDirection = 0;
1206: }
1207:
1208: }
|