<commit_before>/*
 *  eXist Open Source Native XML Database
 *  Copyright (C) 2001-04 The eXist Team
 *
 *  http://exist-db.org
 *  
 *  This program is free software; you can redistribute it and/or
 *  modify it under the terms of the GNU Lesser General Public License
 *  as published by the Free Software Foundation; either version 2
 *  of the License, or (at your option) any later version.
 *  
 *  This program is distributed in the hope that it will be useful,
 *  but WITHOUT ANY WARRANTY; without even the implied warranty of
 *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 *  GNU Lesser General Public License for more details.
 *  
 *  You should have received a copy of the GNU Lesser General Public License
 *  along with this program; if not, write to the Free Software
 *  Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
 *  
 *  $Id$
 */
package org.exist.storage.recovery;

import java.io.File;
import java.io.IOException;

import org.apache.log4j.Logger;
import org.exist.storage.DBBroker;
import org.exist.storage.journal.Journal;
import org.exist.storage.journal.JournalReader;
import org.exist.storage.journal.LogEntryTypes;
import org.exist.storage.journal.LogException;
import org.exist.storage.journal.Loggable;
import org.exist.storage.journal.Lsn;
import org.exist.storage.sync.Sync;
import org.exist.storage.txn.Checkpoint;
import org.exist.util.ProgressBar;
import org.exist.util.hashtable.Long2ObjectHashMap;
import org.exist.util.sanity.SanityCheck;

/**
 * Database recovery. This class is used once during startup to check
 * if the database is in a consistent state. If not, the class attempts to recover
 * the database from the journalling log.
 * 
 * @author wolf
 */
public class RecoveryManager {
	
	private final static Logger LOG = Logger.getLogger(RecoveryManager.class);
	
	/**
     * @uml.property name="logManager"
     * @uml.associationEnd multiplicity="(1 1)"
     */
	private Journal logManager;
	private DBBroker broker;
    
	public RecoveryManager(DBBroker broker, Journal log) {
        this.broker = broker;
		this.logManager = log;
	}
	
