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.log;
9 
10 import java.nio.ByteBuffer;
11 import java.text.NumberFormat;
12 import java.util.ArrayList;
13 import java.util.Comparator;
14 import java.util.Iterator;
15 import java.util.Map;
16 import java.util.TreeMap;
17 
18 import com.sleepycat.je.DatabaseException;
19 import com.sleepycat.je.config.EnvironmentParams;
20 import com.sleepycat.je.dbi.EnvironmentImpl;
21 import com.sleepycat.je.log.entry.LNLogEntry;
22 import com.sleepycat.je.utilint.DbLsn;
23 
24 /**
25  * The StatsFileReader generates stats about the log entries read, such as the
26  * count of each type of entry, the number of bytes, minimum and maximum sized
27  * log entry.
28  */
29 public class StatsFileReader extends DumpFileReader {
30 
31     private final Map<LogEntryType, EntryInfo> entryInfoMap;
32     private long totalLogBytes;
33     private long totalCount;
34 
35     /* Keep stats on log composition in terms of ckpt intervals. */
36     private final ArrayList<CheckpointCounter> ckptList;
37     private CheckpointCounter ckptCounter;
38     private long firstLsnRead;
39 
40     private long realTotalKeyCount = 0;
41     private long realTotalKeyBytes = 0;
42     private long realMinKeyBytes = 0;
43     private long realMaxKeyBytes = 0;
44     private long realTotalDataCount = 0;
45     private long realTotalDataBytes = 0;
46     private long realMinDataBytes = 0;
47     private long realMaxDataBytes = 0;
48 
49     /**
50      * Create this reader to start at a given LSN.
51      */
StatsFileReader(EnvironmentImpl envImpl, int readBufferSize, long startLsn, long finishLsn, long endOfFileLsn, String entryTypes, String txnIds, boolean verbose, boolean repEntriesOnly, boolean forwards)52     public StatsFileReader(EnvironmentImpl envImpl,
53                            int readBufferSize,
54                            long startLsn,
55                            long finishLsn,
56                            long endOfFileLsn,
57                            String entryTypes,
58                            String txnIds,
59                            boolean verbose,
60                            boolean repEntriesOnly,
61                            boolean forwards)
62         throws DatabaseException {
63 
64         super(envImpl, readBufferSize, startLsn, finishLsn, endOfFileLsn,
65               entryTypes, txnIds, verbose, repEntriesOnly, forwards);
66         entryInfoMap = new TreeMap<>(new LogEntryTypeComparator());
67 
68         totalLogBytes = 0;
69         totalCount = 0;
70 
71         ckptCounter = new CheckpointCounter();
72         ckptList = new ArrayList<CheckpointCounter>();
73         if (verbose) {
74             ckptList.add(ckptCounter);
75         }
76     }
77 
78     /**
79      * This reader collects stats about the log entry.
80      */
81     @Override
processEntry(ByteBuffer entryBuffer)82     protected boolean processEntry(ByteBuffer entryBuffer) {
83         byte currentType = currentEntryHeader.getType();
84         int itemSize = currentEntryHeader.getItemSize();
85         int headerSize = currentEntryHeader.getSize();
86 
87         /*
88          * Record various stats based on the entry header, then move the buffer
89          * forward to skip ahead.
90          */
91         LogEntryType lastEntryType = LogEntryType.findType(currentType);
92         int nextEntryPosition = entryBuffer.position() + itemSize;
93 
94         /*
95          * Get the info object for it, if this is the first time it's seen,
96          * create an info object and insert it.
97          */
98         EntryInfo info = entryInfoMap.get(lastEntryType);
99         if (info == null) {
100             info = new EntryInfo();
101             entryInfoMap.put(lastEntryType, info);
102         }
103 
104         /* Update counts. */
105         info.count++;
106         totalCount++;
107         if (currentEntryHeader.getProvisional() == Provisional.YES) {
108             info.provisionalCount++;
109         }
110         int size = itemSize + headerSize;
111         info.totalBytes += size;
112         info.headerBytes += headerSize;
113         totalLogBytes += size;
114 
115         if ((info.minBytes == 0) || (info.minBytes > size)) {
116             info.minBytes = size;
117         }
118         if (info.maxBytes < size) {
119             info.maxBytes = size;
120         }
121 
122         if (verbose) {
123             if (firstLsnRead == DbLsn.NULL_LSN) {
124                 firstLsnRead = getLastLsn();
125             }
126 
127             if (currentType == LogEntryType.LOG_CKPT_END.getTypeNum()) {
128                 /* Start counting a new interval. */
129                 ckptCounter.endCkptLsn = getLastLsn();
130                 ckptCounter = new CheckpointCounter();
131                 ckptList.add(ckptCounter);
132             } else {
133                 ckptCounter.increment(this, currentType);
134             }
135         }
136 
137         if (lastEntryType.isUserLNType()) {
138             /* Read the entry into the ByteBuffer. */
139             LNLogEntry<?> entry =
140                 (LNLogEntry<?>) lastEntryType.getSharedLogEntry();
141             entry.readEntry(envImpl, currentEntryHeader, entryBuffer);
142 
143             /*
144              * The getUnconvertedXxx methods are used because we don't have a
145              * DatabaseImpl for calling LNLogEntry.postFetchInit, and we can
146              * tolerate statistics that use the old duplicates format.
147              */
148             int keyLen = entry.getUnconvertedKeyLength();
149 
150             realTotalKeyBytes += keyLen;
151             realTotalKeyCount += 1;
152 
153             if ((realMinKeyBytes == 0) || (realMinKeyBytes > keyLen)) {
154                 realMinKeyBytes = keyLen;
155             }
156             if (realMaxKeyBytes < keyLen) {
157                 realMaxKeyBytes = keyLen;
158             }
159 
160             if (!entry.isDeleted()) {
161                 int dataLen = entry.getUnconvertedDataLength();
162 
163                 realTotalDataBytes += dataLen;
164                 realTotalDataCount += 1;
165 
166                 if ((realMinDataBytes == 0) || (realMinDataBytes > dataLen)) {
167                     realMinDataBytes = dataLen;
168                 }
169                 if (realMaxDataBytes < dataLen) {
170                     realMaxDataBytes = dataLen;
171                 }
172             }
173         }
174 
175         entryBuffer.position(nextEntryPosition);
176         return true;
177     }
178 
179     @Override
summarize(boolean csvFormat)180     public void summarize(boolean csvFormat) {
181         if (csvFormat) {
182             summarizeCSV();
183         } else {
184             summarizeText();
185         }
186     }
187 
188     class CheckpointInfoTextFormatter {
189         private NumberFormat form;
190 
CheckpointInfoTextFormatter()191         CheckpointInfoTextFormatter() {
192         }
193 
CheckpointInfoTextFormatter(NumberFormat form)194         CheckpointInfoTextFormatter(NumberFormat form) {
195             this.form = form;
196         }
197 
format(String value)198         String format(String value) {
199             return pad(value);
200         }
201 
format(int value)202         String format(int value) {
203             return pad(form.format(value));
204         }
205 
format(long value)206         String format(long value) {
207             return pad(form.format(value));
208         }
209     }
210 
211     class CheckpointInfoCSVFormatter
212         extends CheckpointInfoTextFormatter {
213 
CheckpointInfoCSVFormatter()214         CheckpointInfoCSVFormatter() {
215         }
216 
217         @Override
format(String value)218         String format(String value) {
219             return value + ",";
220         }
221 
222         @Override
format(int value)223         String format(int value) {
224             return value + ",";
225         }
226 
227         @Override
format(long value)228         String format(long value) {
229             return value + ",";
230         }
231     }
232 
summarizeCSV()233     private void summarizeCSV() {
234         Iterator<Map.Entry<LogEntryType,EntryInfo>> iter =
235             entryInfoMap.entrySet().iterator();
236 
237         NumberFormat form = NumberFormat.getIntegerInstance();
238         NumberFormat percentForm = NumberFormat.getInstance();
239         percentForm.setMaximumFractionDigits(1);
240         System.out.println
241             ("type,total count,provisional count,total bytes," +
242              "min bytes,max bytes,avg bytes,entries as % of log");
243 
244         while (iter.hasNext()) {
245             Map.Entry<LogEntryType, EntryInfo> m = iter.next();
246             EntryInfo info = m.getValue();
247             StringBuilder sb = new StringBuilder();
248             LogEntryType entryType = m.getKey();
249             sb.append(entryType.toString()).append(',');
250             sb.append(info.count).append(',');
251             sb.append(info.provisionalCount).append(',');
252             sb.append(info.totalBytes).append(',');
253             sb.append(info.minBytes).append(',');
254             sb.append(info.maxBytes).append(',');
255             sb.append(info.totalBytes / info.count).append(',');
256             double entryPercent =
257                 ((double) (info.totalBytes * 100) / totalLogBytes);
258             sb.append(entryPercent);
259             System.out.println(sb.toString());
260         }
261 
262         /* Print special line for key/data */
263         StringBuilder sb = new StringBuilder();
264         sb.append("key bytes,");
265         sb.append(realTotalKeyCount).append(',');
266         sb.append(",");
267         sb.append(realTotalKeyBytes).append(',');
268         sb.append(realMinKeyBytes).append(',');
269         sb.append(realMaxKeyBytes).append(',');
270         sb.append(realTotalKeyBytes / realTotalKeyCount).append(',');
271         sb.append(((double) (realTotalKeyBytes * 100) /
272                    totalLogBytes));
273         System.out.println(sb.toString());
274 
275         sb = new StringBuilder();
276         sb.append("data bytes,");
277         sb.append(realTotalDataCount).append(',');
278         sb.append(",");
279         sb.append(realTotalDataBytes).append(',');
280         sb.append(realMinDataBytes).append(',');
281         sb.append(realMaxDataBytes).append(',');
282         sb.append(realTotalDataBytes / realTotalDataCount).append(',');
283         sb.append((double) (realTotalDataBytes * 100) /
284                       totalLogBytes);
285         System.out.println(sb.toString());
286 
287         System.out.println("\nTotal bytes in portion of log read: " +
288                            form.format(totalLogBytes));
289         System.out.println("Total number of entries: " +
290                            form.format(totalCount));
291 
292         if (verbose) {
293             summarizeCheckpointInfo(new CheckpointInfoCSVFormatter());
294         }
295     }
296 
summarizeText()297     private void summarizeText() {
298         System.out.println("Log statistics:");
299         Iterator<Map.Entry<LogEntryType,EntryInfo>> iter =
300             entryInfoMap.entrySet().iterator();
301 
302         NumberFormat form = NumberFormat.getIntegerInstance();
303         NumberFormat percentForm = NumberFormat.getInstance();
304         percentForm.setMaximumFractionDigits(1);
305         System.out.println(pad("type") +
306                            pad("total") +
307                            pad("provisional") +
308                            pad("total") +
309                            pad("min") +
310                            pad("max") +
311                            pad("avg") +
312                            pad("entries"));
313 
314         System.out.println(pad("") +
315                            pad("count") +
316                            pad("count") +
317                            pad("bytes") +
318                            pad("bytes") +
319                            pad("bytes") +
320                            pad("bytes") +
321                            pad("as % of log"));
322 
323         while (iter.hasNext()) {
324             Map.Entry<LogEntryType, EntryInfo> m = iter.next();
325             EntryInfo info = m.getValue();
326             StringBuilder sb = new StringBuilder();
327             LogEntryType entryType = m.getKey();
328             sb.append(pad(entryType.toString()));
329             sb.append(pad(form.format(info.count)));
330             sb.append(pad(form.format(info.provisionalCount)));
331             sb.append(pad(form.format(info.totalBytes)));
332             sb.append(pad(form.format(info.minBytes)));
333             sb.append(pad(form.format(info.maxBytes)));
334             sb.append(pad(form.format(info.totalBytes / info.count)));
335             double entryPercent =
336                 ((double) (info.totalBytes * 100) / totalLogBytes);
337             sb.append(pad(percentForm.format(entryPercent)));
338             System.out.println(sb.toString());
339         }
340 
341         /* Print special line for key/data */
342         StringBuilder sb = new StringBuilder();
343         sb.append(pad("key bytes"));
344         sb.append(pad(form.format(realTotalKeyCount)));
345         sb.append(pad(""));
346         sb.append(pad(form.format(realTotalKeyBytes)));
347         sb.append(pad(form.format(realMinKeyBytes)));
348         sb.append(pad(form.format(realMaxKeyBytes)));
349         sb.append(pad(form.format(realTotalKeyBytes / realTotalKeyCount)));
350         String realSize = "(" +
351             percentForm.format((double) (realTotalKeyBytes * 100) /
352                                totalLogBytes) +
353             ")";
354         sb.append(pad(realSize));
355         System.out.println(sb.toString());
356 
357         sb = new StringBuilder();
358         sb.append(pad("data bytes"));
359         sb.append(pad(form.format(realTotalDataCount)));
360         sb.append(pad(""));
361         sb.append(pad(form.format(realTotalDataBytes)));
362         sb.append(pad(form.format(realMinDataBytes)));
363         sb.append(pad(form.format(realMaxDataBytes)));
364         sb.append(pad(form.format(realTotalDataBytes / realTotalDataCount)));
365         realSize = "(" +
366             percentForm.format((double) (realTotalDataBytes * 100) /
367                                totalLogBytes) +
368             ")";
369         sb.append(pad(realSize));
370         System.out.println(sb.toString());
371 
372         System.out.println("\nTotal bytes in portion of log read: " +
373                            form.format(totalLogBytes));
374         System.out.println("Total number of entries: " +
375                            form.format(totalCount));
376 
377         if (verbose) {
378             summarizeCheckpointInfo(new CheckpointInfoTextFormatter(form));
379         }
380     }
381 
pad(String result)382     private String pad(String result) {
383         int spaces = 20 - result.length();
384         StringBuilder sb = new StringBuilder();
385         for (int i = 0; i < spaces; i++) {
386             sb.append(" ");
387         }
388         sb.append(result);
389         return sb.toString();
390     }
391 
summarizeCheckpointInfo(CheckpointInfoTextFormatter f)392     private void summarizeCheckpointInfo(CheckpointInfoTextFormatter f) {
393         System.out.println("\nPer checkpoint interval info:");
394 
395         /*
396          * Print out checkpoint interval info.
397          * If the log looks like this:
398          *
399          * start of log
400          * ckpt1 start
401          * ckpt1 end
402          * ckpt2 start
403          * ckpt2 end
404          * end of log
405          *
406          * There are 3 ckpt intervals
407          * start of log->ckpt1 end
408          * ckpt1 end -> ckpt2 end
409          * ckpt2 end -> end of log
410          */
411         System.out.println
412             (f.format("lnTxn") +
413              f.format("ln") +
414              f.format("mapLNTxn") +
415              f.format("mapLN") +
416              f.format("end to end") +  // ckpt n-1 end -> ckpt n end
417              f.format("end to start") +// ckpt n-1 end -> ckpt n start
418              f.format("start to end") +// ckpt n start -> ckpt n end
419              f.format("maxLNReplay") +
420              f.format("ckptEnd"));
421 
422         long logFileMax =
423             envImpl.getConfigManager().getLong(EnvironmentParams.LOG_FILE_MAX);
424 
425         Iterator<CheckpointCounter> iter = ckptList.iterator();
426         CheckpointCounter prevCounter = null;
427         while (iter.hasNext()) {
428             CheckpointCounter c = iter.next();
429             StringBuilder sb = new StringBuilder();
430 
431             /* Entry type counts. */
432             int maxTxnLNs = c.preStartLNTxnCount + c.postStartLNTxnCount;
433             sb.append(f.format(maxTxnLNs));
434             int maxLNs = c.preStartLNCount + c.postStartLNCount;
435             sb.append(f.format(maxLNs));
436             sb.append(f.format(c.preStartMapLNTxnCount +
437                                c.postStartMapLNTxnCount));
438             sb.append(f.format(c.preStartMapLNCount +
439                                c.postStartMapLNCount));
440 
441             /* Checkpoint interval distance. */
442             long end = (c.endCkptLsn == DbLsn.NULL_LSN) ?
443                 getLastLsn() :
444                 c.endCkptLsn;
445             long endToEndDistance = 0;
446 
447             FileManager fileMgr = envImpl.getFileManager();
448             if (prevCounter == null) {
449                 endToEndDistance = DbLsn.getWithCleaningDistance(
450                     end, firstLsnRead, logFileMax, fileMgr);
451             } else {
452                 endToEndDistance = DbLsn.getWithCleaningDistance(
453                     end, prevCounter.endCkptLsn, logFileMax, fileMgr);
454             }
455             sb.append(f.format(endToEndDistance));
456 
457             /*
458              * Interval between last checkpoint end and this checkpoint start.
459              */
460             long start = (c.startCkptLsn == DbLsn.NULL_LSN) ? getLastLsn() :
461                 c.startCkptLsn;
462             long endToStartDistance = 0;
463 
464             if (prevCounter == null) {
465                 endToStartDistance = DbLsn.getWithCleaningDistance(
466                     start, firstLsnRead, logFileMax, fileMgr);
467             } else {
468                 endToStartDistance = DbLsn.getWithCleaningDistance(
469                     start, prevCounter.endCkptLsn, logFileMax, fileMgr);
470             }
471             sb.append(f.format(endToStartDistance));
472 
473             /*
474              * Interval between ckpt start and ckpt end.
475              */
476             long startToEndDistance = 0;
477             if ((c.startCkptLsn != DbLsn.NULL_LSN)  &&
478                 (c.endCkptLsn != DbLsn.NULL_LSN)) {
479                 startToEndDistance = DbLsn.getWithCleaningDistance(
480                     c.endCkptLsn, c.startCkptLsn, logFileMax, fileMgr);
481             }
482             sb.append(f.format(startToEndDistance));
483 
484             /*
485              * The maximum number of LNs to replay includes the portion of LNs
486              * from checkpoint start to checkpoint end of the previous
487              * interval.
488              */
489             int maxReplay = maxLNs + maxTxnLNs;
490             if (prevCounter != null) {
491                 maxReplay += prevCounter.postStartLNTxnCount;
492                 maxReplay += prevCounter.postStartLNCount;
493             }
494             sb.append(f.format(maxReplay));
495 
496             if (c.endCkptLsn == DbLsn.NULL_LSN) {
497                 sb.append("   ").append(DbLsn.getNoFormatString(getLastLsn()));
498             } else {
499                 sb.append("   ").append(DbLsn.getNoFormatString(c.endCkptLsn));
500             }
501 
502             System.out.println(sb.toString());
503             prevCounter = c;
504         }
505     }
506 
507     static class EntryInfo {
508         public int count;
509         public int provisionalCount;
510         public long totalBytes;
511         public int headerBytes;
512         public int minBytes;
513         public int maxBytes;
514 
EntryInfo()515         EntryInfo() {
516             count = 0;
517             provisionalCount = 0;
518             totalBytes = 0;
519             headerBytes = 0;
520             minBytes = 0;
521             maxBytes = 0;
522         }
523     }
524 
525     static class LogEntryTypeComparator implements Comparator<LogEntryType> {
compare(LogEntryType o1, LogEntryType o2)526         public int compare(LogEntryType o1, LogEntryType o2) {
527             if (o1 == null) {
528                 return -1;
529             }
530 
531             if (o2 == null) {
532                 return 1;
533             }
534 
535             Byte t1 = Byte.valueOf(o1.getTypeNum());
536             Byte t2 = Byte.valueOf(o2.getTypeNum());
537             return t1.compareTo(t2);
538         }
539     }
540 
541     /*
542      * Accumulate the count of items from checkpoint end->checkpoint end.
543      */
544     static class CheckpointCounter {
545         public long startCkptLsn = DbLsn.NULL_LSN;
546         public long endCkptLsn = DbLsn.NULL_LSN;
547         public int preStartLNTxnCount;
548         public int preStartLNCount;
549         public int preStartMapLNTxnCount;
550         public int preStartMapLNCount;
551         public int postStartLNTxnCount;
552         public int postStartLNCount;
553         public int postStartMapLNTxnCount;
554         public int postStartMapLNCount;
555 
increment(FileReader reader, byte currentEntryTypeNum)556         public void increment(FileReader reader,  byte currentEntryTypeNum) {
557             LogEntryType entryType =
558                 LogEntryType.findType(currentEntryTypeNum);
559 
560             if (entryType == LogEntryType.LOG_CKPT_START) {
561                 startCkptLsn = reader.getLastLsn();
562             } else if (entryType.isUserLNType()) {
563                 if (entryType.isTransactional()) {
564                     if (startCkptLsn == DbLsn.NULL_LSN) {
565                         preStartLNTxnCount++;
566                     } else {
567                         postStartLNTxnCount++;
568                     }
569                 } else {
570                     if (startCkptLsn == DbLsn.NULL_LSN) {
571                         preStartLNCount++;
572                     } else {
573                         postStartLNCount++;
574                     }
575                 }
576             } else if (entryType == LogEntryType.LOG_MAPLN) {
577                 if (startCkptLsn == DbLsn.NULL_LSN) {
578                     preStartMapLNCount++;
579                 } else {
580                     postStartMapLNCount++;
581                 }
582             } else if (entryType == LogEntryType.LOG_MAPLN_TRANSACTIONAL) {
583                 if (startCkptLsn == DbLsn.NULL_LSN) {
584                     preStartMapLNTxnCount++;
585                 } else {
586                     postStartMapLNTxnCount++;
587                 }
588             }
589         }
590     }
591 }
592