Scan


1   /*
2   
3      Derby - Class org.apache.derby.impl.store.raw.log.Scan
4   
5      Licensed to the Apache Software Foundation (ASF) under one or more
6      contributor license agreements.  See the NOTICE file distributed with
7      this work for additional information regarding copyright ownership.
8      The ASF licenses this file to you under the Apache License, Version 2.0
9      (the "License"); you may not use this file except in compliance with
10     the License.  You may obtain a copy of the License at
11  
12        http://www.apache.org/licenses/LICENSE-2.0
13  
14     Unless required by applicable law or agreed to in writing, software
15     distributed under the License is distributed on an "AS IS" BASIS,
16     WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
17     See the License for the specific language governing permissions and
18     limitations under the License.
19  
20   */
21  
22  package org.apache.derby.impl.store.raw.log;
23  
24  import org.apache.derby.iapi.reference.SQLState;
25  
26  import org.apache.derby.iapi.services.io.ArrayInputStream;
27  
28  import org.apache.derby.iapi.services.sanity.SanityManager;
29  
30  import org.apache.derby.iapi.error.StandardException;
31  
32  import org.apache.derby.iapi.store.raw.log.LogInstant;
33  
34  import org.apache.derby.iapi.store.raw.xact.TransactionId;
35  
36  import org.apache.derby.impl.store.raw.log.LogCounter;
37  import org.apache.derby.impl.store.raw.log.LogRecord;
38  import org.apache.derby.impl.store.raw.log.StreamLogScan;
39  
40  import org.apache.derby.io.StorageRandomAccessFile;
41  
42  import java.io.IOException  ;
43  import org.apache.derby.iapi.store.raw.Loggable;
44  
45  /**
46  
47          Scan the the log which is implemented by a series of log files.n
48          This log scan knows how to move across log file if it is positioned at
49          the boundary of a log file and needs to getNextRecord.
50  
51      <PRE>
52      4 bytes - length of user data, i.e. N
53      8 bytes - long representing log instant
54      N bytes of supplied data
55      4 bytes - length of user data, i.e. N
56      </PRE>
57  
58  */
59  
60  public class Scan implements StreamLogScan {
61  
62      // value for scanDirection
63      public static final byte FORWARD = 1;
64      public static final byte BACKWARD = 2;
65      public static final byte BACKWARD_FROM_LOG_END = 4;
66  
67      private StorageRandomAccessFile scan;       // an output stream to the log file
68      private LogToFile logFactory;       // log factory knows how to to skip
69                                          // from log file to log file
70  
71      private long currentLogFileNumber;  // the log file the scan is currently on
72  
73      private long currentLogFileLength;  // the size of the current log file
74                                          // used only for FORWARD scan to determine when
75                                          // to switch the next log file
76  
77      private long knownGoodLogEnd; // For FORWARD scan only
78                                  // during recovery, we need to determine the end
79                                  // of the log.  Everytime a complete log record
80                                  // is read in, knownGoodLogEnd is set to the
81                                  // log instant of the next log record if it is
82                                  // on the same log file.
83                                  // 
84                                  // only valid afer a successfull getNextRecord
85                                  // on a FOWARD scan. 
86  
87  
88      private long currentInstant;        // the log instant the scan is
89                                          // currently on - only valid after a
90                                          // successful getNextRecord
91  
92      private long stopAt;                // scan until we find a log record whose 
93                                          // log instance < stopAt if we scan BACKWARD
94                                          // log instance > stopAt if we scan FORWARD
95                                          // log instance >= stopAt if we scan FORWARD_FLUSHED
96  
97  
98      private byte scanDirection;         // BACKWARD or FORWARD
99  
100     private boolean fuzzyLogEnd = false;   //get sets to true during forward scan
101                                           //for recovery, if there were
102                                           //partial writes at the end of the log before crash;
103                                           //during forward scan for recovery.
104 
105 
106     /**
107         For backward scan, we expect a scan positioned at the end of the next log record.
108         For forward scan, we expect a scan positioned at the beginning of the next log record.
109 
110         For forward flushed scan, we expect stopAt to be the instant for the
111            first not-flushed log record. Like any forward scan, we expect a scan
112            positioned at the beginning of the next log record.
113 
114         @exception StandardException Standard Cloudscape error policy
115         @exception IOException cannot access the log at the new position.
116     */
117     public Scan(LogToFile logFactory, long startAt, LogInstant stopAt, byte direction)
118          throws IOException  , StandardException
119     {
120         if (SanityManager.DEBUG)
121             SanityManager.ASSERT(startAt != LogCounter.INVALID_LOG_INSTANT, 
122                                  "cannot start scan on an invalid log instant");
123 
124         this.logFactory = logFactory;
125         currentLogFileNumber = LogCounter.getLogFileNumber(startAt);
126         currentLogFileLength = -1;
127         knownGoodLogEnd = LogCounter.INVALID_LOG_INSTANT;// set at getNextRecord for FORWARD scan
128         currentInstant = LogCounter.INVALID_LOG_INSTANT; // set at getNextRecord
129         if (stopAt != null)
130             this.stopAt = ((LogCounter) stopAt).getValueAsLong();
131         else
132             this.stopAt = LogCounter.INVALID_LOG_INSTANT;
133 
134         switch(direction)
135         {
136         case FORWARD:
137             scan =  logFactory.getLogFileAtPosition(startAt);
138             scanDirection = FORWARD;
139 
140             if (SanityManager.DEBUG)
141                 if (scan == null)
142                     SanityManager.THROWASSERT(
143                         "scan null at " + LogCounter.toDebugString(startAt));
144 
145             // NOTE: just get the length of the file without syncing.
146             // this only works because the only place forward scan is used
147             // right now is on recovery redo and nothing is being added to 
148             // the current log file.  When the forward scan is used for some
149             // other purpose, need to sync access to the end of the log
150             currentLogFileLength = scan.length();
151             break;
152 
153         case BACKWARD:
154             // startAt is at the front of the log record, for backward
155             // scan we need to be positioned at the end of the log record
156             scan =  logFactory.getLogFileAtPosition(startAt);
157             int logsize = scan.readInt();
158 
159             // skip forward over the log record and all the overhead, but remember
160             // we just read an int off the overhead
161             scan.seek(scan.getFilePointer() + logsize + LogToFile.LOG_RECORD_OVERHEAD - 4);
162             scanDirection = BACKWARD;
163             break;
164 
165         case BACKWARD_FROM_LOG_END:
166             // startAt is at the end of the log, no need to skip the log record
167             scan =  logFactory.getLogFileAtPosition(startAt);
168             scanDirection = BACKWARD;
169             break;
170 
171         }
172     }
173 
174     /*
175     ** Methods of StreamLogScan
176     */
177 
178     /**
179         Read the next log record.
180         Switching log to a previous log file if necessary, 
181         Resize the input stream byte array if necessary.  
182         @see StreamLogScan#getNextRecord
183 
184         @return the next LogRecord, or null if the end of the
185         scan has been reached.
186 
187         @exception StandardException Standard Cloudscape error policy
188     */
189     public LogRecord getNextRecord(ArrayInputStream input, 
190                              TransactionId tranId, 
191                              int groupmask)
192          throws StandardException
193     {
194         if (scan == null)
195             return null;
196 
197         if (SanityManager.DEBUG)
198             SanityManager.ASSERT(scanDirection != 0, "scan has been secretly closed!");
199 
200         LogRecord lr = null;
201         try
202         {
203             if (scanDirection == BACKWARD)
204                 lr = getNextRecordBackward(input, tranId, groupmask);
205             else if (scanDirection == FORWARD)
206                 lr = getNextRecordForward(input, tranId, groupmask);
207 
208             return lr;
209 
210         }
211         catch (IOException   ioe)
212         {
213             if (SanityManager.DEBUG)
214                 ioe.printStackTrace();
215 
216             throw logFactory.markCorrupt(
217                 StandardException.newException(SQLState.LOG_CORRUPTED, ioe));
218         }
219         catch (ClassNotFoundException   cnfe)
220         {
221             if (SanityManager.DEBUG)
222                 cnfe.printStackTrace();
223 
224             throw logFactory.markCorrupt(
225                 StandardException.newException(SQLState.LOG_CORRUPTED, cnfe));
226         }
227         finally
228         {
229             if (lr == null)
230                 close();        // no more log record, close the scan
231         }
232 
233     }
234 
235     /**
236         Read the previous log record.
237         Switching log to a previous log file if necessary, 
238         Resize the input stream byte array if necessary.  
239         @see StreamLogScan#getNextRecord
240 
241         Side effects include: 
242                 on a successful read, setting currentInstant.
243                 on a log file switch, setting currentLogFileNumber.
244 
245         @return the previous LogRecord, or null if the end of the
246         scan has been reached.
247     */
248     private LogRecord getNextRecordBackward(ArrayInputStream input, 
249                                       TransactionId tranId,  
250                                       int groupmask) 
251          throws StandardException, IOException  , ClassNotFoundException  
252     {
253         if (SanityManager.DEBUG)
254             SanityManager.ASSERT(scanDirection == BACKWARD, "can only called by backward scan");
255 
256         // scan is positioned just past the last byte of the record, or
257         // right at the beginning of the file (end of the file header)
258         // may need to switch log file
259 
260         boolean candidate;
261         // if we have filtering, peek at the group and/or the transaction id,
262         // do them in one read rather than 2 reads.
263         int peekAmount = LogRecord.formatOverhead() + LogRecord.maxGroupStoredSize();
264         if (tranId != null)
265             peekAmount += LogRecord.maxTransactionIdStoredSize(tranId);
266 
267         int readAmount;         // the number of bytes actually read
268 
269         LogRecord lr;
270         long curpos = scan.getFilePointer();
271 
272         do
273         {
274             // this log record is a candidate unless proven otherwise
275             candidate = true; 
276             lr = null;
277             readAmount = -1;
278 
279             if (curpos == LogToFile.LOG_FILE_HEADER_SIZE)
280             {
281                 // don't go thru the trouble of switching log file if we
282                 // will have gone past stopAt
283                 if (stopAt != LogCounter.INVALID_LOG_INSTANT &&
284                     LogCounter.getLogFileNumber(stopAt) == currentLogFileNumber)
285                 {
286                     if (SanityManager.DEBUG)
287                     {
288                         if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
289                         {
290                             SanityManager.DEBUG(LogToFile.DBG_FLAG, 
291                                 "stopping at " + currentLogFileNumber);
292                         }
293                     }
294 
295                     return null;  // no more log record
296                 }
297                 
298                 // figure out where the last log record is in the previous
299                 // log file
300                 scan.seek(LogToFile.LOG_FILE_HEADER_PREVIOUS_LOG_INSTANT_OFFSET);
301                 long previousLogInstant = scan.readLong();
302                 scan.close();
303 
304                 if (SanityManager.DEBUG)
305                 {
306                     SanityManager.ASSERT(previousLogInstant != LogCounter.INVALID_LOG_INSTANT,
307                                      "scanning backward beyond the first log file");
308                     if (currentLogFileNumber != 
309                             LogCounter.getLogFileNumber(previousLogInstant) + 1)
310                         SanityManager.THROWASSERT(
311                         "scanning backward but get incorrect log file number " + 
312                          "expected " + (currentLogFileNumber -1) + 
313                          "get " +
314                          LogCounter.getLogFileNumber(previousLogInstant));
315 
316                     SanityManager.ASSERT(LogCounter.getLogFilePosition(previousLogInstant) > 
317                                      LogToFile.LOG_FILE_HEADER_SIZE,
318                                      "scanning backward encounter completely empty log file");
319 
320                     SanityManager.DEBUG(LogToFile.DBG_FLAG, 
321                                     "scanning backwards from log file " +
322                                     currentLogFileNumber + ", switch to (" + 
323                                     LogCounter.getLogFileNumber(previousLogInstant) + "," +
324                                     LogCounter.getLogFilePosition(previousLogInstant) + ")"
325                                     );
326                 }
327 
328                 // log file switch, set this.currentLogFileNumber
329                 currentLogFileNumber = LogCounter.getLogFileNumber(previousLogInstant);
330 
331                 scan = logFactory.getLogFileAtPosition(previousLogInstant);
332 
333                 // scan is located right past the last byte of the last log
334                 // record in the previous log file.  currentLogFileNumber is
335                 // set.  We asserted that the scan is not located right at the
336                 // end of the file header, in other words, there is at least
337                 // one log record in this log file.
338                 curpos = scan.getFilePointer();
339 
340                 // if the log file happens to be empty skip and proceed. 
341                 // ideally this case should never occur because log switch is
342                 // not suppose to happen on an empty log file. 
343                 // But it is safer to put following check incase if it ever
344                 // happens to avoid any recovery issues. 
345                 if (curpos == LogToFile.LOG_FILE_HEADER_SIZE)
346                     continue;
347             }
348 
349             scan.seek(curpos - 4);
350             int recordLength = scan.readInt(); // get the length after the log record
351 
352             // calculate where this log record started.
353             // include the eight bytes for the long log instant at the front
354             // the four bytes of length in the front and the four bytes we just read
355             long recordStartPosition = curpos - recordLength -
356                 LogToFile.LOG_RECORD_OVERHEAD; 
357 
358             if (SanityManager.DEBUG)
359             {
360                 if (recordStartPosition < LogToFile.LOG_FILE_HEADER_SIZE)
361                     SanityManager.THROWASSERT(
362                                  "next position " + recordStartPosition +
363                                  " recordLength " + recordLength + 
364                                  " current file position " + scan.getFilePointer());
365 
366                 scan.seek(recordStartPosition);
367 
368                 // read the length before the log record and check it against the
369                 // length after the log record
370                 int checkLength = scan.readInt();
371 
372                 if (checkLength != recordLength)
373                 {
374                     long inst = LogCounter.makeLogInstantAsLong(currentLogFileNumber, recordStartPosition);
375 
376                     throw logFactory.markCorrupt(
377                         StandardException.newException(
378                             SQLState.LOG_RECORD_CORRUPTED, 
379                             new Long  (checkLength),
380                             new Long  (recordLength),
381                             new Long  (inst),
382                             new Long  (currentLogFileNumber)));
383                 }
384             }
385             else
386             {
387                 // skip over the length in insane
388                 scan.seek(recordStartPosition+4);
389             }
390 
391             // scan is positioned just before the log instant
392             // read the current log instant - this is the currentInstant if we have not
393             // exceeded the scan limit
394             currentInstant = scan.readLong();
395 
396             if (SanityManager.DEBUG)
397             {
398                 // sanity check the current instant against the scan position
399                 if (LogCounter.getLogFileNumber(currentInstant) !=
400                     currentLogFileNumber ||
401                     LogCounter.getLogFilePosition(currentInstant) !=
402                     recordStartPosition)
403                     SanityManager.THROWASSERT(
404                                  "Wrong LogInstant on log record " +
405                                 LogCounter.toDebugString(currentInstant) + 
406                                  " version real position (" +
407                                  currentLogFileNumber + "," +
408                                  recordStartPosition + ")");
409             }
410 
411 
412             // if stopAt == INVALID_LOG_INSTANT, no stop instant, read till
413             // nothing more can be read.  Else check scan limit
414             if (currentInstant < stopAt && stopAt != LogCounter.INVALID_LOG_INSTANT)
415             {
416                 currentInstant = LogCounter.INVALID_LOG_INSTANT;
417                 return null;    // we went past the stopAt
418             }
419 
420 
421             byte[] data = input.getData();
422 
423             if (data.length < recordLength)
424             {
425                 // make a new array of sufficient size and reset the arrary
426                 // in the input stream
427                 data = new byte[recordLength];
428                 input.setData(data);
429             }
430 
431             // If the log is encrypted, we must do the filtering after reading
432             // and decrypting the record.
433             if (logFactory.databaseEncrypted())
434             {
435                 scan.readFully(data, 0, recordLength);
436                 int len = logFactory.decrypt(data, 0, recordLength, data, 0);
437                 if (SanityManager.DEBUG)
438                     SanityManager.ASSERT(len == recordLength);
439                 input.setLimit(0, recordLength);
440             }
441             else // no need to decrypt, only get the group and tid if we filter 
442             {
443                 if (groupmask == 0 && tranId == null)
444                 {
445                     // no filter, get the whole thing
446                     scan.readFully(data, 0, recordLength);
447                     input.setLimit(0, recordLength);
448                 }
449                 else
450                 {
451                     // Read only enough so that group and the tran id is in
452                     // the data buffer.  Group is stored as compressed int
453                     // and tran id is stored as who knows what.  read min
454                     // of peekAmount or recordLength
455                     readAmount = (recordLength > peekAmount) ?
456                         peekAmount : recordLength; 
457 
458                     // in the data buffer, we now have enough to peek
459                     scan.readFully(data, 0, readAmount);
460                     input.setLimit(0, readAmount);
461                 }
462             }
463 
464             lr = (LogRecord) input.readObject();
465 
466             // skip the checksum log records, there is no need to look at them 
467             // during backward scans. They are used only in forwardscan during recovery. 
468             if(lr.isChecksum())
469             {
470                 candidate = false; 
471             }else if (groupmask != 0 || tranId != null)
472             {
473 
474                 // skip the checksum log records  
475                 if(lr.isChecksum())
476                     candidate = false; 
477 
478                 if (candidate && groupmask != 0 && (groupmask & lr.group()) == 0)
479                     candidate = false; // no match, throw this log record out 
480 
481                 if (candidate && tranId != null)
482                 {
483                     TransactionId tid = lr.getTransactionId();
484                     if (!tid.equals(tranId)) // nomatch
485                         candidate = false; // throw this log record out
486                 }
487 
488                 // if this log record is not filtered out, we need to read
489                 // in the rest of the log record to the input buffer.
490                 // Except if it is an encrypted database, in which case the
491                 // entire log record have already be read in for
492                 // decryption.
493                 if (candidate && !logFactory.databaseEncrypted())
494                 {
495                     // read the rest of the log into the buffer
496                     if (SanityManager.DEBUG)
497                         SanityManager.ASSERT(readAmount > 0);
498 
499                     if (readAmount < recordLength)
500                     {
501                         // Need to remember where we are because the log
502                         // record may have read part of it off the input
503                         // stream already and that position is lost when we
504                         // set limit again.
505                         int inputPosition = input.getPosition();
506 
507                         scan.readFully(data, readAmount,
508                                        recordLength-readAmount); 
509 
510                         input.setLimit(0, recordLength);
511                         input.setPosition(inputPosition);
512                     }
513                 }
514             }
515 
516             // go back to the start of the log record so that the next time
517             // this method is called, it is positioned right past the last byte
518             // of the record.
519             curpos = recordStartPosition;
520             scan.seek(curpos);
521 
522         } while (candidate == false);
523 
524         return lr;
525 
526     }
527 
528     /**
529         Read the next log record.
530         Switching log to a previous log file if necessary, 
531         Resize the input stream byte array if necessary.  
532         @see StreamLogScan#getNextRecord
533 
534         Side effects include: 
535                 on a successful read, setting currentInstant, knownGoodLogEnd
536                 on a log file switch, setting currentLogFileNumber, currentLogFileLength.
537                 on detecting a fuzzy log end that needs clearing, it will call
538                 logFactory to clear the fuzzy log end.
539 
540         @return the next LogRecord, or null if the end of the
541         scan has been reached.
542     */
543     private LogRecord getNextRecordForward(ArrayInputStream input, 
544                                      TransactionId tranId,  
545                                      int groupmask)
546          throws StandardException,  IOException  , ClassNotFoundException  
547     {
548         if (SanityManager.DEBUG)
549             SanityManager.ASSERT(scanDirection == FORWARD, "can only called by forward scan");
550 
551         // NOTE:
552         //
553         // if forward scan, scan is positioned at the first byte of the
554         // next record, or the end of file - note the the 'end of file'
555         // is defined at the time the scan is initialized.  If we are
556         // on the current log file, it may well have grown by now...
557         //
558         // This is not a problem in reality because the only forward
559         // scan on the log now is recovery redo and the log does not
560         // grow.  If in the future, a foward scan of the log is used
561         // for some other reasons, need to keep this in mind.
562         //
563 
564         // first we need to make sure the entire log record is on the
565         // log, or else this is a fuzzy log end.
566 
567         // RESOLVE: can get this from knownGoodLogEnd if this is not the first
568         // time getNext is called.  Probably just as fast to call
569         // scan.getFilePointer though...
570         long recordStartPosition = scan.getFilePointer();
571 
572         boolean candidate;
573 
574         // if we have filtering, peek at the group and/or the transaction id,
575         // do them in one read rather than 2 reads.
576         int peekAmount = LogRecord.formatOverhead() + LogRecord.maxGroupStoredSize();
577         if (tranId != null)
578             peekAmount += LogRecord.maxTransactionIdStoredSize(tranId);
579 
580         int readAmount;         // the number of bytes actually read
581 
582         LogRecord lr;
583 
584         do
585         {
586             // this log record is a candidate unless proven otherwise
587             candidate = true;
588             lr = null;
589             readAmount = -1;
590 
591             // if we are not right at the end but this position + 4 is at
592             // or exceeds the end, we know we don't have a complete log
593             // record.  This is the log file and chalk it up as the fuzzy
594             // end.
595             if (recordStartPosition + 4 > currentLogFileLength)
596             {
597                 // since there is no end of log file marker, we are at the
598                 // end of the log.
599                 if (SanityManager.DEBUG)
600                 {
601                     if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
602                     {
603                         SanityManager.DEBUG(LogToFile.DBG_FLAG, 
604                             "detected fuzzy log end on log file " + 
605                                 currentLogFileNumber + 
606                             " record start position " + recordStartPosition + 
607                             " file length " + currentLogFileLength);
608                     }
609                 }
610                 
611                 //if  recordStartPosition == currentLogFileLength
612                 //there is NO fuzz, it just a properly ended log 
613                 //without the end marker. 
614                 if(recordStartPosition != currentLogFileLength)
615                     fuzzyLogEnd = true ;
616 
617                 // don't bother to write the end of log file marker because
618                 // if it is not overwritten by the next log record then
619                 // the next time the database is recovered it will come
620                 // back right here
621                 return null;
622             }
623 
624             // read in the length before the log record
625             int recordLength = scan.readInt();
626 
627             while (recordLength == 0 || recordStartPosition + recordLength +
628                    LogToFile.LOG_RECORD_OVERHEAD > currentLogFileLength) 
629             {
630                 // if recordLength is zero or the log record goes beyond the
631                 // current file, then we have detected the end of a log file.
632                 //
633                 // If recordLength == 0 then we know that this log file has either
634                 // been properly switched or it had a 1/2 written log record which 
635                 // was subsequently cleared by clearFuzzyEnd.
636                 //
637                 // If recordLength != 0 but log record goes beyond the current log
638                 // file, we have detected a fuzzy end.  This is the last log file
639                 // since we will clear it by clearFuzzyEnd.
640 
641                 if (recordLength != 0) // this is a fuzzy log end
642                 {
643                     if (SanityManager.DEBUG)
644                     {
645                         if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
646                         {
647                             SanityManager.DEBUG(
648                                 LogToFile.DBG_FLAG, 
649                                 "detected fuzzy log end on log file " + 
650                                     currentLogFileNumber + 
651                                 " record start position " + 
652                                     recordStartPosition + 
653                                 " file length " + currentLogFileLength + 
654                                 " recordLength=" + recordLength );
655                         }
656                     }
657 
658                     fuzzyLogEnd = true;
659                     scan.close();
660                     scan = null;
661 
662                     return null;
663                 }
664 
665                 // recordLength == 0
666 
667                 if (SanityManager.DEBUG) 
668                 {
669                     if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
670                     {
671                         if (recordStartPosition + 4 == currentLogFileLength)
672                         {
673                             SanityManager.DEBUG(LogToFile.DBG_FLAG, 
674                                 "detected proper log end on log file " + 
675                                 currentLogFileNumber);
676                         }
677                         else
678                         {
679                             SanityManager.DEBUG(LogToFile.DBG_FLAG, 
680                                     "detected zapped log end on log file " + 
681                                         currentLogFileNumber +
682                                     " end marker at " + 
683                                         recordStartPosition + 
684                                     " real end at " + currentLogFileLength);
685                         }
686                     }
687                 }
688                 
689                 // don't go thru the trouble of switching log file if we
690                 // have will have gone past stopAt if we want to stop here
691                 if (stopAt != LogCounter.INVALID_LOG_INSTANT &&
692                     LogCounter.getLogFileNumber(stopAt) == currentLogFileNumber)
693                 {
694                     return null;
695                 }
696 
697                 //
698                 // we have a log end marker and we don't want to stop yet, switch
699                 // log file
700                 //
701                 scan.close();
702 
703                 // set this.currentLogFileNumber
704                 scan = logFactory.getLogFileAtBeginning(++currentLogFileNumber);
705                 if (scan == null) // we have seen the last log file
706                 {
707                     return null;
708                 }
709 
710                 // scan is position just past the log header
711                 recordStartPosition = scan.getFilePointer();
712 
713                 // Verify that the header of the new log file refers
714                 // to the end of the log record of the previous file
715                 // (Rest of header has been verified by getLogFileAtBeginning)
716                 scan.seek(LogToFile
717                           .LOG_FILE_HEADER_PREVIOUS_LOG_INSTANT_OFFSET);
718                 long previousLogInstant = scan.readLong();
719                 if (previousLogInstant != knownGoodLogEnd) {
720                     // If there is a mismatch, something is wrong and
721                     // we return null to stop the scan.  The same
722                     // behavior occurs when getLogFileAtBeginning
723                     // detects an error in the other fields of the header.
724                     if (SanityManager.DEBUG) {
725                         if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG)) {
726                             SanityManager.DEBUG(LogToFile.DBG_FLAG, 
727                                                 "log file " 
728                                                 + currentLogFileNumber  
729                                                 + ": previous log record: "
730                                                 + previousLogInstant
731                                                 + " known previous log record: "
732                                                 + knownGoodLogEnd);
733                         }
734                     }
735                     return null;
736                 }
737 
738 
739                 scan.seek(recordStartPosition);
740 
741                 if (SanityManager.DEBUG) 
742                 {
743                     if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
744                     {
745                         SanityManager.DEBUG(LogToFile.DBG_FLAG, 
746                             "switched to next log file " + 
747                             currentLogFileNumber);
748                     }
749                 }
750 
751                 // Advance knownGoodLogEnd to make sure that if this
752                 // log file is the last log file and empty, logging
753                 // continues in this file, not the old file.
754                 knownGoodLogEnd = LogCounter.makeLogInstantAsLong
755                     (currentLogFileNumber, recordStartPosition);
756 
757                 // set this.currentLogFileLength
758                 currentLogFileLength = scan.length();
759 
760                 if (recordStartPosition+4 >= currentLogFileLength) // empty log file
761                 {
762                     if (SanityManager.DEBUG)
763                     {
764                         if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
765                         {
766                             SanityManager.DEBUG(LogToFile.DBG_FLAG, 
767                                 "log file " + currentLogFileNumber + 
768                                 " is empty");
769                         }
770                     }
771 
772                     return null;
773                 }
774 
775                 // we have successfully switched to the next log file.
776                 // scan is positioned just before the next log record
777                 // see if this one is written in entirety
778                 recordLength = scan.readInt();
779             }
780 
781             // we know the entire log record is on this log file
782 
783             // read the current log instant
784             currentInstant = scan.readLong();
785 
786             /*check if the current instant happens is less than the last one. 
787              *This can happen if system crashed before writing the log instant
788              *completely. If the instant is partially written it will be less
789              *than the last one and should be the last record that was suppose to
790              *get written. Currentlt preallocated files are filled with zeros,
791              *this should hold good.
792              *Note: In case of Non-preallocated files earlier check with log
793              * file lengths should have found the end. But in prellocated files, log file
794              *length is not sufficiant to find the log end. This check 
795              *is must to find the end in preallocated log files. 
796              */
797             if(currentInstant < knownGoodLogEnd)
798             {
799                 fuzzyLogEnd = true ;
800                 return null;
801             }
802 
803             // sanity check it 
804             if (SanityManager.DEBUG)
805             {
806                 if (LogCounter.getLogFileNumber(currentInstant) !=
807                     currentLogFileNumber ||
808                     LogCounter.getLogFilePosition(currentInstant) !=
809                     recordStartPosition)
810                     SanityManager.THROWASSERT(
811                               "Wrong LogInstant on log record " +
812                                 LogCounter.toDebugString(currentInstant) + 
813                                  " version real position (" +
814                                  currentLogFileNumber + "," +
815                                  recordStartPosition + ")");
816             }
817 
818 
819             // if stopAt == INVALID_LOG_INSTANT, no stop instant, read till
820             // nothing more can be read.  Else check scan limit
821             if (stopAt != LogCounter.INVALID_LOG_INSTANT && currentInstant > stopAt)
822             {
823                 currentInstant = LogCounter.INVALID_LOG_INSTANT;
824                 return null;            // we went past the stopAt
825             }
826 
827             // read in the log record
828             byte[] data = input.getData();
829 
830             if (data.length < recordLength)
831             {
832                 // make a new array of sufficient size and reset the arrary
833                 // in the input stream
834                 data = new byte[recordLength];
835                 input.setData(data);
836             }
837 
838             // If the log is encrypted, we must do the filtering after
839             // reading and decryptiong the record.
840 
841             if (logFactory.databaseEncrypted())
842             {
843                 scan.readFully(data, 0, recordLength);
844                 int len = logFactory.decrypt(data, 0, recordLength, data, 0);
845                 if (SanityManager.DEBUG)
846                     SanityManager.ASSERT(len == recordLength);
847 
848                 input.setLimit(0, len);
849             }
850             else // no need to decrypt, only get the group and tid if we filter 
851             {
852                 if (groupmask == 0 && tranId == null)
853                 {
854                     // no filter, get the whole thing
855                     scan.readFully(data, 0, recordLength);
856                     input.setLimit(0, recordLength);
857                 }
858                 else
859                 {
860                     // Read only enough so that group and the tran id is in
861                     // the data buffer.  Group is stored as compressed int
862                     // and tran id is stored as who knows what.  read min
863                     // of peekAmount or recordLength
864                     readAmount = (recordLength > peekAmount) ?
865                         peekAmount : recordLength; 
866 
867                     // in the data buffer, we now have enough to peek
868                     scan.readFully(data, 0, readAmount);
869                     input.setLimit(0, readAmount);
870                 }
871             }
872 
873             lr = (LogRecord) input.readObject();
874             if (groupmask != 0 || tranId != null)
875             {
876                 if (groupmask != 0 && (groupmask & lr.group()) == 0)
877                     candidate = false; // no match, throw this log record out 
878 
879                 if (candidate && tranId != null)
880                 {
881                     TransactionId tid = lr.getTransactionId();
882                     if (!tid.equals(tranId)) // nomatch
883                         candidate = false; // throw this log record out
884                 }
885 
886                 // if this log record is not filtered out, we need to read
887                 // in the rest of the log record to the input buffer.
888                 // Except if it is an encrypted database, in which case the
889                 // entire log record have already be read in for
890                 // decryption.
891                 if (candidate && !logFactory.databaseEncrypted())
892                 {
893                     // read the rest of the log into the buffer
894                     if (SanityManager.DEBUG)
895                         SanityManager.ASSERT(readAmount > 0);
896 
897                     if (readAmount < recordLength)
898                     {
899                         // Need to remember where we are because the log
900                         // record may have read part of it off the input
901                         // stream already and that position is lost when we
902                         // set limit again.
903                         int inputPosition = input.getPosition();
904 
905                         scan.readFully(data, readAmount,
906                                        recordLength-readAmount); 
907 
908                         input.setLimit(0, recordLength);
909                         input.setPosition(inputPosition);
910                     }
911                 }
912             }
913 
914             /*check if the logrecord length written before and after the 
915              *log record are equal, if not the end of of the log is reached.
916              *This can happen if system crashed before writing the length field 
917              *in the end of the records completely. If the length is partially
918              *written or not written at all  it will not match with length written 
919              *in the beginning of the log record. Currentlt preallocated files
920              *are filled with zeros, log record length can never be zero; 
921              *if the lengths are not matching, end of the properly written log
922              *is reached.
923              *Note: In case of Non-preallocated files earlier fuzzy case check with log
924              * file lengths should have found the end. But in prellocated files, log file
925              *length is not sufficiant to find the log end. This check 
926              *is must to find the end in preallocated log files. 
927              */
928             // read the length after the log record and check it against the
929             // length before the log record, make sure we go to the correct
930             // place for skipped log record.
931             if (!candidate)
932                 scan.seek(recordStartPosition - 4);
933             int checkLength = scan.readInt();
934             if (checkLength != recordLength && checkLength < recordLength)
935             {
936 
937 
938                 //lengh written in the end of the log record should be always
939                 //less then the length written in the beginning if the log
940                 //record was half written before the crash.
941                 if(checkLength < recordLength)
942                 {
943                     fuzzyLogEnd = true ;
944                     return null;
945                 }else
946                 {
947                 
948                     //If checklength > recordLength then it can be not be a partial write
949                     //probablly it is corrupted for some reason , this should never
950                     //happen throw error in debug mode. In non debug case , let's
951                     //hope it's only is wrong and system can proceed. 
952                         
953                     if (SanityManager.DEBUG)
954                     {   
955                         throw logFactory.markCorrupt
956                         (StandardException.newException(
957                             SQLState.LOG_RECORD_CORRUPTED, 
958                             new Long  (checkLength),
959                             new Long  (recordLength),
960                             new Long  (currentInstant),
961                             new Long  (currentLogFileNumber)));
962 
963                     }
964                     
965                     //In non debug case, do nothing , let's hope it's only
966                     //length part that is incorrect and system can proceed. 
967                 }
968 
969             }
970 
971             // next record start position is right after this record
972             recordStartPosition += recordLength + LogToFile.LOG_RECORD_OVERHEAD;
973             knownGoodLogEnd = LogCounter.makeLogInstantAsLong
974                                 (currentLogFileNumber, recordStartPosition);
975 
976 
977             if (SanityManager.DEBUG)
978             {
979                 if (recordStartPosition != scan.getFilePointer())
980                     SanityManager.THROWASSERT(
981                                      "calculated end " + recordStartPosition + 
982                                      " != real end " + scan.getFilePointer());
983             }
984             else
985             {
986                 // seek to the start of the next log record
987                 scan.seek(recordStartPosition);
988             }
989 
990             // the scan is now positioned just past this log record and right
991             // at the beginning of the next log record
992 
993 
994             /** if the current log record is a checksum log record then
995              * using the information available in this record validate
996              * that data in the log file by matching the checksum in 
997              * checksum log record and by recalculating the checksum for the 
998              * specified length of the data in the log file. cheksum values
999              * should match unless the right was incomplete before the crash.
1000             */
1001            if(lr.isChecksum())
1002            {
1003                // checksum log record should not be returned to the logger recovery redo
1004                // routines, it is just used to identify the incomplete log writes.
1005
1006                candidate = false;
1007                Loggable op = lr.getLoggable(); 
1008                if (SanityManager.DEBUG)
1009                {
1010                    if (SanityManager.DEBUG_ON(LogToFile.DUMP_LOG_ONLY) ||
1011                        SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
1012
1013                        SanityManager.DEBUG(LogToFile.DBG_FLAG, 
1014                                            "scanned " + "Null" + " : " + op + 
1015                                            " instant = " + 
1016                                            LogCounter.toDebugString(currentInstant) + 
1017                                            " logEnd = " +  LogCounter.toDebugString(knownGoodLogEnd));
1018                }
1019
1020                ChecksumOperation clop = (ChecksumOperation) op;
1021                int ckDataLength =  clop.getDataLength(); 
1022                // resize the buffer to be size of checksum data length if required.
1023                if (data.length < ckDataLength)
1024                {
1025                    // make a new array of sufficient size and reset the arrary
1026                    // in the input stream
1027                    data = new byte[ckDataLength];
1028                    input.setData(data);
1029                    input.setLimit(0, ckDataLength);
1030                }
1031                
1032                boolean validChecksum = false;
1033                // check if the expected number of bytes by the checksum log
1034                // record actually exist in the file and then verify if checksum
1035                // is valid to identify any incomplete out of order writes.
1036                if((recordStartPosition + ckDataLength) <= currentLogFileLength)
1037                {
1038                    // read the data into the buffer
1039                    scan.readFully(data, 0, ckDataLength);
1040                    // verify the checksum 
1041                    if(clop.isChecksumValid(data, 0 , ckDataLength))
1042                        validChecksum = true;
1043                }
1044
1045
1046                if(!validChecksum)
1047                {
1048                    // declare that the end of the transaction log is fuzzy, checksum is invalid
1049                    // only when the writes are incomplete; this can happen
1050                    // only when writes at the end of the log were partially
1051                    // written before the crash. 
1052
1053                    if (SanityManager.DEBUG)
1054                    {
1055                        if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
1056                        {
1057                            SanityManager.DEBUG(
1058                                LogToFile.DBG_FLAG, 
1059                                "detected fuzzy log end on log file while doing checksum checks " + 
1060                                currentLogFileNumber + 
1061                                " checksum record start position " + recordStartPosition + 
1062                                " file length " + currentLogFileLength + 
1063                                " checksumDataLength=" + ckDataLength);
1064                        }
1065                        
1066                    }
1067                    
1068                    fuzzyLogEnd = true;
1069                    scan.close();
1070                    scan = null;
1071                    return null;
1072                }
1073
1074                // reset the scan to the start of the next log record
1075                scan.seek(recordStartPosition);
1076            }
1077
1078
1079        } while (candidate == false) ;
1080
1081        return lr;
1082    }
1083
1084
1085    /**
1086        Reset the scan to the given LogInstant.
1087
1088        @param instant the position to reset to
1089        @exception IOException scan cannot access the log at the new position.
1090        @exception StandardException cloudscape standard error policy
1091    */
1092
1093    public void resetPosition(LogInstant instant) 
1094         throws IOException  , StandardException
1095    {
1096        if (SanityManager.DEBUG)
1097            SanityManager.ASSERT(instant != null);
1098
1099        long instant_long = ((LogCounter)instant).getValueAsLong();
1100
1101        if ((instant_long == LogCounter.INVALID_LOG_INSTANT) ||
1102            (stopAt != LogCounter.INVALID_LOG_INSTANT &&
1103             (scanDirection == FORWARD && instant_long > stopAt) ||
1104             (scanDirection == FORWARD && instant_long < stopAt)))
1105        {
1106            close();
1107
1108            throw StandardException.newException(
1109                    SQLState.LOG_RESET_BEYOND_SCAN_LIMIT, 
1110                    instant, new LogCounter(stopAt));
1111        }
1112        else
1113        {
1114            long fnum = ((LogCounter)instant).getLogFileNumber();
1115
1116            if (fnum != currentLogFileNumber)
1117            {
1118                if (SanityManager.DEBUG) 
1119                {
1120                    if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
1121                    {
1122                        SanityManager.DEBUG(LogToFile.DBG_FLAG, 
1123                                        "Scan " + scanDirection +
1124                                        " resetting to " + instant + 
1125                                        " need to switch log from " + 
1126                                        currentLogFileNumber + " to " + fnum);
1127                    }
1128                }
1129
1130                scan.close();
1131                scan = logFactory.getLogFileAtPosition(instant_long);
1132
1133                currentLogFileNumber= fnum;
1134
1135                if (scanDirection == FORWARD)
1136                {
1137                    // NOTE: 
1138                    //
1139                    // just get the length of the file without syncing.
1140                    // this only works because the only place forward scan is used
1141                    // right now is on recovery redo and nothing is being added to 
1142                    // the current log file.  When the forward scan is used for some
1143                    // other purpose, need to sync access to the end of the log
1144                    //
1145                    currentLogFileLength = scan.length();
1146                }
1147            }
1148            else
1149
1150            {
1151                long fpos = ((LogCounter)instant).getLogFilePosition();
1152                scan.seek(fpos);
1153
1154                //
1155                //RESOLVE: Can this be optimized? Does it belong here.
1156                currentLogFileLength = scan.length();
1157
1158                if (SanityManager.DEBUG)
1159                {
1160                    if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
1161                    {
1162                        SanityManager.DEBUG(LogToFile.DBG_FLAG, 
1163                                        "Scan reset to " + instant);
1164                    }
1165                }
1166            }
1167
1168
1169            currentInstant = instant_long;
1170
1171            //scan is being reset, it is possibly that, scan is doing a random 
1172            //access of the log file. set the knownGoodLogEnd to  the instant
1173            //scan  is being reset to.
1174            //Note: reset gets called with undo forward scan for CLR processing during 
1175            //recovery, if this value is not reset checks to find the end of log 
1176            //getNextRecordForward() will fail because undoscan scans log file
1177            //back & forth to redo CLR's.
1178            knownGoodLogEnd = currentInstant;
1179
1180            if (SanityManager.DEBUG)
1181            {
1182                if (SanityManager.DEBUG_ON(LogToFile.DBG_FLAG))
1183                {
1184                    SanityManager.DEBUG(LogToFile.DBG_FLAG, 
1185                        "Scan.getInstant reset to " + currentInstant + 
1186                        LogCounter.toDebugString(currentInstant));
1187                }
1188            }
1189        }
1190    }
1191
1192    /**
1193        Return the log instant (as an integer) the scan is currently on - this is the log
1194        instant of the log record that was returned by getNextRecord.
1195    */
1196    public long getInstant()
1197    {
1198        return currentInstant;
1199    }
1200
1201    /**
1202        Return the log instant at the end of the log record on the current
1203        LogFile in the form of a log instant.
1204        After the scan has been closed, the end of the last log record will be
1205        returned except when the scan ended in an empty log file.  In that
1206        case, the start of this empty log file will be returned.  (This is
1207        done to make sure new log records are inserted into the newest log
1208        file.)
1209    */
1210    public long getLogRecordEnd()
1211    {
1212        return knownGoodLogEnd;
1213    }
1214
1215    /**
1216       returns true if there is partially writen log records before the crash 
1217       in the last log file. Partiall wrires are identified during forward 
1218       redo scans for log recovery.
1219    */
1220    public boolean isLogEndFuzzy()
1221    {
1222        return fuzzyLogEnd;
1223    }
1224
1225    /**
1226        Return the log instant the scan is currently on - this is the log
1227        instant of the log record that was returned by getNextRecord.
1228    */
1229    public LogInstant getLogInstant()
1230    {
1231        if (currentInstant == LogCounter.INVALID_LOG_INSTANT)
1232            return null;
1233        else
1234            return new LogCounter(currentInstant);
1235    }
1236
1237    /**
1238        Close the scan.
1239    */
1240    public void close()
1241    {
1242        if (scan != null)
1243        {
1244            try 
1245            {
1246                scan.close();
1247            }
1248            catch (IOException   ioe)
1249            {}
1250
1251            scan = null;
1252        }
1253
1254        logFactory = null;
1255        currentLogFileNumber = -1;
1256        currentLogFileLength = -1;
1257        // Do not reset knownGoodLogEnd, it needs to be available after the
1258        // scan has closed.
1259        currentInstant = LogCounter.INVALID_LOG_INSTANT;
1260        stopAt = LogCounter.INVALID_LOG_INSTANT;
1261        scanDirection = 0;
1262    }
1263
1264}
1265
A to Z: JavaDoc & Examples Daily Java News & Articles Open Source Projects Open Source Codes Free Computer Books Remove Frame
Popular Tags