	/**
	 * Checks if the database is in a consistent state. If not, start a recovery run.
	 * 
	 * The method scans the last log file and tries to find the last checkpoint
	 * record. If the checkpoint record is the last record in the file,
	 * the database was closed cleanly and is in a consistent state. If not, a
	 * recovery run is started beginning at the last checkpoint found.
	 *  
	 * @throws LogException
	 */
	public boolean recover() throws LogException {
        boolean recoveryRun = false;
		File files[] = logManager.getFiles();
        // find the last log file in the data directory
		int lastNum = Journal.findLastFile(files);
		if (-1 < lastNum) {
            // load the last log file
			File last = logManager.getFile(lastNum);
			// scan the last log file and record the last checkpoint found
			JournalReader reader = new JournalReader(broker, last, lastNum);
            try {
            	// try to read the last log record to see if it is a checkpoint
            	boolean checkpointFound = false;
    			try {
                    Loggable lastLog = reader.lastEntry();
                    if (lastLog != null && lastLog.getLogType() == LogEntryTypes.CHECKPOINT) {
                    	Checkpoint checkpoint = (Checkpoint) lastLog;
                    	// Found a checkpoint. To be sure it is indeed a valid checkpoint
                    	// record, we compare the LSN stored in it with the current LSN.
                    	if (checkpoint.getStoredLsn() == checkpoint.getLsn()) {
                    		checkpointFound = true;
                    		LOG.debug("Database is in clean state. Last checkpoint: " + 
                    				checkpoint.getDateString());
                    	}
                    }
                } catch (LogException e) {
                    LOG.debug("Reading last journal log entry failed: " + e.getMessage() + ". Will scan the log...");
                    // if an exception occurs at this point, the journal file is probably incomplete,
                    // which indicates a db crash
                    checkpointFound = false;
                }
    			if (!checkpointFound) {
    				reader.position(1);
    				Long2ObjectHashMap txnsStarted = new Long2ObjectHashMap();
	    			Checkpoint lastCheckpoint = null;
	    			long lastLsn = Lsn.LSN_INVALID;
	                Loggable next;
	                try {
						ProgressBar progress = new ProgressBar("Scanning journal ", last.length());
	        			while ((next = reader.nextEntry()) != null) {
	//                        LOG.debug(next.dump());
							progress.set(Lsn.getOffset(next.getLsn()));
							if (next.getLogType() == LogEntryTypes.TXN_START) {
				                // new transaction starts: add it to the transactions table
				                txnsStarted.put(next.getTransactionId(), next);
				            } else if (next.getLogType() == LogEntryTypes.TXN_ABORT) {
				            	// transaction aborted: remove it from the transactions table
				            	txnsStarted.remove(next.getTransactionId());
				            } else if (next.getLogType() == LogEntryTypes.CHECKPOINT) {
				            	txnsStarted.clear();
	        					lastCheckpoint = (Checkpoint) next;
				            }
	        				lastLsn = next.getLsn();
	        			}
	                } catch (LogException e) {
	                    e.printStackTrace();
	                    if (LOG.isDebugEnabled())
	                        LOG.debug("Last readable log entry lsn: " + Lsn.dump(lastLsn));
	                }
	                
	    			// if the last checkpoint record is not the last record in the file
	    			// we need a recovery.
	    			if ((lastCheckpoint == null || lastCheckpoint.getLsn() != lastLsn) &&
	    					txnsStarted.size() > 0) {
	    				LOG.debug("Found dirty transactions: " + txnsStarted.size());
	    				// starting recovery: reposition the log reader to the last checkpoint
						if (lastCheckpoint == null)
						    reader.position(1);
						else {
						    reader.position(lastCheckpoint.getLsn());
						    next = reader.nextEntry();
						}
	                    recoveryRun = true;
	                    doRecovery(last, reader, lastLsn);
	                } else if (LOG.isDebugEnabled())
	    				LOG.debug("Database is in clean state.");
    			}
    			cleanDirectory(files);
            } finally {
                reader.close();
            }
		}
        logManager.setCurrentFileNum(lastNum);
		logManager.switchFiles();
        return recoveryRun;
	}

