EMMA Coverage Report (generated Wed Jun 28 22:15:27 PDT 2006)
[all classes][org.apache.derby.impl.store.raw.log]

COVERAGE SUMMARY FOR SOURCE FILE [Scan.java]

nameclass, %method, %block, %line, %
Scan.java100% (1/1)90%  (9/10)67%  (1024/1531)78%  (222.6/285)

COVERAGE BREAKDOWN BY CLASS AND METHOD

nameclass, %method, %block, %line, %
     
class Scan100% (1/1)90%  (9/10)67%  (1024/1531)78%  (222.6/285)
Scan (LogToFile, long, LogInstant, byte): void 100% (1/1)90%  (94/105)96%  (25/26)
close (): void 100% (1/1)97%  (32/33)92%  (12/13)
getInstant (): long 100% (1/1)100% (3/3)100% (1/1)
getLogInstant (): LogInstant 0%   (0/1)0%   (0/13)0%   (0/3)
getLogRecordEnd (): long 100% (1/1)100% (3/3)100% (1/1)
getNextRecord (ArrayInputStream, TransactionId, int): LogRecord 100% (1/1)58%  (41/71)53%  (9/17)
getNextRecordBackward (ArrayInputStream, TransactionId, int): LogRecord 100% (1/1)71%  (330/462)83%  (66.1/80)
getNextRecordForward (ArrayInputStream, TransactionId, int): LogRecord 100% (1/1)63%  (426/680)75%  (88.8/119)
isLogEndFuzzy (): boolean 100% (1/1)100% (3/3)100% (1/1)
resetPosition (LogInstant): void 100% (1/1)58%  (92/158)78%  (18.8/24)

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

[all classes][org.apache.derby.impl.store.raw.log]
EMMA 2.0.5312 (C) Vladimir Roubtsov