1 /*-
2  * See the file LICENSE for redistribution information.
3  *
4  * Copyright (c) 2002, 2014 Oracle and/or its affiliates.  All rights reserved.
5  *
6  */
7 
8 package com.sleepycat.je.cleaner;
9 
10 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_BIN_DELTAS_CLEANED;
11 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_BIN_DELTAS_DEAD;
12 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_BIN_DELTAS_MIGRATED;
13 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_BIN_DELTAS_OBSOLETE;
14 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_CLUSTER_LNS_PROCESSED;
15 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_DELETIONS;
16 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_ENTRIES_READ;
17 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_INS_CLEANED;
18 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_INS_DEAD;
19 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_INS_MIGRATED;
20 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_INS_OBSOLETE;
21 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LAST_KNOWN_UTILIZATION;
22 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LNQUEUE_HITS;
23 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LNS_CLEANED;
24 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LNS_DEAD;
25 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LNS_LOCKED;
26 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LNS_MARKED;
27 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LNS_MIGRATED;
28 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LNS_OBSOLETE;
29 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_LN_SIZE_CORRECTION_FACTOR;
30 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_MARKED_LNS_PROCESSED;
31 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_PENDING_LNS_LOCKED;
32 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_PENDING_LNS_PROCESSED;
33 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_PROBE_RUNS;
34 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_REPEAT_ITERATOR_READS;
35 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_RUNS;
36 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_TOTAL_LOG_SIZE;
37 import static com.sleepycat.je.cleaner.CleanerStatDefinition.CLEANER_TO_BE_CLEANED_LNS_PROCESSED;
38 import static com.sleepycat.je.cleaner.CleanerStatDefinition.GROUP_DESC;
39 import static com.sleepycat.je.cleaner.CleanerStatDefinition.GROUP_NAME;
40 
41 import java.io.File;
42 import java.io.IOException;
43 import java.util.Collection;
44 import java.util.Collections;
45 import java.util.Iterator;
46 import java.util.LinkedList;
47 import java.util.List;
48 import java.util.Map;
49 import java.util.NavigableSet;
50 import java.util.Set;
51 import java.util.concurrent.atomic.AtomicBoolean;
52 import java.util.concurrent.atomic.AtomicLong;
53 import java.util.logging.Level;
54 import java.util.logging.Logger;
55 
56 import com.sleepycat.je.CacheMode;
57 import com.sleepycat.je.DatabaseException;
58 import com.sleepycat.je.EnvironmentFailureException;
59 import com.sleepycat.je.EnvironmentMutableConfig;
60 import com.sleepycat.je.StatsConfig;
61 import com.sleepycat.je.cleaner.FileSelector.CheckpointStartCleanerState;
62 import com.sleepycat.je.config.EnvironmentParams;
63 import com.sleepycat.je.dbi.CursorImpl;
64 import com.sleepycat.je.dbi.DatabaseId;
65 import com.sleepycat.je.dbi.DatabaseImpl;
66 import com.sleepycat.je.dbi.DbConfigManager;
67 import com.sleepycat.je.dbi.DbTree;
68 import com.sleepycat.je.dbi.EnvConfigObserver;
69 import com.sleepycat.je.dbi.EnvironmentFailureReason;
70 import com.sleepycat.je.dbi.EnvironmentImpl;
71 import com.sleepycat.je.log.FileManager;
72 import com.sleepycat.je.log.ReplicationContext;
73 import com.sleepycat.je.tree.BIN;
74 import com.sleepycat.je.tree.FileSummaryLN;
75 import com.sleepycat.je.tree.IN;
76 import com.sleepycat.je.tree.LN;
77 import com.sleepycat.je.tree.Node;
78 import com.sleepycat.je.tree.Tree;
79 import com.sleepycat.je.tree.TreeLocation;
80 import com.sleepycat.je.txn.BasicLocker;
81 import com.sleepycat.je.txn.LockGrantType;
82 import com.sleepycat.je.txn.LockResult;
83 import com.sleepycat.je.txn.LockType;
84 import com.sleepycat.je.utilint.DaemonRunner;
85 import com.sleepycat.je.utilint.DbLsn;
86 import com.sleepycat.je.utilint.FloatStat;
87 import com.sleepycat.je.utilint.IntStat;
88 import com.sleepycat.je.utilint.LoggerUtils;
89 import com.sleepycat.je.utilint.LongStat;
90 import com.sleepycat.je.utilint.StatGroup;
91 import com.sleepycat.je.utilint.TestHook;
92 import com.sleepycat.je.utilint.VLSN;
93 
94 /**
95  * The Cleaner is responsible for effectively garbage collecting the JE log.
96  * It selects the least utilized log file for cleaning (see FileSelector),
97  * reads through the log file (FileProcessor) and determines whether each entry
98  * is obsolete (no longer relevant) or active (referenced by the Btree).
99  * Entries that are active are migrated (copied) to the end of the log, and
100  * finally the cleaned file is deleted.
101  *
102  * The migration of active entries is a multi-step process that can be
103  * configured to operate in different ways.  Eviction and checkpointing, as
104  * well as the cleaner threads (FileProcessor instances) are participants in
105  * this process.  Migration may be immediate or lazy.
106  *
107  * Active INs are always migrated lazily, which means that they are marked
108  * dirty by the FileProcessor, and then logged later by an eviction or
109  * checkpoint.  Active LNs are always migrated immediately by the FileProcessor
110  * by logging them.
111  *
112  * When the FileProcessor is finished with a file, all lazy migration for that
113  * file is normally completed by the end of the next checkpoint, if not sooner
114  * via eviction.  The checkpoint/recovery mechanism will ensure that obsolete
115  * entries will not be referenced by the Btree.  At the end of the checkpoint,
116  * it is therefore safe to delete the log file.
117  *
118  * There is one exception to the above paragraph.  When attempting to migrate
119  * an LN, if the LN cannot be locked then we must retry the migration at a
120  * later time.  Also, if a database removal is in progress, we consider all
121  * entries in the database obsolete but cannot delete the log file until
122  * database removal is complete.  Such "pending" LNs and databases are queued
123  * and processed periodically during file processing and at the start of a
124  * checkpoint; see processPending().  In this case, we may have to wait for
125  * more than one checkpoint to occur before the log file can be deleted.  See
126  * FileSelector and the use of the pendingLNs and pendingDBs collections.
127  */
128 public class Cleaner implements DaemonRunner, EnvConfigObserver {
129     /* From cleaner */
130     static final String CLEAN_IN = "CleanIN:";
131     static final String CLEAN_LN = "CleanLN:";
132     static final String CLEAN_MIGRATE_LN = "CleanMigrateLN:";
133     static final String CLEAN_PENDING_LN = "CleanPendingLN:";
134 
135     /**
136      * The CacheMode to use for Btree searches.  This is currently UNCHANGED
137      * because we update the generation of the BIN when we migrate an LN.
138      * In other other cases, it is not desirable to keep INs in cache.
139      */
140     static final CacheMode UPDATE_GENERATION = CacheMode.UNCHANGED;
141 
142     /**
143      * Whether the cleaner should participate in critical eviction.  Ideally
144      * the cleaner would not participate in eviction, since that would reduce
145      * the cost of cleaning.  However, the cleaner can add large numbers of
146      * nodes to the cache.  By not participating in eviction, other threads
147      * could be kept in a constant state of eviction and would effectively
148      * starve.  Therefore, this setting is currently enabled.
149      */
150     static final boolean DO_CRITICAL_EVICTION = true;
151 
152     /*
153      * Constants used by checkBacklogGrowth.  These settings are not
154      * configurable externally because our internal backlog data will probably
155      * be removed or changed in the future, and we'll have to use a different
156      * approach for determining whether the cleaner is making progress.
157      */
158     /* Number of backlogs counted in the trailing average. */
159     static final int BACKLOG_ALERT_COUNT = 5;
160     /* Smallest backlog value that will generate an alert. */
161     static final int BACKLOG_ALERT_FLOOR = 5;
162 
163     private static final String DELETED_SUBDIR = "deleted";
164 
165     /*
166      * List of recent backlog values. Maximum size is BACKLOG_ALERT_COUNT.  See
167      * checkBacklogGrowth.
168      */
169     private final LinkedList<Integer> backlogAlertList =
170         new LinkedList<Integer>();
171 
172     /*
173      * Cumulative counters.  Updates to these counters occur in multiple
174      * threads, including FileProcessor threads,  and are not synchronized.
175      * This could produce errors in counting, but avoids contention around stat
176      * updates.
177      */
178     StatGroup stats;
179     LongStat nCleanerRuns;
180     LongStat nCleanerProbeRuns;
181     LongStat nCleanerDeletions;
182     LongStat nINsObsolete;
183     LongStat nINsCleaned;
184     LongStat nINsDead;
185     LongStat nINsMigrated;
186     LongStat nBINDeltasObsolete;
187     LongStat nBINDeltasCleaned;
188     LongStat nBINDeltasDead;
189     LongStat nBINDeltasMigrated;
190     LongStat nLNsObsolete;
191     LongStat nLNsCleaned;
192     LongStat nLNsDead;
193     LongStat nLNsLocked;
194     LongStat nLNsMigrated;
195     LongStat nLNsMarked;
196     LongStat nLNQueueHits;
197     LongStat nPendingLNsProcessed;
198     LongStat nMarkedLNsProcessed;
199     LongStat nToBeCleanedLNsProcessed;
200     LongStat nClusterLNsProcessed;
201     LongStat nPendingLNsLocked;
202     LongStat nEntriesRead;
203     LongStat nRepeatIteratorReads;
204     LongStat totalLogSize;
205     FloatStat lnSizeCorrectionFactor;
206     IntStat lastKnownUtilization;
207 
208     /*
209      * Configuration parameters are non-private for use by FileProcessor,
210      * UtilizationTracker, or UtilizationCalculator.
211      */
212     long lockTimeout;
213     int readBufferSize;
214     int lookAheadCacheSize;
215     long nDeadlockRetries;
216     boolean expunge;
217     boolean useDeletedDir;
218     int maxBatchFiles;
219     long cleanerBytesInterval;
220     boolean trackDetail;
221     boolean fetchObsoleteSize;
222     int dbCacheClearCount;
223     private final boolean rmwFixEnabled;
224     int minUtilization;
225     int minFileUtilization;
226     int minAge;
227 
228     /**
229      * All files that are below the minUtilization threshold.  Used to perform
230      * clustering migration.  Is read-only after assignment, so no
231      * synchronization is needed.
232      */
233     private Set<Long> lowUtilizationFiles = Collections.emptySet();
234 
235     private final String name;
236     private final EnvironmentImpl env;
237     private final UtilizationProfile profile;
238     private final UtilizationTracker tracker;
239     private final UtilizationCalculator calculator;
240     private final FileSelector fileSelector;
241     private FileProcessor[] threads;
242 
243     /*
244      * Log file deletion must check for ongoing backups and other procedures
245      * that rely on a set log files remaining stable (no deletions).  Multiple
246      * ranges of file numbers may be protected from deletion, where each range
247      * is from a given file number to the end of the log.
248      *
249      * protectedFileRanges is a list that contains the starting file number for
250      * each protected range.  All files from the mininum of these values to the
251      * end of the log are protected from deletion.  This field is accessed only
252      * while synchronizing on protectedFileRanges.
253      */
254     private final List<Long> protectedFileRanges;
255     private final Logger logger;
256     final AtomicLong totalRuns;
257     TestHook fileChosenHook;
258 
259     /* See processPending. */
260     private final AtomicBoolean processPendingReentrancyGuard =
261         new AtomicBoolean(false);
262 
Cleaner(EnvironmentImpl env, String name)263     public Cleaner(EnvironmentImpl env, String name)
264         throws DatabaseException {
265 
266         this.env = env;
267         this.name = name;
268 
269         /* Initiate the stats definitions. */
270         stats = new StatGroup(GROUP_NAME, GROUP_DESC);
271         nCleanerRuns = new LongStat(stats, CLEANER_RUNS);
272         nCleanerProbeRuns = new LongStat(stats, CLEANER_PROBE_RUNS);
273         nCleanerDeletions = new LongStat(stats, CLEANER_DELETIONS);
274         nINsObsolete = new LongStat(stats, CLEANER_INS_OBSOLETE);
275         nINsCleaned = new LongStat(stats, CLEANER_INS_CLEANED);
276         nINsDead = new LongStat(stats, CLEANER_INS_DEAD);
277         nINsMigrated = new LongStat(stats, CLEANER_INS_MIGRATED);
278         nBINDeltasObsolete = new LongStat(stats, CLEANER_BIN_DELTAS_OBSOLETE);
279         nBINDeltasCleaned = new LongStat(stats, CLEANER_BIN_DELTAS_CLEANED);
280         nBINDeltasDead = new LongStat(stats, CLEANER_BIN_DELTAS_DEAD);
281         nBINDeltasMigrated = new LongStat(stats, CLEANER_BIN_DELTAS_MIGRATED);
282         nLNsObsolete = new LongStat(stats, CLEANER_LNS_OBSOLETE);
283         nLNsCleaned = new LongStat(stats, CLEANER_LNS_CLEANED);
284         nLNsDead = new LongStat(stats, CLEANER_LNS_DEAD);
285         nLNsLocked = new LongStat(stats, CLEANER_LNS_LOCKED);
286         nLNsMigrated = new LongStat(stats, CLEANER_LNS_MIGRATED);
287         nLNsMarked = new LongStat(stats, CLEANER_LNS_MARKED);
288         nLNQueueHits = new LongStat(stats, CLEANER_LNQUEUE_HITS);
289         nPendingLNsProcessed =
290             new LongStat(stats, CLEANER_PENDING_LNS_PROCESSED);
291         nMarkedLNsProcessed = new LongStat(stats, CLEANER_MARKED_LNS_PROCESSED);
292         nToBeCleanedLNsProcessed =
293             new LongStat(stats, CLEANER_TO_BE_CLEANED_LNS_PROCESSED);
294         nClusterLNsProcessed =
295             new LongStat(stats, CLEANER_CLUSTER_LNS_PROCESSED);
296         nPendingLNsLocked = new LongStat(stats, CLEANER_PENDING_LNS_LOCKED);
297         nEntriesRead = new LongStat(stats, CLEANER_ENTRIES_READ);
298         nRepeatIteratorReads =
299             new LongStat(stats, CLEANER_REPEAT_ITERATOR_READS);
300         totalLogSize = new LongStat(stats, CLEANER_TOTAL_LOG_SIZE);
301         lnSizeCorrectionFactor =
302             new FloatStat(stats, CLEANER_LN_SIZE_CORRECTION_FACTOR);
303         lastKnownUtilization =
304             new IntStat(stats, CLEANER_LAST_KNOWN_UTILIZATION);
305 
306         tracker = new UtilizationTracker(env, this);
307         profile = new UtilizationProfile(env, tracker);
308         calculator = new UtilizationCalculator(env, this);
309         fileSelector = new FileSelector();
310         threads = new FileProcessor[0];
311         protectedFileRanges = new LinkedList<Long>();
312         logger = LoggerUtils.getLogger(getClass());
313         totalRuns = new AtomicLong(0);
314 
315         /*
316          * The trackDetail property is immutable because of the complexity (if
317          * it were mutable) in determining whether to update the memory budget
318          * and perform eviction.
319          */
320         trackDetail = env.getConfigManager().getBoolean
321             (EnvironmentParams.CLEANER_TRACK_DETAIL);
322 
323         rmwFixEnabled = env.getConfigManager().getBoolean
324             (EnvironmentParams.CLEANER_RMW_FIX);
325 
326         /* Initialize mutable properties and register for notifications. */
327         envConfigUpdate(env.getConfigManager(), null);
328         env.addConfigObserver(this);
329     }
330 
331     /**
332      * Process notifications of mutable property changes.
333      *
334      * @throws IllegalArgumentException via Environment ctor and
335      * setMutableConfig.
336      */
envConfigUpdate(DbConfigManager cm, EnvironmentMutableConfig ignore)337     public void envConfigUpdate(DbConfigManager cm,
338                                 EnvironmentMutableConfig ignore)
339         throws DatabaseException {
340 
341         lockTimeout = cm.getDuration(EnvironmentParams.CLEANER_LOCK_TIMEOUT);
342 
343         readBufferSize = cm.getInt(EnvironmentParams.CLEANER_READ_SIZE);
344         if (readBufferSize <= 0) {
345             readBufferSize = cm.getInt
346                 (EnvironmentParams.LOG_ITERATOR_READ_SIZE);
347         }
348 
349         lookAheadCacheSize = cm.getInt
350             (EnvironmentParams.CLEANER_LOOK_AHEAD_CACHE_SIZE);
351 
352         nDeadlockRetries = cm.getInt(EnvironmentParams.CLEANER_DEADLOCK_RETRY);
353 
354         expunge = cm.getBoolean(EnvironmentParams.CLEANER_REMOVE);
355 
356         useDeletedDir =
357             cm.getBoolean(EnvironmentParams.CLEANER_USE_DELETED_DIR);
358 
359         maxBatchFiles = cm.getInt(EnvironmentParams.CLEANER_MAX_BATCH_FILES);
360 
361         dbCacheClearCount =
362             cm.getInt(EnvironmentParams.ENV_DB_CACHE_CLEAR_COUNT);
363 
364         int nThreads = cm.getInt(EnvironmentParams.CLEANER_THREADS);
365         assert nThreads > 0;
366 
367         if (nThreads != threads.length) {
368 
369             /* Shutdown threads when reducing their number. */
370             for (int i = nThreads; i < threads.length; i += 1) {
371                 if (threads[i] != null) {
372                     threads[i].shutdown();
373                     threads[i] = null;
374                 }
375             }
376 
377             /* Copy existing threads that are still used. */
378             FileProcessor[] newThreads = new FileProcessor[nThreads];
379             for (int i = 0; i < nThreads && i < threads.length; i += 1) {
380                 newThreads[i] = threads[i];
381             }
382 
383             /* Don't lose track of new threads if an exception occurs. */
384             threads = newThreads;
385 
386             /* Start new threads when increasing their number. */
387             for (int i = 0; i < nThreads; i += 1) {
388                 if (threads[i] == null) {
389                     threads[i] = new FileProcessor
390                         (name + '-' + (i + 1),
391                          env, this, profile, calculator, fileSelector);
392                 }
393             }
394         }
395 
396         cleanerBytesInterval = cm.getLong
397             (EnvironmentParams.CLEANER_BYTES_INTERVAL);
398         if (cleanerBytesInterval == 0) {
399             cleanerBytesInterval = cm.getLong
400                 (EnvironmentParams.LOG_FILE_MAX) / 4;
401         }
402 
403         fetchObsoleteSize = cm.getBoolean
404             (EnvironmentParams.CLEANER_FETCH_OBSOLETE_SIZE);
405 
406         minAge = cm.getInt(EnvironmentParams.CLEANER_MIN_AGE);
407         minUtilization = cm.getInt(EnvironmentParams.CLEANER_MIN_UTILIZATION);
408         minFileUtilization = cm.getInt
409             (EnvironmentParams.CLEANER_MIN_FILE_UTILIZATION);
410     }
411 
getUtilizationTracker()412     public UtilizationTracker getUtilizationTracker() {
413         return tracker;
414     }
415 
getUtilizationProfile()416     public UtilizationProfile getUtilizationProfile() {
417         return profile;
418     }
419 
getUtilizationCalculator()420     public UtilizationCalculator getUtilizationCalculator() {
421         return calculator;
422     }
423 
getFileSelector()424     public FileSelector getFileSelector() {
425         return fileSelector;
426     }
427 
getFetchObsoleteSize(DatabaseImpl db)428     public boolean getFetchObsoleteSize(DatabaseImpl db) {
429         return fetchObsoleteSize && !db.isLNImmediatelyObsolete();
430     }
431 
432     /**
433      * @see EnvironmentParams#CLEANER_RMW_FIX
434      * @see FileSummaryLN#postFetchInit
435      */
isRMWFixEnabled()436     public boolean isRMWFixEnabled() {
437         return rmwFixEnabled;
438     }
439 
440     /* For unit testing only. */
setFileChosenHook(TestHook hook)441     public void setFileChosenHook(TestHook hook) {
442         fileChosenHook = hook;
443     }
444 
getLogSummary()445     public CleanerLogSummary getLogSummary() {
446         return calculator.getLogSummary();
447     }
448 
setLogSummary(CleanerLogSummary logSummary)449     public void setLogSummary(CleanerLogSummary logSummary) {
450         calculator.setLogSummary(logSummary);
451     }
452 
453     /*
454      * Delegate the run/pause/wakeup/shutdown DaemonRunner operations.  We
455      * always check for null to account for the possibility of exceptions
456      * during thread creation.  Cleaner daemon can't ever be run if No Locking
457      * mode is enabled.
458      */
runOrPause(boolean run)459     public void runOrPause(boolean run) {
460         if (!env.isNoLocking()) {
461             for (FileProcessor processor : threads) {
462                 if (processor != null) {
463                     processor.runOrPause(run);
464                 }
465             }
466         }
467     }
468 
wakeup()469     public void wakeup() {
470         for (FileProcessor thread : threads) {
471             if (thread != null) {
472                 thread.wakeup();
473             }
474         }
475     }
476 
requestShutdown()477     public void requestShutdown() {
478         for (FileProcessor thread : threads) {
479             if (thread != null) {
480                 thread.requestShutdown();
481             }
482         }
483     }
484 
shutdown()485     public void shutdown() {
486         for (int i = 0; i < threads.length; i += 1) {
487             if (threads[i] != null) {
488                 threads[i].shutdown();
489                 threads[i].clearEnv();
490                 threads[i] = null;
491             }
492         }
493     }
494 
getNWakeupRequests()495     public int getNWakeupRequests() {
496         int count = 0;
497         for (FileProcessor thread : threads) {
498             if (thread != null) {
499                 count += thread.getNWakeupRequests();
500             }
501         }
502         return count;
503     }
504 
areThreadsRunning()505     private boolean areThreadsRunning() {
506         for (FileProcessor thread : threads) {
507             if (thread != null) {
508                 return thread.isRunning();
509             }
510         }
511         return false;
512     }
513 
514     /**
515      * Cleans selected files and returns the number of files cleaned.  This
516      * method is not invoked by a deamon thread, it is programatically.
517      *
518      * @param cleanMultipleFiles is true to clean until we're under budget,
519      * or false to clean at most one file.
520      *
521      * @param forceCleaning is true to clean even if we're not under the
522      * utilization threshold.
523      *
524      * @return the number of files cleaned, not including files cleaned
525      * unsuccessfully.
526      */
doClean(boolean cleanMultipleFiles, boolean forceCleaning)527     public int doClean(boolean cleanMultipleFiles, boolean forceCleaning)
528         throws DatabaseException {
529 
530         FileProcessor processor = new FileProcessor
531             ("", env, this, profile, calculator, fileSelector);
532         return processor.doClean
533             (false /*invokedFromDaemon*/, cleanMultipleFiles, forceCleaning);
534     }
535 
536     /**
537      * Load stats.
538      */
loadStats(StatsConfig config)539     public StatGroup loadStats(StatsConfig config) {
540 
541         if (!config.getFast()) {
542             totalLogSize.set(profile.getTotalLogSize());
543         }
544 
545         lnSizeCorrectionFactor.set(calculator.getLNSizeCorrectionFactor());
546         lastKnownUtilization.set(calculator.getLastKnownUtilization());
547 
548         StatGroup copyStats = stats.cloneGroup(config.getClear());
549         /* Add the FileSelector's stats to the cleaner stat group. */
550         copyStats.addAll(fileSelector.loadStats());
551 
552         return copyStats;
553     }
554 
555     /**
556      * Deletes all files that are safe-to-delete and which are not protected by
557      * a DbBackup or replication. Files are deleted only if there are no
558      * read-only processes.
559      *
560      * Log file deletion is coordinated by the use of three mechanisms:
561      *
562      * 1) To guard against read/only processes, the would-be deleter tries to
563      * get an exclusive lock on the environment. This will not be possible if a
564      * read/only process exists.  File locks must be used for inter-process
565      * coordination. But note that file locks are not supported intra-process.
566      *
567      * 2) Synchronization on the protectedFileRanges field.  Elements are added
568      * to and removed from the protectedFileRanges collection by DbBackup.
569      * More than one backup may be occuring at once, hence a collection of
570      * protectedFileRanges is maintained, and the files protected are the range
571      * starting with the minimum value returned by the objects in that
572      * collection.
573      *
574      * 3) In a replicated environment, files are protected from deletion by the
575      * CBVLSN (CleanerBarrier VLSN). No file greater or equal to the CBVLSN
576      * file may be deleted.
577      *
578      * For case (2) and (3), all coordinated activities -- replication, backup
579      * and file deletion -- can only be carried out by a read-write process, so
580      * we know that all activities are occurring in the same process because
581      * there can only be one JE read-write process per environment.
582      *
583      * This method is synchronized to prevent multiple threads from requesting
584      * the environment lock or deleting the same files.
585      */
deleteSafeToDeleteFiles()586     synchronized void deleteSafeToDeleteFiles()
587         throws DatabaseException {
588 
589         /* Fail loudly if the environment is invalid. */
590         env.checkIfInvalid();
591 
592         /* Fail silently if the environment is not open. */
593         if (env.mayNotWrite()) {
594             return;
595         }
596 
597         final NavigableSet<Long> safeToDeleteFiles =
598             fileSelector.copySafeToDeleteFiles();
599         if (safeToDeleteFiles == null) {
600             return; /* Nothing to do. */
601         }
602 
603         /*
604          * Ask HA to filter the "safe to delete" file set to determine which
605          * are needed for HA purposes, and are protected.  We can safely assume
606          * that if a file is declared to be unprotected by HA, and eligible to
607          * delete, it will never be deemed on a later call to be protected.
608          * This lets us avoid any synchronization between cleaning and HA.
609          */
610         NavigableSet<Long> unprotectedFiles =
611             env.getUnprotectedFileSet(safeToDeleteFiles);
612         if (unprotectedFiles == null) {
613 
614             /*
615              * The replicated node is not available, so the cleaner barrier can
616              * not be read. Don't delete any files.
617              */
618             return;
619         }
620 
621         if (unprotectedFiles.isEmpty()) {
622             /* Leave a clue for analyzing log file deletion problems. */
623             LoggerUtils.traceAndLog(logger, env, Level.WARNING,
624                                     "Cleaner has " + safeToDeleteFiles.size() +
625                                     " files not deleted because they are " +
626                                     "protected by replication.");
627             return; /* Nothing to do. */
628         }
629 
630         /*
631          * Truncate the entries in the VLSNIndex that reference VLSNs in the
632          * files to be deleted.  [#16566]
633          *
634          * This is done prior to deleting the files to ensure that the
635          * replicator removes the files from the VLSNIndex.  If we were to
636          * truncate after deleting a file, we may crash before the truncation
637          * and would have to "replay" the truncation later in
638          * UtilizationProfile.populateCache.  This would be more complex and
639          * the lastVLSN for the files would not be available.
640          *
641          * OTOH, if we crash after the truncation and before deleting a file,
642          * it is very likely that we will re-clean the zero utilization file
643          * and delete it later.  This will only cause a redundant truncation.
644          *
645          * This is done before locking the environment to minimize the interval
646          * during which the environment is locked and read-only processes are
647          * blocked.  We may unnecessarily truncate the VLSNIndex if we can't
648          * lock the environment, but that is a lesser priority.
649          *
650          * We intentionally do not honor the protected file ranges specified by
651          * DbBackups when truncating, because the VLSNIndex is protected only
652          * by the CBVLSN.  Luckily, this also means we do not need to
653          * synchronize on protectedFileRanges while truncating, and DbBackups
654          * will not be blocked by this potentially expensive operation.
655          */
656         Long[] unprotectedFilesArray = unprotectedFiles.toArray(new Long[0]);
657         for (int i = unprotectedFilesArray.length - 1; i >= 0; i -= 1) {
658             Long fileNum = unprotectedFilesArray[i];
659 
660             /*
661              * Truncate VLSNIndex for the highest numbered file with a VLSN. We
662              * search from high to low because some files may not contain a
663              * VLSN. If the truncate does have to do work, the VLSNIndex will
664              * ensure that the change is fsynced to disk. [#20702]
665              */
666             VLSN lastVlsn = fileSelector.getLastVLSN(fileNum);
667             if ((lastVlsn != null) && !lastVlsn.isNull()) {
668                 env.vlsnHeadTruncate(lastVlsn, fileNum);
669                 break;
670             }
671         }
672 
673         /*
674          * If we can't get an exclusive lock, then there are other processes
675          * with the environment open read-only and we can't delete any files.
676          */
677         final FileManager fileManager = env.getFileManager();
678         if (!fileManager.lockEnvironment(false, true)) {
679             LoggerUtils.traceAndLog(logger, env, Level.WARNING,
680                                     "Cleaner has " + safeToDeleteFiles.size() +
681                                     " files not deleted because of read-only" +
682                                     " processes.");
683             return;
684         }
685 
686         /* Be sure to release the environment lock in the finally block. */
687         try {
688             /* Synchronize while deleting files to block DbBackup.start. */
689             synchronized (protectedFileRanges) {
690 
691                 /* Intersect the protected ranges for active DbBackups. */
692                 if (!protectedFileRanges.isEmpty()) {
693                     final Long minRangeStart =
694                         Collections.min(protectedFileRanges);
695                     if (minRangeStart <= unprotectedFiles.first()) {
696                         /*
697                          * Simply return, no files can be deleted. Other
698                          * threads may asynchronously change the
699                          * protectedFileRanges list as a way of temporarily
700                          * imposing a curb on cleaning. For example,
701                          * DiskOrderedScan and DbBackup can increase the
702                          * protectedFileRange to protect a scan or backup, and
703                          * there is no restriction on how much the range can be
704                          * increased. While the calculation of the
705                          * unprotectedFiles Set considers the
706                          * protectedFileRange, check the protectedFileRange
707                          * again while under synchronization to see if there
708                          * have been any asynchronous changes since that
709                          * calculation, which might make have extended the
710                          * range and made it larger than the unprotectedFile
711                          * set.
712                          */
713                         return;
714                     }
715                     unprotectedFiles =
716                         unprotectedFiles.headSet(minRangeStart, false);
717                 }
718 
719                 /* Delete the unprotected files. */
720                 for (final Iterator<Long> iter = unprotectedFiles.iterator();
721                      iter.hasNext();) {
722                     final Long fileNum = iter.next();
723                     final boolean deleted;
724                     final String expungeLabel = expunge ? "delete" : "rename";
725                     final String expungedLabel = expungeLabel + "d";
726                     try {
727                         if (expunge) {
728                             deleted = fileManager.deleteFile(fileNum);
729                         } else {
730                             final File newFile = fileManager.renameFile(
731                                 fileNum, FileManager.DEL_SUFFIX,
732                                 useDeletedDir ? DELETED_SUBDIR : null);
733 
734                             if (newFile != null) {
735                                 newFile.setLastModified(
736                                     System.currentTimeMillis());
737                             }
738 
739                             deleted = (newFile != null);
740                         }
741                     } catch (IOException e) {
742                         throw new EnvironmentFailureException
743                             (env, EnvironmentFailureReason.LOG_WRITE,
744                              "Unable to " + expungeLabel + " " + fileNum, e);
745                     }
746                     if (deleted) {
747 
748                         /*
749                          * Deletion was successful.  Log a trace message for
750                          * debugging of log cleaning behavior.
751                          */
752                         LoggerUtils.traceAndLog(logger, env, Level.FINE,
753                                                 "Cleaner deleted file 0x" +
754                                                 Long.toHexString(fileNum));
755                     } else if (!fileManager.isFileValid(fileNum)) {
756 
757                         /*
758                          * Somehow the file was previously deleted.  This could
759                          * indicate an internal state error, and therefore we
760                          * output a trace message.  But we should not
761                          * repeatedly attempt to delete it, so we do remove it
762                          * from the profile below.
763                          */
764                         LoggerUtils.traceAndLog
765                             (logger, env, Level.SEVERE,
766                              "Cleaner deleteSafeToDeleteFiles Log file 0x" +
767                              Long.toHexString(fileNum) + " was previously " +
768                              expungedLabel + ".  State: " + fileSelector );
769                     } else {
770 
771                         /*
772                          * We will retry the deletion later if file still
773                          * exists.  The deletion could have failed on Windows
774                          * if the file was recently closed.  Remove the file
775                          * from unprotectedFiles. That way, we won't remove it
776                          * from the FileSelector's safe-to-delete set or the UP
777                          * below, and we will retry the file deletion later.
778                          */
779                         iter.remove();
780 
781                         LoggerUtils.traceAndLog
782                             (logger, env, Level.WARNING,
783                              "Cleaner deleteSafeToDeleteFiles Log file 0x" +
784                              Long.toHexString(fileNum) + " could not be " +
785                              expungedLabel + ". This operation will be " +
786                              "retried at the next checkpoint. State: " +
787                              fileSelector);
788                     }
789                 }
790             }
791         } finally {
792             fileManager.releaseExclusiveLock();
793         }
794 
795         /*
796          * Now unprotectedFiles contains only the files we deleted above.  We
797          * can update the UP (and FileSelector) here outside of the
798          * synchronization block and without the environment locked.  That way,
799          * DbBackups and read-only processes will not be blocked by the
800          * expensive UP operation.
801          *
802          * We do not retry if an error occurs deleting the UP database entries
803          * below.  Retrying (when file deletion fails) is intended only to
804          * solve a problem on Windows where deleting a log file isn't always
805          * possible immediately after closing it.
806          *
807          * Remove the file from the UP before removing it from the
808          * FileSelector's safe-to-delete set.  If we remove in the reverse
809          * order, it may be selected for cleaning.  Always remove the file from
810          * the safe-to-delete set (in a finally block) so that we don't attempt
811          * to delete the file again.
812          */
813         profile.removePerDbMetadata(
814             unprotectedFiles,
815             fileSelector.getCleanedDatabases(unprotectedFiles));
816 
817         for (Long fileNum : unprotectedFiles) {
818             try {
819                 profile.removePerFileMetadata(fileNum);
820             } finally {
821                 fileSelector.removeDeletedFile(fileNum, env.getMemoryBudget());
822             }
823             nCleanerDeletions.increment();
824         }
825 
826         /* Leave a clue for analyzing log file deletion problems. */
827         if (safeToDeleteFiles.size() > unprotectedFiles.size()) {
828             LoggerUtils.traceAndLog(
829                 logger, env, Level.WARNING,
830                 "Cleaner has " +
831                 (safeToDeleteFiles.size() - unprotectedFiles.size()) +
832                 " files not deleted because they are protected by DbBackup " +
833                 "or replication.");
834         }
835     }
836 
837     /**
838      * Adds a range of log files to be protected from deletion during a backup
839      * or similar procedures where log files must not be deleted.
840      *
841      * <p>This method is called automatically by the {@link
842      * com.sleepycat.je.util.DbBackup} utility and is provided here as a
843      * separate API for advanced applications that may implement a custom
844      * backup procedure.</p>
845      *
846      * <p><em>WARNING:</em> After calling this method, deletion of log files in
847      * the file range by the JE log cleaner will be disabled until {@link
848      * #removeProtectedFileRange} is called.  To prevent unbounded growth of
849      * disk usage, be sure to call {@link #removeProtectedFileRange} to
850      * re-enable log file deletion.</p>
851      *
852      * @param firstProtectedFile the number of the first file to be protected.
853      * The protected range is from this file number to the last (highest
854      * numbered) file in the log.
855      *
856      * @since 4.0
857      */
addProtectedFileRange(long firstProtectedFile)858     public void addProtectedFileRange(long firstProtectedFile) {
859         synchronized (protectedFileRanges) {
860             protectedFileRanges.add(firstProtectedFile);
861         }
862     }
863 
864     /**
865      * Removes a range of log files to be protected after calling {@link
866      * #addProtectedFileRange}.
867      *
868      * @param firstProtectedFile the value previously passed to {@link
869      * #addProtectedFileRange}.
870      *
871      * @throws EnvironmentFailureException if {@code firstProtectedFile} is not
872      * currently the start of a protected range.
873      *
874      * @since 4.0
875      */
removeProtectedFileRange(long firstProtectedFile)876     public void removeProtectedFileRange(long firstProtectedFile) {
877         synchronized (protectedFileRanges) {
878             if (!protectedFileRanges.remove(firstProtectedFile)) {
879                 throw EnvironmentFailureException.unexpectedState
880                     ("File range starting with 0x" +
881                      Long.toHexString(firstProtectedFile) +
882                      " is not currently protected");
883             }
884         }
885     }
886 
887     /**
888      * Returns a copy of the cleaned and processed files at the time a
889      * checkpoint starts.
890      *
891      * <p>If non-null is returned, the checkpoint should flush an extra level,
892      * and addCheckpointedFiles() should be called when the checkpoint is
893      * complete.</p>
894      */
getFilesAtCheckpointStart()895     public CheckpointStartCleanerState getFilesAtCheckpointStart()
896         throws DatabaseException {
897 
898         /* Pending LNs can prevent file deletion. */
899         processPending();
900 
901         return fileSelector.getFilesAtCheckpointStart();
902     }
903 
904     /**
905      * When a checkpoint is complete, update the files that were returned at
906      * the beginning of the checkpoint.
907      */
updateFilesAtCheckpointEnd(CheckpointStartCleanerState info)908     public void updateFilesAtCheckpointEnd(CheckpointStartCleanerState info)
909         throws DatabaseException {
910 
911         fileSelector.updateFilesAtCheckpointEnd(info);
912         deleteSafeToDeleteFiles();
913     }
914 
915     /**
916      * Add current backlog to backlogAlertList and check backlog growth.
917      * [#21111]
918      * <p>
919      * A SEVERE message is logged when the trailing average increases.  A
920      * growing backlog is normally due to an undersized cache, and the hope is
921      * that the application/user/admin will take action when the SEVERE message
922      * is seen.
923      * <p>
924      * Multiple cleaner threads may call this method concurrently, so multiple
925      * messages may be logged at around the same time.  This is considered to
926      * be acceptable.  This method is called only once for each file that is
927      * cleaned by FileProcessor, which limits the number of messages logged.
928      */
checkBacklogGrowth()929     void checkBacklogGrowth() {
930 
931         final int newBacklog = fileSelector.getBacklog();
932         final int oldBacklog;
933 
934         final boolean averagesAreValid;
935         final float oldAvg;
936         final float newAvg;
937 
938         /* Protect access to backlogAlertList. */
939         synchronized (backlogAlertList) {
940             oldBacklog = (backlogAlertList.size() > 0) ?
941                 backlogAlertList.peekLast() : 0;
942 
943             /*
944              * Averages are considered valid when we have required number of
945              * recent backlog values for the old and new average computations.
946              */
947             averagesAreValid =
948                 (backlogAlertList.size() >= BACKLOG_ALERT_COUNT);
949 
950             oldAvg = getAverage(backlogAlertList);
951 
952             /* Append new value and remove older value(s). */
953             backlogAlertList.addLast(newBacklog);
954             while (backlogAlertList.size() > BACKLOG_ALERT_COUNT) {
955                 backlogAlertList.removeFirst();
956             }
957 
958             newAvg = getAverage(backlogAlertList);
959         }
960 
961         /* Don't log when the current backlog is below the alert floor. */
962         if (newBacklog < BACKLOG_ALERT_FLOOR) {
963             return;
964         }
965 
966         /* Don't log when the backlog doesn't grow. */
967         if (newBacklog <= oldBacklog) {
968             return;
969         }
970 
971         /* Don't log unless averages are valid and increasing. */
972         if (!averagesAreValid || newAvg <= oldAvg) {
973             return;
974         }
975 
976         final String msg =String.format
977              ("Average cleaner backlog has grown from %.1f to %.1f. If the " +
978               "cleaner continues to be unable to make progress, the JE " +
979               "cache size and/or number of cleaner threads are probably too " +
980               "small. If this is not corrected, eventually all available " +
981               "disk space will be used.", oldAvg, newAvg);
982 
983         LoggerUtils.logMsg(logger, env, Level.SEVERE, msg);
984     }
985 
getAverage(Collection<Integer> integers)986     private static float getAverage(Collection<Integer> integers) {
987         float total = 0;
988         for (int i : integers) {
989             total += i;
990         }
991         return total / integers.size();
992     }
993 
994     /**
995      * If any LNs are pending, process them.  This method should be called
996      * often enough to prevent the pending LN set from growing too large.
997      */
processPending()998     void processPending()
999         throws DatabaseException {
1000 
1001         /*
1002          * This method is not synchronized because that would block cleaner
1003          * and checkpointer threads unnecessarily.  However, we do prevent
1004          * reentrancy, for two reasons:
1005          * 1. It is wasteful for two threads to process the same pending
1006          *    entries.
1007          * 2. Many threads calling getDb may increase the liklihood of
1008          *    livelock. [#20816]
1009          */
1010         if (!processPendingReentrancyGuard.compareAndSet(false, true)) {
1011             return;
1012         }
1013         try {
1014             DbTree dbMapTree = env.getDbTree();
1015 
1016             Map<Long, LNInfo> pendingLNs = fileSelector.getPendingLNs();
1017             if (pendingLNs != null) {
1018                 TreeLocation location = new TreeLocation();
1019 
1020                 for (Map.Entry<Long, LNInfo> entry : pendingLNs.entrySet()) {
1021                     long originalLsn = entry.getKey();
1022                     LNInfo info = entry.getValue();
1023                     DatabaseId dbId = info.getDbId();
1024                     DatabaseImpl db = dbMapTree.getDb(dbId, lockTimeout);
1025                     try {
1026                         byte[] key = info.getKey();
1027                         LN ln = info.getLN();
1028 
1029                         /* Evict before processing each entry. */
1030                         if (DO_CRITICAL_EVICTION) {
1031                             env.daemonEviction(true /*backgroundIO*/);
1032                         }
1033 
1034                         processPendingLN(originalLsn, ln, db, key, location);
1035                     } finally {
1036                         dbMapTree.releaseDb(db);
1037                     }
1038 
1039                     /* Sleep if background read/write limit was exceeded. */
1040                     env.sleepAfterBackgroundIO();
1041                 }
1042             }
1043 
1044             DatabaseId[] pendingDBs = fileSelector.getPendingDBs();
1045             if (pendingDBs != null) {
1046                 for (DatabaseId dbId : pendingDBs) {
1047                     DatabaseImpl db = dbMapTree.getDb(dbId, lockTimeout);
1048                     try {
1049                         if (db == null || db.isDeleteFinished()) {
1050                             fileSelector.removePendingDB(dbId);
1051                         }
1052                     } finally {
1053                         dbMapTree.releaseDb(db);
1054                     }
1055                 }
1056             }
1057         } finally {
1058             processPendingReentrancyGuard.set(false);
1059         }
1060     }
1061 
1062     /**
1063      * Processes a pending LN, getting the lock first to ensure that the
1064      * overhead of retries is mimimal.
1065      */
processPendingLN(long originalLsn, LN ln, DatabaseImpl db, byte[] key, TreeLocation location)1066     private void processPendingLN(long originalLsn,
1067                                   LN ln,
1068                                   DatabaseImpl db,
1069                                   byte[] key,
1070                                   TreeLocation location)
1071         throws DatabaseException {
1072 
1073         boolean parentFound = false;  // We found the parent BIN.
1074         boolean processedHere = true; // The LN was cleaned here.
1075         boolean lockDenied = false;   // The LN lock was denied.
1076         boolean obsolete = false;     // The LN is no longer in use.
1077         boolean completed = false;    // This method completed.
1078 
1079         BasicLocker locker = null;
1080         BIN bin = null;
1081         try {
1082             nPendingLNsProcessed.increment();
1083 
1084             /*
1085              * If the DB is gone, this LN is obsolete.  If delete cleanup is in
1086              * progress, put the DB into the DB pending set; this LN will be
1087              * declared deleted after the delete cleanup is finished.
1088              */
1089             if (db == null || db.isDeleted()) {
1090                 addPendingDB(db);
1091                 nLNsDead.increment();
1092                 obsolete = true;
1093                 completed = true;
1094                 return;
1095             }
1096 
1097             Tree tree = db.getTree();
1098             assert tree != null;
1099 
1100             /*
1101              * Get a non-blocking read lock on the original log LSN.  If this
1102              * fails, then the original LSN is still write-locked.  We may have
1103              * to lock again, if the LSN has changed in the BIN, but this
1104              * initial check prevents a Btree lookup in some cases.
1105              */
1106             locker = BasicLocker.createBasicLocker(env, false /*noWait*/);
1107 
1108             /* Don't allow this short-lived lock to be preempted/stolen. */
1109             locker.setPreemptable(false);
1110 
1111             LockResult lockRet = locker.nonBlockingLock(
1112                 originalLsn, LockType.READ, false /*jumpAheadOfWaiters*/, db);
1113 
1114             if (lockRet.getLockGrant() == LockGrantType.DENIED) {
1115                 /* Try again later. */
1116                 nPendingLNsLocked.increment();
1117                 lockDenied = true;
1118                 completed = true;
1119                 return;
1120             }
1121 
1122             /*
1123              * Search down to the bottom most level for the parent of this LN.
1124              */
1125             parentFound = tree.getParentBINForChildLN(
1126                 location, key, false /*splitsAllowed*/,
1127                 false /*blindDeltaOps*/, UPDATE_GENERATION);
1128 
1129             bin = location.bin;
1130             int index = location.index;
1131 
1132             if (!parentFound) {
1133                 nLNsDead.increment();
1134                 obsolete = true;
1135                 completed = true;
1136                 return;
1137             }
1138 
1139             /* Migrate an LN. */
1140             processedHere = false;
1141             migratePendingLN(
1142                 db, bin.getLsn(index), bin, index, originalLsn,
1143                 true /*backgroundIO*/, CLEAN_PENDING_LN);
1144             completed = true;
1145         } catch (DatabaseException DBE) {
1146             DBE.printStackTrace();
1147             LoggerUtils.traceAndLogException
1148                 (env, "com.sleepycat.je.cleaner.Cleaner",
1149                  "processLN", "Exception thrown: ", DBE);
1150             throw DBE;
1151         } finally {
1152             if (bin != null) {
1153                 bin.releaseLatch();
1154             }
1155 
1156             if (locker != null) {
1157                 locker.operationEnd();
1158             }
1159 
1160             /*
1161              * If migratePendingLN was not called above, remove the pending LN
1162              * and perform tracing in this method.
1163              */
1164             if (processedHere) {
1165                 if (completed && !lockDenied) {
1166                     fileSelector.removePendingLN(originalLsn);
1167                 }
1168                 logFine(CLEAN_PENDING_LN, ln, DbLsn.NULL_LSN,
1169                         completed, obsolete, false /*migrated*/);
1170             }
1171         }
1172     }
1173 
1174     /**
1175      * Migrate a pending LN in the given BIN entry, if it is not obsolete.  The
1176      * BIN must be latched on entry and is left latched by this method.
1177      */
migratePendingLN(DatabaseImpl db, long lsn, BIN bin, int index, long lockedPendingLsn, boolean backgroundIO, String cleanAction)1178     private void migratePendingLN(DatabaseImpl db,
1179                                   long lsn,
1180                                   BIN bin,
1181                                   int index,
1182                                   long lockedPendingLsn,
1183                                   boolean backgroundIO,
1184                                   String cleanAction)
1185         throws DatabaseException {
1186 
1187         /* Status variables are used to generate debug tracing info. */
1188         boolean obsolete = false;    // The LN is no longer in use.
1189         boolean migrated = false;    // The LN was in use and is migrated.
1190         boolean lockDenied = false;  // The LN lock was denied.
1191         boolean completed = false;   // This method completed.
1192         boolean clearTarget = false; // Node was non-resident when called.
1193 
1194         /*
1195          * If wasCleaned is false we don't count statistics unless we migrate
1196          * the LN.  This avoids double counting.
1197          */
1198         BasicLocker locker = null;
1199         LN ln = null;
1200 
1201         try {
1202             if (lsn == DbLsn.NULL_LSN) {
1203                 /* This node was never written, no need to migrate. */
1204                 completed = true;
1205                 return;
1206             }
1207 
1208             /*
1209              * Fetch the node, if necessary.  If it was not resident and it is
1210              * an evictable LN, we will clear it after we migrate it.
1211              */
1212             if (!bin.isEntryKnownDeleted(index)) {
1213                 ln = (LN) bin.getTarget(index);
1214                 if (ln == null) {
1215                     /* If fetchLN returns null, a deleted LN was cleaned.*/
1216                     ln = bin.fetchLN(index, CacheMode.EVICT_LN);
1217                     clearTarget = !db.getId().equals(DbTree.ID_DB_ID);
1218                 }
1219             }
1220 
1221             /* Don't migrate knownDeleted or deleted cleaned LNs.  */
1222             if (ln == null) {
1223                 nLNsDead.increment();
1224                 obsolete = true;
1225                 completed = true;
1226                 return;
1227             }
1228 
1229             /*
1230              * Get a non-blocking read lock on the LN.  A pending node is
1231              * already locked, but the original pending LSN may have changed.
1232              * We must lock the current LSN to guard against aborts.
1233              */
1234             if (lockedPendingLsn != lsn) {
1235                 locker = BasicLocker.createBasicLocker(env, false /*noWait*/);
1236                 /* Don't allow this short-lived lock to be preempted/stolen. */
1237                 locker.setPreemptable(false);
1238                 LockResult lockRet = locker.nonBlockingLock(
1239                     lsn, LockType.READ, false /*jumpAheadOfWaiters*/, db);
1240                 if (lockRet.getLockGrant() == LockGrantType.DENIED) {
1241 
1242                     /*
1243                      * LN is currently locked by another Locker, so we can't
1244                      * assume anything about the value of the LSN in the bin.
1245                      */
1246                     nLNsLocked.increment();
1247                     lockDenied = true;
1248                     completed = true;
1249                     return;
1250                 }
1251             }
1252 
1253             /* Don't migrate deleted LNs.  */
1254             if (ln.isDeleted()) {
1255                 bin.setKnownDeleted(index);
1256                 nLNsDead.increment();
1257                 obsolete = true;
1258                 completed = true;
1259                 return;
1260             }
1261 
1262             /*
1263              * Migrate the LN.
1264              *
1265              * Do not pass a locker, because there is no need to lock the new
1266              * LSN, as done for user operations.  Another locker cannot attempt
1267              * to lock the new LSN until we're done, because we release the
1268              * lock before we release the BIN latch.
1269              */
1270             final LN.LogResult logResult = ln.log(
1271                 env, db, bin.getKey(index), lsn, bin.getLastLoggedSize(index),
1272                 null /*locker*/, null /*writeLockInfo*/, backgroundIO,
1273                 getMigrationRepContext(ln));
1274             bin.updateEntry(index, logResult.newLsn, logResult.newSize);
1275             nLNsMigrated.increment();
1276             /* Lock new LSN on behalf of existing lockers. */
1277             CursorImpl.lockAfterLsnChange
1278                 (db, lsn, logResult.newLsn, locker /*excludeLocker*/);
1279             migrated = true;
1280             completed = true;
1281             return;
1282         } finally {
1283             if (completed && !lockDenied) {
1284                 fileSelector.removePendingLN(lockedPendingLsn);
1285             }
1286 
1287             /*
1288              * If the node was originally non-resident, evict it now so that we
1289              * don't create more work for the evictor and reduce the cache
1290              * memory available to the application.
1291              */
1292             if (clearTarget) {
1293                 bin.evictLN(index);
1294             }
1295 
1296             if (locker != null) {
1297                 locker.operationEnd();
1298             }
1299 
1300             logFine(cleanAction, ln, lsn, completed, obsolete, migrated);
1301         }
1302     }
1303 
1304     /**
1305      * Returns the ReplicationContext to use for migrating the given LN.  If
1306      * VLSNs are preserved in this Environment then the VLSN is logically part
1307      * of the data record, and LN.getVLSNSequence will return the VLSN, which
1308      * should be included in the migrated LN.
1309      */
getMigrationRepContext(LN ln)1310     static ReplicationContext getMigrationRepContext(LN ln) {
1311         long vlsnSeq = ln.getVLSNSequence();
1312         if (vlsnSeq <= 0) {
1313             return ReplicationContext.NO_REPLICATE;
1314         }
1315         return new ReplicationContext(new VLSN(vlsnSeq),
1316                                       false /*inReplicationStream*/);
1317     }
1318 
1319     /**
1320      * Adds the DB ID to the pending DB set if it is being deleted but deletion
1321      * is not yet complete.
1322      */
addPendingDB(DatabaseImpl db)1323     void addPendingDB(DatabaseImpl db) {
1324         if (db != null && db.isDeleted() && !db.isDeleteFinished()) {
1325             DatabaseId id = db.getId();
1326             if (fileSelector.addPendingDB(id)) {
1327                 LoggerUtils.logMsg(logger, env, Level.FINE,
1328                                    "CleanAddPendingDB " + id);
1329             }
1330         }
1331     }
1332 
1333     /**
1334      * Send trace messages to the java.util.logger. Don't rely on the logger
1335      * alone to conditionalize whether we send this message, we don't even want
1336      * to construct the message if the level is not enabled.
1337      */
logFine(String action, Node node, long logLsn, boolean completed, boolean obsolete, boolean dirtiedMigrated)1338     void logFine(String action,
1339                Node node,
1340                long logLsn,
1341                boolean completed,
1342                boolean obsolete,
1343                boolean dirtiedMigrated) {
1344 
1345         if (logger.isLoggable(Level.FINE)) {
1346             StringBuilder sb = new StringBuilder();
1347             sb.append(action);
1348             if (node instanceof IN) {
1349                 sb.append(" node=");
1350                 sb.append(((IN) node).getNodeId());
1351             }
1352             sb.append(" logLsn=");
1353             sb.append(DbLsn.getNoFormatString(logLsn));
1354             sb.append(" complete=").append(completed);
1355             sb.append(" obsolete=").append(obsolete);
1356             sb.append(" dirtiedOrMigrated=").append(dirtiedMigrated);
1357 
1358             LoggerUtils.logMsg(logger, env, Level.FINE, sb.toString());
1359         }
1360     }
1361 
1362     /**
1363      * Release resources and update memory budget. Should only be called
1364      * when this environment is closed and will never be accessed again.
1365      */
close()1366     public void close() {
1367         profile.close();
1368         tracker.close();
1369         fileSelector.close(env.getMemoryBudget());
1370     }
1371 }
1372