    /**
     * Called by {@link #recover()} to do the actual recovery.
     * 
     * @param reader
     * @param lastLsn
     * @throws LogException
     */
    private void doRecovery(File last, JournalReader reader, long lastLsn) throws LogException {
        if (LOG.isDebugEnabled())
            LOG.debug("Running recovery ...");
        logManager.setInRecovery(true);
        
        // map to track running transactions
        Long2ObjectHashMap runningTxns = new Long2ObjectHashMap();
        
        // ------- REDO ---------
        if (LOG.isDebugEnabled())
            LOG.debug("First pass: redoing operations");
		ProgressBar progress = new ProgressBar("Redo ", last.length());
        Loggable next;
        while ((next = reader.nextEntry()) != null) {
            SanityCheck.ASSERT(next.getLogType() != LogEntryTypes.CHECKPOINT,
                    "Found a checkpoint during recovery run! This should not ever happen.");
            if (next.getLogType() == LogEntryTypes.TXN_START) {
                // new transaction starts: add it to the transactions table
                runningTxns.put(next.getTransactionId(), next);
            } else if (next.getLogType() == LogEntryTypes.TXN_COMMIT) {
                // transaction committed: remove it from the transactions table
                runningTxns.remove(next.getTransactionId());
            } else if (next.getLogType() == LogEntryTypes.TXN_ABORT) {
            	// transaction aborted: remove it from the transactions table
            	runningTxns.remove(next.getTransactionId());
            }
            LOG.debug("Redo: " + next.dump());
            // redo the log entry<commit_msg>Forgot to comment out a LOG statement.<commit_after>/*
 *  eXist Open Source Native XML Database
 *  Copyright (C) 2001-04 The eXist Team
 *
 *  http://exist-db.org
 *  
 *  This program is free software; you can redistribute it and/or
 *  modify it under the terms of the GNU Lesser General Public License
 *  as published by the Free Software Foundation; either version 2
 *  of the License, or (at your option) any later version.
 *  
 *  This program is distributed in the hope that it will be useful,
 *  but WITHOUT ANY WARRANTY; without even the implied warranty of
 *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 *  GNU Lesser General Public License for more details.
 *  
 *  You should have received a copy of the GNU Lesser General Public License
 *  along with this program; if not, write to the Free Software
 *  Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
 *  
 *  $Id$
 */
package org.exist.storage.recovery;

import java.io.File;
import java.io.IOException;

import org.apache.log4j.Logger;
import org.exist.storage.DBBroker;
import org.exist.storage.journal.Journal;
import org.exist.storage.journal.JournalReader;
import org.exist.storage.journal.LogEntryTypes;
import org.exist.storage.journal.LogException;
import org.exist.storage.journal.Loggable;
import org.exist.storage.journal.Lsn;
import org.exist.storage.sync.Sync;
import org.exist.storage.txn.Checkpoint;
import org.exist.util.ProgressBar;
import org.exist.util.hashtable.Long2ObjectHashMap;
import org.exist.util.sanity.SanityCheck;

/**
 * Database recovery. This class is used once during startup to check
 * if the database is in a consistent state. If not, the class attempts to recover
 * the database from the journalling log.
 * 
 * @author wolf
 */
public class RecoveryManager {
	
	private final static Logger LOG = Logger.getLogger(RecoveryManager.class);
	
	/**
     * @uml.property name="logManager"
     * @uml.associationEnd multiplicity="(1 1)"
     */
	private Journal logManager;
	private DBBroker broker;
    
	public RecoveryManager(DBBroker broker, Journal log) {
        this.broker = broker;
		this.logManager = log;
	}
	
	/**
	 * Checks if the database is in a consistent state. If not, start a recovery run.
	 * 
	 * The method scans the last log file and tries to find the last checkpoint
	 * record. If the checkpoint record is the last record in the file,
	 * the database was closed cleanly and is in a consistent state. If not, a
	 * recovery run is started beginning at the last checkpoint found.
	 *  
	 * @throws LogException
	 */
	public boolean recover() throws LogException {
        boolean recoveryRun = false;
		File files[] = logManager.getFiles();
        // find the last log file in the data directory
		int lastNum = Journal.findLastFile(files);
		if (-1 < lastNum) {
            // load the last log file
			File last = logManager.getFile(lastNum);
			// scan the last log file and record the last checkpoint found
			JournalReader reader = new JournalReader(broker, last, lastNum);
            try {
            	// try to read the last log record to see if it is a checkpoint
            	boolean checkpointFound = false;
    			try {
                    Loggable lastLog = reader.lastEntry();
                    if (lastLog != null && lastLog.getLogType() == LogEntryTypes.CHECKPOINT) {
                    	Checkpoint checkpoint = (Checkpoint) lastLog;
                    	// Found a checkpoint. To be sure it is indeed a valid checkpoint
                    	// record, we compare the LSN stored in it with the current LSN.
                    	if (checkpoint.getStoredLsn() == checkpoint.getLsn()) {
                    		checkpointFound = true;
                    		LOG.debug("Database is in clean state. Last checkpoint: " + 
                    				checkpoint.getDateString());
                    	}
                    }
                } catch (LogException e) {
                    LOG.debug("Reading last journal log entry failed: " + e.getMessage() + ". Will scan the log...");
                    // if an exception occurs at this point, the journal file is probably incomplete,
                    // which indicates a db crash
                    checkpointFound = false;
                }
    			if (!checkpointFound) {
    				reader.position(1);
    				Long2ObjectHashMap txnsStarted = new Long2ObjectHashMap();
	    			Checkpoint lastCheckpoint = null;
	    			long lastLsn = Lsn.LSN_INVALID;
	                Loggable next;
	                try {
						ProgressBar progress = new ProgressBar("Scanning journal ", last.length());
	        			while ((next = reader.nextEntry()) != null) {
	//                        LOG.debug(next.dump());
							progress.set(Lsn.getOffset(next.getLsn()));
							if (next.getLogType() == LogEntryTypes.TXN_START) {
				                // new transaction starts: add it to the transactions table
				                txnsStarted.put(next.getTransactionId(), next);
				            } else if (next.getLogType() == LogEntryTypes.TXN_ABORT) {
				            	// transaction aborted: remove it from the transactions table
				            	txnsStarted.remove(next.getTransactionId());
				            } else if (next.getLogType() == LogEntryTypes.CHECKPOINT) {
				            	txnsStarted.clear();
	        					lastCheckpoint = (Checkpoint) next;
				            }
	        				lastLsn = next.getLsn();
	        			}
	                } catch (LogException e) {
	                    e.printStackTrace();
	                    if (LOG.isDebugEnabled())
	                        LOG.debug("Last readable log entry lsn: " + Lsn.dump(lastLsn));
	                }
	                
	    			// if the last checkpoint record is not the last record in the file
	    			// we need a recovery.
	    			if ((lastCheckpoint == null || lastCheckpoint.getLsn() != lastLsn) &&
	    					txnsStarted.size() > 0) {
	    				LOG.debug("Found dirty transactions: " + txnsStarted.size());
	    				// starting recovery: reposition the log reader to the last checkpoint
						if (lastCheckpoint == null)
						    reader.position(1);
						else {
						    reader.position(lastCheckpoint.getLsn());
						    next = reader.nextEntry();
						}
	                    recoveryRun = true;
	                    doRecovery(last, reader, lastLsn);
	                } else if (LOG.isDebugEnabled())
	    				LOG.debug("Database is in clean state.");
    			}
    			cleanDirectory(files);
            } finally {
                reader.close();
            }
		}
        logManager.setCurrentFileNum(lastNum);
		logManager.switchFiles();
        return recoveryRun;
	}

    /**
     * Called by {@link #recover()} to do the actual recovery.
     * 
     * @param reader
     * @param lastLsn
     * @throws LogException
     */
    private void doRecovery(File last, JournalReader reader, long lastLsn) throws LogException {
        if (LOG.isDebugEnabled())
            LOG.debug("Running recovery ...");
        logManager.setInRecovery(true);
        
        // map to track running transactions
        Long2ObjectHashMap runningTxns = new Long2ObjectHashMap();
        
        // ------- REDO ---------
        if (LOG.isDebugEnabled())
            LOG.debug("First pass: redoing operations");
		ProgressBar progress = new ProgressBar("Redo ", last.length());
        Loggable next;
        while ((next = reader.nextEntry()) != null) {
            SanityCheck.ASSERT(next.getLogType() != LogEntryTypes.CHECKPOINT,
                    "Found a checkpoint during recovery run! This should not ever happen.");
            if (next.getLogType() == LogEntryTypes.TXN_START) {
                // new transaction starts: add it to the transactions table
                runningTxns.put(next.getTransactionId(), next);
            } else if (next.getLogType() == LogEntryTypes.TXN_COMMIT) {
                // transaction committed: remove it from the transactions table
                runningTxns.remove(next.getTransactionId());
            } else if (next.getLogType() == LogEntryTypes.TXN_ABORT) {
            	// transaction aborted: remove it from the transactions table
            	runningTxns.remove(next.getTransactionId());
            }
//            LOG.debug("Redo: " + next.dump());
            // redo the log entry
{'fraction_non_alphanumeric': 0.09400782896717856, 'fraction_numerical': 0.0032520325203252032, 'mean_word_length': 2.093517138599106, 'pattern_counts': {'":': 0, '<': 5, '<?xml version=': 0, '>': 5, 'https://': 0, 'lorem ipsum': 0, 'www.': 0, 'xml': 0}, 'pii_count': 0, 'substrings_counts': 0, 'word_list_counts': {'cursed_substrings.json': 0, 'profanity_word_list.json': 0, 'sexual_word_list.json': 0, 'zh_pornsignals.json': 0}}
{'dir': 'git-commits-cleaned', 'id': '5102157', 'n_tokens_mistral': 4804, 'n_tokens_neox': 4328, 'n_words': 1411}