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