View Javadoc

1   /**
2    *
3    * Licensed to the Apache Software Foundation (ASF) under one
4    * or more contributor license agreements.  See the NOTICE file
5    * distributed with this work for additional information
6    * regarding copyright ownership.  The ASF licenses this file
7    * to you under the Apache License, Version 2.0 (the
8    * "License"); you may not use this file except in compliance
9    * with the License.  You may obtain a copy of the License at
10   *
11   *     http://www.apache.org/licenses/LICENSE-2.0
12   *
13   * Unless required by applicable law or agreed to in writing, software
14   * distributed under the License is distributed on an "AS IS" BASIS,
15   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
16   * See the License for the specific language governing permissions and
17   * limitations under the License.
18   */
19  package org.apache.hadoop.hbase.replication.regionserver;
20  
21  import java.io.Closeable;
22  import java.io.FileNotFoundException;
23  import java.io.IOException;
24  import java.util.Iterator;
25  import java.util.NoSuchElementException;
26  import java.util.concurrent.PriorityBlockingQueue;
27  
28  import org.apache.commons.logging.Log;
29  import org.apache.commons.logging.LogFactory;
30  import org.apache.hadoop.conf.Configuration;
31  import org.apache.hadoop.fs.FileStatus;
32  import org.apache.hadoop.fs.FileSystem;
33  import org.apache.hadoop.fs.Path;
34  import org.apache.hadoop.hbase.HConstants;
35  import org.apache.hadoop.hbase.classification.InterfaceAudience;
36  import org.apache.hadoop.hbase.classification.InterfaceStability;
37  import org.apache.hadoop.hbase.regionserver.wal.ProtobufLogReader;
38  import org.apache.hadoop.hbase.util.CancelableProgressable;
39  import org.apache.hadoop.hbase.util.FSUtils;
40  import org.apache.hadoop.hbase.util.LeaseNotRecoveredException;
41  import org.apache.hadoop.hbase.wal.WAL.Entry;
42  import org.apache.hadoop.hbase.wal.WAL.Reader;
43  import org.apache.hadoop.hbase.wal.WALFactory;
44  import org.apache.hadoop.ipc.RemoteException;
45  
46  /**
47   * Streaming access to WAL entries. This class is given a queue of WAL {@link Path}, and continually
48   * iterates through all the WAL {@link Entry} in the queue. When it's done reading from a Path, it
49   * dequeues it and starts reading from the next.
50   */
51  @InterfaceAudience.Private
52  @InterfaceStability.Evolving
53  public class WALEntryStream implements Iterator<Entry>, Closeable, Iterable<Entry> {
54    private static final Log LOG = LogFactory.getLog(WALEntryStream.class);
55  
56    private Reader reader;
57    private Path currentPath;
58    // cache of next entry for hasNext()
59    private Entry currentEntry;
60    // position after reading current entry
61    private long currentPosition = 0;
62    private PriorityBlockingQueue<Path> logQueue;
63    private FileSystem fs;
64    private Configuration conf;
65    private MetricsSource metrics;
66  
67    /**
68     * Create an entry stream over the given queue
69     * @param logQueue the queue of WAL paths
70     * @param fs {@link FileSystem} to use to create {@link Reader} for this stream
71     * @param conf {@link Configuration} to use to create {@link Reader} for this stream
72     * @param metrics replication metrics
73     * @throws IOException
74     */
75    public WALEntryStream(PriorityBlockingQueue<Path> logQueue, FileSystem fs, Configuration conf,
76        MetricsSource metrics)
77        throws IOException {
78      this(logQueue, fs, conf, 0, metrics);
79    }
80  
81    /**
82     * Create an entry stream over the given queue at the given start position
83     * @param logQueue the queue of WAL paths
84     * @param fs {@link FileSystem} to use to create {@link Reader} for this stream
85     * @param conf {@link Configuration} to use to create {@link Reader} for this stream
86     * @param startPosition the position in the first WAL to start reading at
87     * @param metrics replication metrics
88     * @throws IOException
89     */
90    public WALEntryStream(PriorityBlockingQueue<Path> logQueue, FileSystem fs, Configuration conf,
91        long startPosition, MetricsSource metrics) throws IOException {
92      this.logQueue = logQueue;
93      this.fs = fs;
94      this.conf = conf;
95      this.currentPosition = startPosition;
96      this.metrics = metrics;
97    }
98  
99    /**
100    * @return true if there is another WAL {@link Entry}
101    * @throws WALEntryStreamRuntimeException if there was an Exception while reading
102    */
103   @Override
104   public boolean hasNext() {
105     if (currentEntry == null) {
106       try {
107         tryAdvanceEntry();
108       } catch (Exception e) {
109         throw new WALEntryStreamRuntimeException(e);
110       }
111     }
112     return currentEntry != null;
113   }
114 
115   /**
116    * @return the next WAL entry in this stream
117    * @throws WALEntryStreamRuntimeException if there was an IOException
118    * @throws NoSuchElementException if no more entries in the stream.
119    */
120   @Override
121   public Entry next() {
122     if (!hasNext()) throw new NoSuchElementException();
123     Entry save = currentEntry;
124     currentEntry = null; // gets reloaded by hasNext()
125     return save;
126   }
127 
128   /**
129    * Not supported.
130    */
131   @Override
132   public void remove() {
133     throw new UnsupportedOperationException();
134   }
135 
136   /**
137    * {@inheritDoc}
138    */
139   @Override
140   public void close() throws IOException {
141     closeReader();
142   }
143 
144   /**
145    * @return the iterator over WAL entries in the queue.
146    */
147   @Override
148   public Iterator<Entry> iterator() {
149     return this;
150   }
151 
152   /**
153    * @return the position of the last Entry returned by next()
154    */
155   public long getPosition() {
156     return currentPosition;
157   }
158 
159   /**
160    * @return the {@link Path} of the current WAL
161    */
162   public Path getCurrentPath() {
163     return currentPath;
164   }
165 
166   private String getCurrentPathStat() {
167     StringBuilder sb = new StringBuilder();
168     if (currentPath != null) {
169       sb.append("currently replicating from: ").append(currentPath).append(" at position: ")
170           .append(currentPosition).append("\n");
171     } else {
172       sb.append("no replication ongoing, waiting for new log");
173     }
174     return sb.toString();
175   }
176 
177   /**
178    * Should be called if the stream is to be reused (i.e. used again after hasNext() has returned
179    * false)
180    * @throws IOException
181    */
182   public void reset() throws IOException {
183     if (reader != null && currentPath != null) {
184       resetReader();
185     }
186   }
187 
188   private void setPosition(long position) {
189     currentPosition = position;
190   }
191 
192   private void setCurrentPath(Path path) {
193     this.currentPath = path;
194   }
195 
196   private void tryAdvanceEntry() throws IOException {
197     if (checkReader()) {
198       readNextEntryAndSetPosition();
199       if (currentEntry == null) { // no more entries in this log file - see if log was rolled
200         if (logQueue.size() > 1) { // log was rolled
201           // Before dequeueing, we should always get one more attempt at reading.
202           // This is in case more entries came in after we opened the reader,
203           // and a new log was enqueued while we were reading. See HBASE-6758
204           resetReader();
205           readNextEntryAndSetPosition();
206           if (currentEntry == null) {
207             if (checkAllBytesParsed()) { // now we're certain we're done with this log file
208               dequeueCurrentLog();
209               if (openNextLog()) {
210                 readNextEntryAndSetPosition();
211               }
212             }
213           }
214         } // no other logs, we've simply hit the end of the current open log. Do nothing
215       }
216     }
217     // do nothing if we don't have a WAL Reader (e.g. if there's no logs in queue)
218   }
219 
220   // HBASE-15984 check to see we have in fact parsed all data in a cleanly closed file
221   private boolean checkAllBytesParsed() throws IOException {
222     // -1 means the wal wasn't closed cleanly.
223     final long trailerSize = currentTrailerSize();
224     FileStatus stat = null;
225     try {
226       stat = fs.getFileStatus(this.currentPath);
227     } catch (IOException exception) {
228       LOG.warn("Couldn't get file length information about log " + this.currentPath + ", it "
229           + (trailerSize < 0 ? "was not" : "was") + " closed cleanly " + getCurrentPathStat());
230       metrics.incrUnknownFileLengthForClosedWAL();
231     }
232     if (stat != null) {
233       if (trailerSize < 0) {
234         if (currentPosition < stat.getLen()) {
235           final long skippedBytes = stat.getLen() - currentPosition;
236           if (LOG.isDebugEnabled()) {
237             LOG.debug("Reached the end of WAL file '" + currentPath
238                 + "'. It was not closed cleanly, so we did not parse " + skippedBytes
239                 + " bytes of data. This is normally ok.");
240           }
241           metrics.incrUncleanlyClosedWALs();
242           metrics.incrBytesSkippedInUncleanlyClosedWALs(skippedBytes);
243         }
244       } else if (currentPosition + trailerSize < stat.getLen()) {
245         LOG.warn("Processing end of WAL file '" + currentPath + "'. At position " + currentPosition
246             + ", which is too far away from reported file length " + stat.getLen()
247             + ". Restarting WAL reading (see HBASE-15983 for details). " + getCurrentPathStat());
248         setPosition(0);
249         resetReader();
250         metrics.incrRestartedWALReading();
251         metrics.incrRepeatedFileBytes(currentPosition);
252         return false;
253       }
254     }
255     if (LOG.isTraceEnabled()) {
256       LOG.trace("Reached the end of log " + this.currentPath + ", and the length of the file is "
257           + (stat == null ? "N/A" : stat.getLen()));
258     }
259     metrics.incrCompletedWAL();
260     return true;
261   }
262 
263   private void dequeueCurrentLog() throws IOException {
264     if (LOG.isDebugEnabled()) {
265       LOG.debug("Reached the end of log " + currentPath);
266     }
267     closeReader();
268     logQueue.remove();
269     setPosition(0);
270     metrics.decrSizeOfLogQueue();
271   }
272 
273   private void readNextEntryAndSetPosition() throws IOException {
274     Entry readEntry = reader.next();
275     long readerPos = reader.getPosition();
276     if (readEntry != null) {
277       metrics.incrLogEditsRead();
278       metrics.incrLogReadInBytes(readerPos - currentPosition);
279     }
280     currentEntry = readEntry; // could be null
281     setPosition(readerPos);
282   }
283 
284   private void closeReader() throws IOException {
285     if (reader != null) {
286       reader.close();
287       reader = null;
288     }
289   }
290 
291   // if we don't have a reader, open a reader on the next log
292   private boolean checkReader() throws IOException {
293     if (reader == null) {
294       return openNextLog();
295     }
296     return true;
297   }
298 
299   // open a reader on the next log in queue
300   private boolean openNextLog() throws IOException {
301     Path nextPath = logQueue.peek();
302     if (nextPath != null) {
303       openReader(nextPath);
304       if (reader != null) return true;
305     }
306     return false;
307   }
308 
309   private Path getArchivedLog(Path path) throws IOException {
310     Path rootDir = FSUtils.getRootDir(conf);
311     Path oldLogDir = new Path(rootDir, HConstants.HREGION_OLDLOGDIR_NAME);
312     Path archivedLogLocation = new Path(oldLogDir, path.getName());
313     if (fs.exists(archivedLogLocation)) {
314       LOG.info("Log " + path + " was moved to " + archivedLogLocation);
315       return archivedLogLocation;
316     } else {
317       LOG.error("Couldn't locate log: " + path);
318       return path;
319     }
320   }
321 
322   private void handleFileNotFound(Path path, FileNotFoundException fnfe) throws IOException {
323     // If the log was archived, continue reading from there
324     Path archivedLog = getArchivedLog(path);
325     if (!path.equals(archivedLog)) {
326       openReader(archivedLog);
327     } else {
328       throw fnfe;
329     }
330   }
331   private void openReader(Path path) throws IOException {
332     try {
333       // Detect if this is a new file, if so get a new reader else
334       // reset the current reader so that we see the new data
335       if (reader == null || !getCurrentPath().equals(path)) {
336         closeReader();
337         reader = WALFactory.createReader(fs, path, conf);
338         seek();
339         setCurrentPath(path);
340       } else {
341         resetReader();
342       }
343     } catch (FileNotFoundException fnfe) {
344       handleFileNotFound(path, fnfe);
345     }  catch (RemoteException re) {
346       IOException ioe = re.unwrapRemoteException(FileNotFoundException.class);
347       if (!(ioe instanceof FileNotFoundException)) throw ioe;
348       handleFileNotFound(path, (FileNotFoundException)ioe);
349     } catch (LeaseNotRecoveredException lnre) {
350       // HBASE-15019 the WAL was not closed due to some hiccup.
351       LOG.warn("Try to recover the WAL lease " + currentPath, lnre);
352       recoverLease(conf, currentPath);
353       reader = null;
354     } catch (NullPointerException npe) {
355       // Workaround for race condition in HDFS-4380
356       // which throws a NPE if we open a file before any data node has the most recent block
357       // Just sleep and retry. Will require re-reading compressed WALs for compressionContext.
358       LOG.warn("Got NPE opening reader, will retry.");
359       reader = null;
360     }
361   }
362 
363   // For HBASE-15019
364   private void recoverLease(final Configuration conf, final Path path) {
365     try {
366       final FileSystem dfs = FSUtils.getCurrentFileSystem(conf);
367       FSUtils fsUtils = FSUtils.getInstance(dfs, conf);
368       fsUtils.recoverFileLease(dfs, path, conf, new CancelableProgressable() {
369         @Override
370         public boolean progress() {
371           LOG.debug("recover WAL lease: " + path);
372           return true;
373         }
374       });
375     } catch (IOException e) {
376       LOG.warn("unable to recover lease for WAL: " + path, e);
377     }
378   }
379 
380   private void resetReader() throws IOException {
381     try {
382       reader.reset();
383       seek();
384     } catch (FileNotFoundException fnfe) {
385       // If the log was archived, continue reading from there
386       Path archivedLog = getArchivedLog(currentPath);
387       if (!currentPath.equals(archivedLog)) {
388         openReader(archivedLog);
389       } else {
390         throw fnfe;
391       }
392     } catch (NullPointerException npe) {
393       throw new IOException("NPE resetting reader, likely HDFS-4380", npe);
394     }
395   }
396 
397   private void seek() throws IOException {
398     if (currentPosition != 0) {
399       reader.seek(currentPosition);
400     }
401   }
402 
403   private long currentTrailerSize() {
404     long size = -1L;
405     if (reader instanceof ProtobufLogReader) {
406       final ProtobufLogReader pblr = (ProtobufLogReader) reader;
407       size = pblr.trailerSize();
408     }
409     return size;
410   }
411 
412   @InterfaceAudience.Private
413   public static class WALEntryStreamRuntimeException extends RuntimeException {
414     private static final long serialVersionUID = -6298201811259982568L;
415 
416     public WALEntryStreamRuntimeException(Exception e) {
417       super(e);
418     }
419   }
420 
421 }