001/*
002 * Licensed to the Apache Software Foundation (ASF) under one
003 * or more contributor license agreements.  See the NOTICE file
004 * distributed with this work for additional information
005 * regarding copyright ownership.  The ASF licenses this file
006 * to you under the Apache License, Version 2.0 (the
007 * "License"); you may not use this file except in compliance
008 * with the License.  You may obtain a copy of the License at
009 *
010 *     http://www.apache.org/licenses/LICENSE-2.0
011 *
012 * Unless required by applicable law or agreed to in writing, software
013 * distributed under the License is distributed on an "AS IS" BASIS,
014 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
015 * See the License for the specific language governing permissions and
016 * limitations under the License.
017 */
018package org.apache.hadoop.hbase.mapreduce;
019
020import java.io.DataInput;
021import java.io.DataOutput;
022import java.io.EOFException;
023import java.io.FileNotFoundException;
024import java.io.IOException;
025import java.time.Instant;
026import java.util.ArrayList;
027import java.util.Collections;
028import java.util.List;
029import org.apache.hadoop.conf.Configuration;
030import org.apache.hadoop.fs.FileStatus;
031import org.apache.hadoop.fs.FileSystem;
032import org.apache.hadoop.fs.LocatedFileStatus;
033import org.apache.hadoop.fs.Path;
034import org.apache.hadoop.fs.RemoteIterator;
035import org.apache.hadoop.hbase.fs.HFileSystem;
036import org.apache.hadoop.hbase.regionserver.wal.WALHeaderEOFException;
037import org.apache.hadoop.hbase.util.LeaseNotRecoveredException;
038import org.apache.hadoop.hbase.wal.AbstractFSWALProvider;
039import org.apache.hadoop.hbase.wal.WAL;
040import org.apache.hadoop.hbase.wal.WAL.Entry;
041import org.apache.hadoop.hbase.wal.WALEdit;
042import org.apache.hadoop.hbase.wal.WALFactory;
043import org.apache.hadoop.hbase.wal.WALKey;
044import org.apache.hadoop.hbase.wal.WALStreamReader;
045import org.apache.hadoop.hdfs.DistributedFileSystem;
046import org.apache.hadoop.io.Writable;
047import org.apache.hadoop.mapreduce.InputFormat;
048import org.apache.hadoop.mapreduce.InputSplit;
049import org.apache.hadoop.mapreduce.JobContext;
050import org.apache.hadoop.mapreduce.RecordReader;
051import org.apache.hadoop.mapreduce.TaskAttemptContext;
052import org.apache.hadoop.mapreduce.lib.input.FileInputFormat;
053import org.apache.hadoop.mapreduce.security.TokenCache;
054import org.apache.hadoop.util.StringUtils;
055import org.apache.yetus.audience.InterfaceAudience;
056import org.slf4j.Logger;
057import org.slf4j.LoggerFactory;
058
059/**
060 * Simple {@link InputFormat} for {@link org.apache.hadoop.hbase.wal.WAL} files.
061 */
062@InterfaceAudience.Public
063public class WALInputFormat extends InputFormat<WALKey, WALEdit> {
064  private static final Logger LOG = LoggerFactory.getLogger(WALInputFormat.class);
065
066  public static final String START_TIME_KEY = "wal.start.time";
067  public static final String END_TIME_KEY = "wal.end.time";
068
069  /**
070   * {@link InputSplit} for {@link WAL} files. Each split represent exactly one log file.
071   */
072  public static class WALSplit extends InputSplit implements Writable {
073    private String logFileName;
074    private long fileSize;
075    private long startTime;
076    private long endTime;
077
078    /** for serialization */
079    public WALSplit() {
080    }
081
082    /**
083     * Represent an WALSplit, i.e. a single WAL file. Start- and EndTime are managed by the split,
084     * so that WAL files can be filtered before WALEdits are passed to the mapper(s).
085     */
086    public WALSplit(String logFileName, long fileSize, long startTime, long endTime) {
087      this.logFileName = logFileName;
088      this.fileSize = fileSize;
089      this.startTime = startTime;
090      this.endTime = endTime;
091    }
092
093    @Override
094    public long getLength() throws IOException, InterruptedException {
095      return fileSize;
096    }
097
098    @Override
099    public String[] getLocations() throws IOException, InterruptedException {
100      // TODO: Find the data node with the most blocks for this WAL?
101      return new String[] {};
102    }
103
104    public String getLogFileName() {
105      return logFileName;
106    }
107
108    public long getStartTime() {
109      return startTime;
110    }
111
112    public long getEndTime() {
113      return endTime;
114    }
115
116    @Override
117    public void readFields(DataInput in) throws IOException {
118      logFileName = in.readUTF();
119      fileSize = in.readLong();
120      startTime = in.readLong();
121      endTime = in.readLong();
122    }
123
124    @Override
125    public void write(DataOutput out) throws IOException {
126      out.writeUTF(logFileName);
127      out.writeLong(fileSize);
128      out.writeLong(startTime);
129      out.writeLong(endTime);
130    }
131
132    @Override
133    public String toString() {
134      return logFileName + " (" + startTime + ":" + endTime + ") length:" + fileSize;
135    }
136  }
137
138  /**
139   * {@link RecordReader} for an {@link WAL} file. Implementation shared with deprecated
140   * HLogInputFormat.
141   */
142  static abstract class WALRecordReader<K extends WALKey> extends RecordReader<K, WALEdit> {
143    private WALStreamReader reader = null;
144    // visible until we can remove the deprecated HLogInputFormat
145    Entry currentEntry = new Entry();
146    private long startTime;
147    private long endTime;
148    private Configuration conf;
149    private Path logFile;
150    private long currentPos;
151
152    @edu.umd.cs.findbugs.annotations.SuppressWarnings(value = "DCN_NULLPOINTER_EXCEPTION",
153        justification = "HDFS-4380")
154    private WALStreamReader openReader(Path path, long startPosition) throws IOException {
155      long retryInterval = 2000; // 2 sec
156      int maxAttempts = 30;
157      int attempt = 0;
158      Exception ee = null;
159      WALStreamReader reader = null;
160      while (reader == null && attempt++ < maxAttempts) {
161        try {
162          // Detect if this is a new file, if so get a new reader else
163          // reset the current reader so that we see the new data
164          reader =
165            WALFactory.createStreamReader(path.getFileSystem(conf), path, conf, startPosition);
166          return reader;
167        } catch (WALHeaderEOFException wheofe) {
168          // We hit EOF while reading the WAL header. A file that ever had an entry synced to it
169          // necessarily has a complete, readable header (a sync flushes the header too), so a
170          // header EOF means the file holds nothing recoverable right now. For a file that is not
171          // being actively written (a closed/archived WAL, or one left empty by a crashed
172          // RegionServer) the header never appears, so retrying only delays an inevitable skip.
173          // The one case a retry could help is a WAL still being written by the legacy
174          // (non-async) writer that has not yet flushed its header; but we skip that too.
175          LOG.warn("Got WALHeaderEOFException opening reader for {}, skipping empty WAL file.",
176            path, wheofe);
177          return null;
178        } catch (LeaseNotRecoveredException lnre) {
179          // HBASE-15019 the WAL was not closed due to some hiccup.
180          LOG.warn("Try to recover the WAL lease " + path, lnre);
181          AbstractFSWALProvider.recoverLease(conf, path);
182          reader = null;
183          ee = lnre;
184        } catch (NullPointerException npe) {
185          // Workaround for race condition in HDFS-4380
186          // which throws a NPE if we open a file before any data node has the most recent block
187          // Just sleep and retry. Will require re-reading compressed WALs for compressionContext.
188          LOG.warn("Got NPE opening reader, will retry.");
189          reader = null;
190          ee = npe;
191        }
192        if (reader == null) {
193          // sleep before next attempt
194          try {
195            Thread.sleep(retryInterval);
196          } catch (InterruptedException e) {
197            Thread.currentThread().interrupt();
198          }
199        }
200      }
201      throw new IOException("Could not open reader", ee);
202    }
203
204    @Override
205    public void initialize(InputSplit split, TaskAttemptContext context)
206      throws IOException, InterruptedException {
207      WALSplit hsplit = (WALSplit) split;
208      logFile = new Path(hsplit.getLogFileName());
209      conf = context.getConfiguration();
210      LOG.info("Opening {} for {}", logFile, split);
211      openReader(logFile);
212      this.startTime = hsplit.getStartTime();
213      this.endTime = hsplit.getEndTime();
214    }
215
216    private void openReader(Path path) throws IOException {
217      closeReader();
218      reader = openReader(path, currentPos > 0 ? currentPos : -1);
219      setCurrentPath(path);
220    }
221
222    private void setCurrentPath(Path path) {
223      this.logFile = path;
224    }
225
226    private void closeReader() throws IOException {
227      if (reader != null) {
228        reader.close();
229        reader = null;
230      }
231    }
232
233    @Override
234    public boolean nextKeyValue() throws IOException, InterruptedException {
235      if (reader == null) {
236        return false;
237      }
238      this.currentPos = reader.getPosition();
239      Entry temp;
240      long i = -1;
241      try {
242        do {
243          // skip older entries
244          try {
245            temp = reader.next(currentEntry);
246            i++;
247          } catch (EOFException x) {
248            LOG.warn("Corrupted entry detected. Ignoring the rest of the file."
249              + " (This is normal when a RegionServer crashed.)");
250            return false;
251          }
252        } while (temp != null && temp.getKey().getWriteTime() < startTime);
253
254        if (temp == null) {
255          if (i > 0) {
256            LOG.info("Skipped " + i + " entries.");
257          }
258          LOG.info("Reached end of file.");
259          return false;
260        } else if (i > 0) {
261          LOG.info("Skipped " + i + " entries, until ts: " + temp.getKey().getWriteTime() + ".");
262        }
263        boolean res = temp.getKey().getWriteTime() <= endTime;
264        if (!res) {
265          LOG.info(
266            "Reached ts: " + temp.getKey().getWriteTime() + " ignoring the rest of the file.");
267        }
268        return res;
269      } catch (IOException e) {
270        Path archivedLog = AbstractFSWALProvider.findArchivedLog(logFile, conf);
271        // archivedLog can be null if unable to locate in archiveDir.
272        if (archivedLog != null) {
273          openReader(archivedLog);
274          // Try call again in recursion
275          return nextKeyValue();
276        } else {
277          throw e;
278        }
279      }
280    }
281
282    @Override
283    public WALEdit getCurrentValue() throws IOException, InterruptedException {
284      return currentEntry.getEdit();
285    }
286
287    @Override
288    public float getProgress() throws IOException, InterruptedException {
289      // N/A depends on total number of entries, which is unknown
290      return 0;
291    }
292
293    @Override
294    public void close() throws IOException {
295      LOG.info("Closing reader");
296      if (reader != null) {
297        this.reader.close();
298      }
299    }
300  }
301
302  /**
303   * handler for non-deprecated WALKey version. fold into WALRecordReader once we no longer need to
304   * support HLogInputFormat.
305   */
306  static class WALKeyRecordReader extends WALRecordReader<WALKey> {
307    @Override
308    public WALKey getCurrentKey() throws IOException, InterruptedException {
309      return currentEntry.getKey();
310    }
311  }
312
313  @Override
314  public List<InputSplit> getSplits(JobContext context) throws IOException, InterruptedException {
315    return getSplits(context, START_TIME_KEY, END_TIME_KEY);
316  }
317
318  /**
319   * implementation shared with deprecated HLogInputFormat
320   */
321  List<InputSplit> getSplits(final JobContext context, final String startKey, final String endKey)
322    throws IOException, InterruptedException {
323    Configuration conf = context.getConfiguration();
324    boolean ignoreMissing = conf.getBoolean(WALPlayer.IGNORE_MISSING_FILES, false);
325    Path[] inputPaths = getInputPaths(conf);
326    // get delegation token for the filesystem
327    TokenCache.obtainTokensForNamenodes(context.getCredentials(), inputPaths, conf);
328    long startTime = conf.getLong(startKey, Long.MIN_VALUE);
329    long endTime = conf.getLong(endKey, Long.MAX_VALUE);
330
331    List<FileStatus> allFiles = new ArrayList<FileStatus>();
332    for (Path inputPath : inputPaths) {
333      FileSystem fs = inputPath.getFileSystem(conf);
334      try {
335        List<FileStatus> files = getFiles(fs, inputPath, startTime, endTime, conf);
336        allFiles.addAll(files);
337      } catch (FileNotFoundException e) {
338        if (ignoreMissing) {
339          LOG.warn("File " + inputPath + " is missing. Skipping it.");
340          continue;
341        }
342        throw e;
343      }
344    }
345
346    boolean ignoreEmptyFiles =
347      conf.getBoolean(WALPlayer.IGNORE_EMPTY_FILES, WALPlayer.DEFAULT_IGNORE_EMPTY_FILES);
348    List<InputSplit> splits = new ArrayList<InputSplit>(allFiles.size());
349    for (FileStatus file : allFiles) {
350      if (ignoreEmptyFiles && file.getLen() == 0) {
351        LOG.warn("Ignoring empty file: " + file.getPath());
352        continue;
353      }
354      splits.add(new WALSplit(file.getPath().toString(), file.getLen(), startTime, endTime));
355    }
356    return splits;
357  }
358
359  Path[] getInputPaths(Configuration conf) {
360    String inpDirs = conf.get(FileInputFormat.INPUT_DIR);
361    return StringUtils
362      .stringToPath(inpDirs.split(conf.get(WALPlayer.INPUT_FILES_SEPARATOR_KEY, ",")));
363  }
364
365  /**
366   * @param startTime Files created before this time are dropped only if confirmed closed before it.
367   *                  Files without a parseable timestamp in their name are always included.
368   * @param endTime   Files created after this time are dropped. Files without a parseable timestamp
369   *                  in their name are always included.
370   */
371  List<FileStatus> getFiles(FileSystem fs, Path dir, long startTime, long endTime,
372    Configuration conf) throws IOException {
373    List<FileStatus> result = new ArrayList<>();
374    LOG.debug("Scanning " + dir.toString() + " for WAL files");
375    RemoteIterator<LocatedFileStatus> iter = listLocatedFileStatus(fs, dir, conf);
376    if (!iter.hasNext()) {
377      return Collections.emptyList();
378    }
379    while (iter.hasNext()) {
380      LocatedFileStatus file = iter.next();
381      if (file.isDirectory()) {
382        // Recurse into sub directories
383        result.addAll(getFiles(fs, file.getPath(), startTime, endTime, conf));
384      } else {
385        addFile(result, fs, file, startTime, endTime);
386      }
387    }
388    // TODO: These results should be sorted? Results could be content of recovered.edits directory
389    // -- null padded increasing numeric -- or a WAL file w/ timestamp suffix or timestamp and
390    // then meta suffix. See AbstractFSWALProvider#WALStartTimeComparator
391    return result;
392  }
393
394  /**
395   * Whether the file is closed and its final modification time precedes {@code time}. Only a closed
396   * file has a reliable modification time, so an open file or a non-HDFS file always returns
397   * {@code false} (kept). When the file is confirmed closed, its status is re-fetched because the
398   * {@code lfs} from {@code listLocatedStatus} may carry a stale creation-time mtime from when the
399   * file was still open.
400   */
401  private static boolean isClosedBefore(FileSystem fs, LocatedFileStatus lfs, long time) {
402    if (lfs.getModificationTime() >= time) {
403      return false;
404    }
405    try {
406      FileSystem backing = fs instanceof HFileSystem ? ((HFileSystem) fs).getBackingFs() : fs;
407      if (
408        !(backing instanceof DistributedFileSystem)
409          || !((DistributedFileSystem) backing).isFileClosed(lfs.getPath())
410      ) {
411        return false;
412      }
413      FileStatus refreshed = fs.getFileStatus(lfs.getPath());
414      return refreshed.getModificationTime() < time;
415    } catch (IOException | UnsupportedOperationException e) {
416      LOG.debug("Could not confirm closure of {}, keeping it", lfs.getPath(), e);
417      return false;
418    }
419  }
420
421  static void addFile(List<FileStatus> result, FileSystem fs, LocatedFileStatus lfs, long startTime,
422    long endTime) {
423    long timestamp = AbstractFSWALProvider.getTimestamp(lfs.getPath().getName());
424    if (timestamp > 0) {
425      // The name carries the WAL's creation time, which only bounds its entries from below. A WAL
426      // stays open until it rolls, so one created before startTime can still hold entries in
427      // range and must not be dropped on the strength of its name alone.
428      if (timestamp > endTime) {
429        LOG.info("Skipped {}, created after endTime [{}/{}]", lfs.getPath(), endTime,
430          Instant.ofEpochMilli(endTime));
431        return;
432      }
433      if (timestamp < startTime && isClosedBefore(fs, lfs, startTime)) {
434        LOG.info("Skipped {}, closed before startTime [{}/{}]", lfs.getPath(), startTime,
435          Instant.ofEpochMilli(startTime));
436        return;
437      }
438      LOG.info("Found {}", lfs.getPath());
439      result.add(lfs);
440    } else {
441      // If no timestamp, add it regardless.
442      LOG.info("Found (no-timestamp!) {}", lfs);
443      result.add(lfs);
444    }
445  }
446
447  @Override
448  public RecordReader<WALKey, WALEdit> createRecordReader(InputSplit split,
449    TaskAttemptContext context) throws IOException, InterruptedException {
450    return new WALKeyRecordReader();
451  }
452
453  /**
454   * Attempts to return the {@link LocatedFileStatus} for the given directory. If the directory does
455   * not exist, it will check if the directory is an archived log file and try to find it
456   */
457  private static RemoteIterator<LocatedFileStatus> listLocatedFileStatus(FileSystem fs, Path dir,
458    Configuration conf) throws IOException {
459    try {
460      return fs.listLocatedStatus(dir);
461    } catch (FileNotFoundException e) {
462      if (AbstractFSWALProvider.isArchivedLogFile(dir)) {
463        throw e;
464      }
465
466      LOG.warn("Log file {} not found, trying to find it in archive directory.", dir);
467      Path archiveFile = AbstractFSWALProvider.findArchivedLog(dir, conf);
468      if (archiveFile == null) {
469        LOG.error("Did not find archive file for {}", dir);
470        throw e;
471      }
472
473      return fs.listLocatedStatus(archiveFile);
474    }
475  }
476}