HBASE-26787 TestRegionReplicaReplicationError should inject error in replicateToRepli...
[hbase.git] / src / main / asciidoc / _chapters / troubleshooting.adoc
blobeb340bf31df8d20e42ec8c8f17b14851d977ed0c
1 ////
2 /**
3  *
4  * Licensed to the Apache Software Foundation (ASF) under one
5  * or more contributor license agreements.  See the NOTICE file
6  * distributed with this work for additional information
7  * regarding copyright ownership.  The ASF licenses this file
8  * to you under the Apache License, Version 2.0 (the
9  * "License"); you may not use this file except in compliance
10  * with the License.  You may obtain a copy of the License at
11  *
12  *     http://www.apache.org/licenses/LICENSE-2.0
13  *
14  * Unless required by applicable law or agreed to in writing, software
15  * distributed under the License is distributed on an "AS IS" BASIS,
16  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
17  * See the License for the specific language governing permissions and
18  * limitations under the License.
19  */
20 ////
22 [[trouble]]
23 = Troubleshooting and Debugging Apache HBase
24 :doctype: book
25 :numbered:
26 :toc: left
27 :icons: font
28 :experimental:
30 [[trouble.general]]
31 == General Guidelines
33 Always start with the master log (TODO: Which lines?). Normally it's just printing the same lines over and over again.
34 If not, then there's an issue.
35 Google should return some hits for those exceptions you're seeing.
37 An error rarely comes alone in Apache HBase, usually when something gets screwed up what will follow may be hundreds of exceptions and stack traces coming from all over the place.
38 The best way to approach this type of problem is to walk the log up to where it all began, for example one trick with RegionServers is that they will print some metrics when aborting so grepping for _Dump_ should get you around the start of the problem.
40 RegionServer suicides are 'normal', as this is what they do when something goes wrong.
41 For example, if ulimit and max transfer threads (the two most important initial settings, see <<ulimit>> and <<dfs.datanode.max.transfer.threads>>) aren't changed, it will make it impossible at some point for DataNodes to create new threads that from the HBase point of view is seen as if HDFS was gone.
42 Think about what would happen if your MySQL database was suddenly unable to access files on your local file system, well it's the same with HBase and HDFS.
43 Another very common reason to see RegionServers committing seppuku is when they enter prolonged garbage collection pauses that last longer than the default ZooKeeper session timeout.
44 For more information on GC pauses, see the link:https://blog.cloudera.com/blog/2011/02/avoiding-full-gcs-in-hbase-with-memstore-local-allocation-buffers-part-1/[3 part blog post] by Todd Lipcon and <<gcpause>> above.
46 [[trouble.log]]
47 == Logs
49 The key process logs are as follows... (replace <user> with the user that started the service, and <hostname> for the machine name)
51 NameNode: _$HADOOP_HOME/logs/hadoop-<user>-namenode-<hostname>.log_
53 DataNode: _$HADOOP_HOME/logs/hadoop-<user>-datanode-<hostname>.log_
55 JobTracker: _$HADOOP_HOME/logs/hadoop-<user>-jobtracker-<hostname>.log_
57 TaskTracker: _$HADOOP_HOME/logs/hadoop-<user>-tasktracker-<hostname>.log_
59 HMaster: _$HBASE_HOME/logs/hbase-<user>-master-<hostname>.log_
61 RegionServer: _$HBASE_HOME/logs/hbase-<user>-regionserver-<hostname>.log_
63 ZooKeeper: _TODO_
65 [[trouble.log.locations]]
66 === Log Locations
68 For stand-alone deployments the logs are obviously going to be on a single machine, however this is a development configuration only.
69 Production deployments need to run on a cluster.
71 [[trouble.log.locations.namenode]]
72 ==== NameNode
74 The NameNode log is on the NameNode server.
75 The HBase Master is typically run on the NameNode server, and well as ZooKeeper.
77 For smaller clusters the JobTracker/ResourceManager is typically run on the NameNode server as well.
79 [[trouble.log.locations.datanode]]
80 ==== DataNode
82 Each DataNode server will have a DataNode log for HDFS, as well as a RegionServer log for HBase.
84 Additionally, each DataNode server will also have a TaskTracker/NodeManager log for MapReduce task execution.
86 [[trouble.log.levels]]
87 === Log Levels
89 [[rpc.logging]]
90 ==== Enabling RPC-level logging
92 Enabling the RPC-level logging on a RegionServer can often give insight on timings at the server.
93 Once enabled, the amount of log spewed is voluminous.
94 It is not recommended that you leave this logging on for more than short bursts of time.
95 To enable RPC-level logging, browse to the RegionServer UI and click on _Log Level_.
96 Set the log level to `DEBUG` for the package `org.apache.hadoop.ipc` (That's right, for `hadoop.ipc`, NOT, `hbase.ipc`). Then tail the RegionServers log.
97 Analyze.
99 To disable, set the logging level back to `INFO` level.
101 [[trouble.log.gc]]
102 === JVM Garbage Collection Logs
104 [NOTE]
105 ====
106 All example Garbage Collection logs in this section are based on Java 8 output. The introduction of Unified Logging in Java 9 and newer will result in very different looking logs.
107 ====
109 HBase is memory intensive, and using the default GC you can see long pauses in all threads including the _Juliet Pause_ aka "GC of Death". To help debug this or confirm this is happening GC logging can be turned on in the Java virtual machine.
111 To enable, in _hbase-env.sh_, uncomment one of the below lines :
113 [source,bourne]
114 ----
116 # This enables basic gc logging to the .out file.
117 # export SERVER_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps"
119 # This enables basic gc logging to its own file.
120 # export SERVER_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<FILE-PATH>"
122 # This enables basic GC logging to its own file with automatic log rolling. Only applies to jdk 1.6.0_34+ and 1.7.0_2+.
123 # export SERVER_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<FILE-PATH> -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=1 -XX:GCLogFileSize=512M"
125 # If <FILE-PATH> is not replaced, the log file(.gc) would be generated in the HBASE_LOG_DIR.
126 ----
128 At this point you should see logs like so:
130 [source]
131 ----
133 64898.952: [GC [1 CMS-initial-mark: 2811538K(3055704K)] 2812179K(3061272K), 0.0007360 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
134 64898.953: [CMS-concurrent-mark-start]
135 64898.971: [GC 64898.971: [ParNew: 5567K->576K(5568K), 0.0101110 secs] 2817105K->2812715K(3061272K), 0.0102200 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
136 ----
138 In this section, the first line indicates a 0.0007360 second pause for the CMS to initially mark.
139 This pauses the entire VM, all threads for that period of time.
141 The third line indicates a "minor GC", which pauses the VM for 0.0101110 seconds - aka 10 milliseconds.
142 It has reduced the "ParNew" from about 5.5m to 576k.
143 Later on in this cycle we see:
145 [source]
146 ----
148 64901.445: [CMS-concurrent-mark: 1.542/2.492 secs] [Times: user=10.49 sys=0.33, real=2.49 secs]
149 64901.445: [CMS-concurrent-preclean-start]
150 64901.453: [GC 64901.453: [ParNew: 5505K->573K(5568K), 0.0062440 secs] 2868746K->2864292K(3061272K), 0.0063360 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
151 64901.476: [GC 64901.476: [ParNew: 5563K->575K(5568K), 0.0072510 secs] 2869283K->2864837K(3061272K), 0.0073320 secs] [Times: user=0.05 sys=0.01, real=0.01 secs]
152 64901.500: [GC 64901.500: [ParNew: 5517K->573K(5568K), 0.0120390 secs] 2869780K->2865267K(3061272K), 0.0121150 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
153 64901.529: [GC 64901.529: [ParNew: 5507K->569K(5568K), 0.0086240 secs] 2870200K->2865742K(3061272K), 0.0087180 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
154 64901.554: [GC 64901.555: [ParNew: 5516K->575K(5568K), 0.0107130 secs] 2870689K->2866291K(3061272K), 0.0107820 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
155 64901.578: [CMS-concurrent-preclean: 0.070/0.133 secs] [Times: user=0.48 sys=0.01, real=0.14 secs]
156 64901.578: [CMS-concurrent-abortable-preclean-start]
157 64901.584: [GC 64901.584: [ParNew: 5504K->571K(5568K), 0.0087270 secs] 2871220K->2866830K(3061272K), 0.0088220 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
158 64901.609: [GC 64901.609: [ParNew: 5512K->569K(5568K), 0.0063370 secs] 2871771K->2867322K(3061272K), 0.0064230 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
159 64901.615: [CMS-concurrent-abortable-preclean: 0.007/0.037 secs] [Times: user=0.13 sys=0.00, real=0.03 secs]
160 64901.616: [GC[YG occupancy: 645 K (5568 K)]64901.616: [Rescan (parallel) , 0.0020210 secs]64901.618: [weak refs processing, 0.0027950 secs] [1 CMS-remark: 2866753K(3055704K)] 2867399K(3061272K), 0.0049380 secs] [Times: user=0.00 sys=0.01, real=0.01 secs]
161 64901.621: [CMS-concurrent-sweep-start]
162 ----
164 The first line indicates that the CMS concurrent mark (finding garbage) has taken 2.4 seconds.
165 But this is a _concurrent_ 2.4 seconds, Java has not been paused at any point in time.
167 There are a few more minor GCs, then there is a pause at the 2nd last line:
168 [source]
169 ----
171 64901.616: [GC[YG occupancy: 645 K (5568 K)]64901.616: [Rescan (parallel) , 0.0020210 secs]64901.618: [weak refs processing, 0.0027950 secs] [1 CMS-remark: 2866753K(3055704K)] 2867399K(3061272K), 0.0049380 secs] [Times: user=0.00 sys=0.01, real=0.01 secs]
172 ----
174 The pause here is 0.0049380 seconds (aka 4.9 milliseconds) to 'remark' the heap.
176 At this point the sweep starts, and you can watch the heap size go down:
178 [source]
179 ----
181 64901.637: [GC 64901.637: [ParNew: 5501K->569K(5568K), 0.0097350 secs] 2871958K->2867441K(3061272K), 0.0098370 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
182 ...  lines removed ...
183 64904.936: [GC 64904.936: [ParNew: 5532K->568K(5568K), 0.0070720 secs] 1365024K->1360689K(3061272K), 0.0071930 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
184 64904.953: [CMS-concurrent-sweep: 2.030/3.332 secs] [Times: user=9.57 sys=0.26, real=3.33 secs]
185 ----
187 At this point, the CMS sweep took 3.332 seconds, and heap went from about ~ 2.8 GB to 1.3 GB (approximate).
189 The key points here is to keep all these pauses low.
190 CMS pauses are always low, but if your ParNew starts growing, you can see minor GC pauses approach 100ms, exceed 100ms and hit as high at 400ms.
192 This can be due to the size of the ParNew, which should be relatively small.
193 If your ParNew is very large after running HBase for a while, in one example a ParNew was about 150MB, then you might have to constrain the size of ParNew (The larger it is, the longer the collections take but if it's too small, objects are promoted to old gen too quickly). In the below we constrain new gen size to 64m.
195 Add the below line in _hbase-env.sh_:
196 [source,bourne]
197 ----
199 export SERVER_GC_OPTS="$SERVER_GC_OPTS -XX:NewSize=64m -XX:MaxNewSize=64m"
200 ----
202 Similarly, to enable GC logging for client processes, uncomment one of the below lines in _hbase-env.sh_:
204 [source,bourne]
205 ----
207 # This enables basic gc logging to the .out file.
208 # export CLIENT_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps"
210 # This enables basic gc logging to its own file.
211 # export CLIENT_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<FILE-PATH>"
213 # This enables basic GC logging to its own file with automatic log rolling. Only applies to jdk 1.6.0_34+ and 1.7.0_2+.
214 # export CLIENT_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<FILE-PATH> -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=1 -XX:GCLogFileSize=512M"
216 # If <FILE-PATH> is not replaced, the log file(.gc) would be generated in the HBASE_LOG_DIR .
217 ----
219 For more information on GC pauses, see the link:https://blog.cloudera.com/blog/2011/02/avoiding-full-gcs-in-hbase-with-memstore-local-allocation-buffers-part-1/[3 part blog post] by Todd Lipcon and <<gcpause>> above.
221 [[trouble.resources]]
222 == Resources
224 [[trouble.resources.lists]]
225 === Mailing Lists
227 Ask a question on the link:https://hbase.apache.org/mail-lists.html[Apache HBase mailing lists].
228 The 'dev' mailing list is aimed at the community of developers actually building Apache HBase and for features currently under development, and 'user' is generally used for questions on released versions of Apache HBase.
229 Before going to the mailing list, make sure your question has not already been answered by searching the mailing list
230 archives first. For those who prefer to communicate in Chinese, they can use the 'user-zh' mailing list instead of the
231 'user' list.
232 Take some time crafting your question.
233 See link:http://www.mikeash.com/getting_answers.html[Getting Answers] for ideas on crafting good questions.
234 A quality question that includes all context and exhibits evidence the author has tried to find answers in the manual and out on lists is more likely to get a prompt response.
236 [[trouble.resources.slack]]
237 === Slack
238 See  http://apache-hbase.slack.com Channel on Slack
240 [[trouble.resources.irc]]
241 === IRC
242 (You will probably get a more prompt response on the Slack channel)
244 #hbase on irc.freenode.net
246 [[trouble.resources.jira]]
247 === JIRA
249 link:https://issues.apache.org/jira/browse/HBASE[JIRA] is also really helpful when looking for Hadoop/HBase-specific issues.
251 [[trouble.tools]]
252 == Tools
254 [[trouble.tools.builtin]]
255 === Builtin Tools
257 [[trouble.tools.builtin.webmaster]]
258 ==== Master Web Interface
260 The Master starts a web-interface on port 16010 by default.
262 The Master web UI lists created tables and their definition (e.g., ColumnFamilies, blocksize, etc.). Additionally, the available RegionServers in the cluster are listed along with selected high-level metrics (requests, number of regions, usedHeap, maxHeap). The Master web UI allows navigation to each RegionServer's web UI.
264 [[trouble.tools.builtin.webregion]]
265 ==== RegionServer Web Interface
267 RegionServers starts a web-interface on port 16030 by default.
269 The RegionServer web UI lists online regions and their start/end keys, as well as point-in-time RegionServer metrics (requests, regions, storeFileIndexSize, compactionQueueSize, etc.).
271 See <<hbase_metrics>> for more information in metric definitions.
273 [[trouble.tools.builtin.zkcli]]
274 ==== zkcli
276 `zkcli` is a very useful tool for investigating ZooKeeper-related issues.
277 To invoke:
278 [source,bourne]
279 ----
280 ./hbase zkcli -server host:port <cmd> <args>
281 ----
283 The commands (and arguments) are:
285 [source]
286 ----
287   connect host:port
288   get path [watch]
289   ls path [watch]
290   set path data [version]
291   delquota [-n|-b] path
292   quit
293   printwatches on|off
294   create [-s] [-e] path data acl
295   stat path [watch]
296   close
297   ls2 path [watch]
298   history
299   listquota path
300   setAcl path acl
301   getAcl path
302   sync path
303   redo cmdno
304   addauth scheme auth
305   delete path [version]
306   setquota -n|-b val path
307 ----
309 [[trouble.tools.maintenancemode]]
310 ==== Maintenance Mode
311 If the cluster has gotten stuck in some state and the standard techniques aren't making progress,
312  it is possible to restart the cluster in "maintenance mode." This mode features drastically
313  reduced capabilities and surface area, making it easier to enact very low-level changes such
314  as repairing/recovering the `hbase:meta` table.
316 To enter maintenance mode, set `hbase.master.maintenance_mode` to `true` either in your
317 `hbase-site.xml` or via system propery when starting the master process (`-D...=true`). Entering
318 and exiting this mode requires a service restart, however the typical use will be when HBase Master
319 is already facing startup difficulties.
321 When maintenance mode is enabled, the master will host all system tables - ensure that it has
322 enough memory to do so. RegionServers will not be assigned any regions from user-space tables;
323 in fact, they will go completely unused while in maintenance mode. Additionally, the master will
324 not load any coprocessors, will not run any normalization or merge/split operations, and will not
325 enforce quotas.
327 [[trouble.tools.external]]
328 === External Tools
330 [[trouble.tools.tail]]
331 ==== tail
333 `tail` is the command line tool that lets you look at the end of a file.
334 Add the `-f` option and it will refresh when new data is available.
335 It's useful when you are wondering what's happening, for example, when a cluster is taking a long time to shutdown or startup as you can just fire a new terminal and tail the master log (and maybe a few RegionServers).
337 [[trouble.tools.top]]
338 ==== top
340 `top` is probably one of the most important tools when first trying to see what's running on a machine and how the resources are consumed.
341 Here's an example from production system:
343 [source]
344 ----
345 top - 14:46:59 up 39 days, 11:55,  1 user,  load average: 3.75, 3.57, 3.84
346 Tasks: 309 total,   1 running, 308 sleeping,   0 stopped,   0 zombie
347 Cpu(s):  4.5%us,  1.6%sy,  0.0%ni, 91.7%id,  1.4%wa,  0.1%hi,  0.6%si,  0.0%st
348 Mem:  24414432k total, 24296956k used,   117476k free,     7196k buffers
349 Swap: 16008732k total,  14348k used, 15994384k free, 11106908k cached
351   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM      TIME+  COMMAND
352 15558 hadoop    18  -2 3292m 2.4g 3556 S   79 10.4   6523:52 java
353 13268 hadoop    18  -2 8967m 8.2g 4104 S   21 35.1   5170:30 java
354  8895 hadoop    18  -2 1581m 497m 3420 S   11  2.1   4002:32 java
355 …
356 ----
358 Here we can see that the system load average during the last five minutes is 3.75, which very roughly means that on average 3.75 threads were waiting for CPU time during these 5 minutes.
359 In general, the _perfect_ utilization equals to the number of cores, under that number the machine is under utilized and over that the machine is over utilized.
360 This is an important concept, see this article to understand it more: http://www.linuxjournal.com/article/9001.
362 Apart from load, we can see that the system is using almost all its available RAM but most of it is used for the OS cache (which is good). The swap only has a few KBs in it and this is wanted, high numbers would indicate swapping activity which is the nemesis of performance of Java systems.
363 Another way to detect swapping is when the load average goes through the roof (although this could also be caused by things like a dying disk, among others).
365 The list of processes isn't super useful by default, all we know is that 3 java processes are using about 111% of the CPUs.
366 To know which is which, simply type `c` and each line will be expanded.
367 Typing `1` will give you the detail of how each CPU is used instead of the average for all of them like shown here.
369 [[trouble.tools.jps]]
370 ==== jps
372 `jps` is shipped with every JDK and gives the java process ids for the current user (if root, then it gives the ids for all users). Example:
374 [source,bourne]
375 ----
376 hadoop@sv4borg12:~$ jps
377 1322 TaskTracker
378 17789 HRegionServer
379 27862 Child
380 1158 DataNode
381 25115 HQuorumPeer
382 2950 Jps
383 19750 ThriftServer
384 18776 jmx
385 ----
387 In order, we see a:
389 * Hadoop TaskTracker, manages the local Childs
390 * HBase RegionServer, serves regions
391 * Child, its MapReduce task, cannot tell which type exactly
392 * Hadoop TaskTracker, manages the local Childs
393 * Hadoop DataNode, serves blocks
394 * HQuorumPeer, a ZooKeeper ensemble member
395 * Jps, well... it's the current process
396 * ThriftServer, it's a special one will be running only if thrift was started
397 * jmx, this is a local process that's part of our monitoring platform ( poorly named maybe). You probably don't have that.
399 You can then do stuff like checking out the full command line that started the process:
401 [source,bourne]
402 ----
403 hadoop@sv4borg12:~$ ps aux | grep HRegionServer
404 hadoop   17789  155 35.2 9067824 8604364 ?     S&lt;l  Mar04 9855:48 /usr/java/jdk1.6.0_14/bin/java -Xmx8000m -XX:+DoEscapeAnalysis -XX:+AggressiveOpts -XX:+UseConcMarkSweepGC -XX:NewSize=64m -XX:MaxNewSize=64m -XX:CMSInitiatingOccupancyFraction=88 -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:/export1/hadoop/logs/gc-hbase.log -Dcom.sun.management.jmxremote.port=10102 -Dcom.sun.management.jmxremote.authenticate=true -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.password.file=/home/hadoop/hbase/conf/jmxremote.password -Dcom.sun.management.jmxremote -Dhbase.log.dir=/export1/hadoop/logs -Dhbase.log.file=hbase-hadoop-regionserver-sv4borg12.log -Dhbase.home.dir=/home/hadoop/hbase -Dhbase.id.str=hadoop -Dhbase.root.logger=INFO,DRFA -Djava.library.path=/home/hadoop/hbase/lib/native/Linux-amd64-64 -classpath /home/hadoop/hbase/bin/../conf:[many jars]:/home/hadoop/hadoop/conf org.apache.hadoop.hbase.regionserver.HRegionServer start
405 ----
407 [[trouble.tools.jstack]]
408 ==== jstack
410 `jstack` is one of the most important tools when trying to figure out what a java process is doing apart from looking at the logs.
411 It has to be used in conjunction with jps in order to give it a process id.
412 It shows a list of threads, each one has a name, and they appear in the order that they were created (so the top ones are the most recent threads). Here are a few example:
414 The main thread of a RegionServer waiting for something to do from the master:
416 [source]
417 ----
418 "regionserver60020" prio=10 tid=0x0000000040ab4000 nid=0x45cf waiting on condition [0x00007f16b6a96000..0x00007f16b6a96a70]
419 java.lang.Thread.State: TIMED_WAITING (parking)
420     at sun.misc.Unsafe.park(Native Method)
421     - parking to wait for  <0x00007f16cd5c2f30> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
422     at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
423     at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1963)
424     at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:395)
425     at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:647)
426     at java.lang.Thread.run(Thread.java:619)
427 ----
429 The MemStore flusher thread that is currently flushing to a file:
431 [source]
432 ----
433 "regionserver60020.cacheFlusher" daemon prio=10 tid=0x0000000040f4e000 nid=0x45eb in Object.wait() [0x00007f16b5b86000..0x00007f16b5b87af0]
434 java.lang.Thread.State: WAITING (on object monitor)
435     at java.lang.Object.wait(Native Method)
436     at java.lang.Object.wait(Object.java:485)
437     at org.apache.hadoop.ipc.Client.call(Client.java:803)
438     - locked <0x00007f16cb14b3a8> (a org.apache.hadoop.ipc.Client$Call)
439     at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:221)
440     at $Proxy1.complete(Unknown Source)
441     at sun.reflect.GeneratedMethodAccessor38.invoke(Unknown Source)
442     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
443     at java.lang.reflect.Method.invoke(Method.java:597)
444     at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
445     at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
446     at $Proxy1.complete(Unknown Source)
447     at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3390)
448     - locked <0x00007f16cb14b470> (a org.apache.hadoop.hdfs.DFSClient$DFSOutputStream)
449     at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3304)
450     at org.apache.hadoop.fs.FSDataOutputStream$PositionCache.close(FSDataOutputStream.java:61)
451     at org.apache.hadoop.fs.FSDataOutputStream.close(FSDataOutputStream.java:86)
452     at org.apache.hadoop.hbase.io.hfile.HFile$Writer.close(HFile.java:650)
453     at org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:853)
454     at org.apache.hadoop.hbase.regionserver.Store.internalFlushCache(Store.java:467)
455     - locked <0x00007f16d00e6f08> (a java.lang.Object)
456     at org.apache.hadoop.hbase.regionserver.Store.flushCache(Store.java:427)
457     at org.apache.hadoop.hbase.regionserver.Store.access$100(Store.java:80)
458     at org.apache.hadoop.hbase.regionserver.Store$StoreFlusherImpl.flushCache(Store.java:1359)
459     at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:907)
460     at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:834)
461     at org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:786)
462     at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:250)
463     at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:224)
464     at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.run(MemStoreFlusher.java:146)
465 ----
467 A handler thread that's waiting for stuff to do (like put, delete, scan, etc.):
469 [source]
470 ----
471 "IPC Server handler 16 on 60020" daemon prio=10 tid=0x00007f16b011d800 nid=0x4a5e waiting on condition [0x00007f16afefd000..0x00007f16afefd9f0]
472    java.lang.Thread.State: WAITING (parking)
473           at sun.misc.Unsafe.park(Native Method)
474           - parking to wait for  <0x00007f16cd3f8dd8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
475           at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
476           at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
477           at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
478           at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1013)
479 ----
481 And one that's busy doing an increment of a counter (it's in the phase where it's trying to create a scanner in order to read the last value):
483 [source]
484 ----
485 "IPC Server handler 66 on 60020" daemon prio=10 tid=0x00007f16b006e800 nid=0x4a90 runnable [0x00007f16acb77000..0x00007f16acb77cf0]
486    java.lang.Thread.State: RUNNABLE
487           at org.apache.hadoop.hbase.regionserver.KeyValueHeap.<init>(KeyValueHeap.java:56)
488           at org.apache.hadoop.hbase.regionserver.StoreScanner.<init>(StoreScanner.java:79)
489           at org.apache.hadoop.hbase.regionserver.Store.getScanner(Store.java:1202)
490           at org.apache.hadoop.hbase.regionserver.HRegion$RegionScanner.<init>(HRegion.java:2209)
491           at org.apache.hadoop.hbase.regionserver.HRegion.instantiateInternalScanner(HRegion.java:1063)
492           at org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:1055)
493           at org.apache.hadoop.hbase.regionserver.HRegion.getScanner(HRegion.java:1039)
494           at org.apache.hadoop.hbase.regionserver.HRegion.getLastIncrement(HRegion.java:2875)
495           at org.apache.hadoop.hbase.regionserver.HRegion.incrementColumnValue(HRegion.java:2978)
496           at org.apache.hadoop.hbase.regionserver.HRegionServer.incrementColumnValue(HRegionServer.java:2433)
497           at sun.reflect.GeneratedMethodAccessor20.invoke(Unknown Source)
498           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
499           at java.lang.reflect.Method.invoke(Method.java:597)
500           at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:560)
501           at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1027)
502 ----
504 A thread that receives data from HDFS:
506 [source]
507 ----
508 "IPC Client (47) connection to sv4borg9/10.4.24.40:9000 from hadoop" daemon prio=10 tid=0x00007f16a02d0000 nid=0x4fa3 runnable [0x00007f16b517d000..0x00007f16b517dbf0]
509    java.lang.Thread.State: RUNNABLE
510           at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
511           at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:215)
512           at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65)
513           at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
514           - locked <0x00007f17d5b68c00> (a sun.nio.ch.Util$1)
515           - locked <0x00007f17d5b68be8> (a java.util.Collections$UnmodifiableSet)
516           - locked <0x00007f1877959b50> (a sun.nio.ch.EPollSelectorImpl)
517           at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
518           at org.apache.hadoop.net.SocketIOWithTimeout$SelectorPool.select(SocketIOWithTimeout.java:332)
519           at org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:157)
520           at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:155)
521           at org.apache.hadoop.net.SocketInputStream.read(SocketInputStream.java:128)
522           at java.io.FilterInputStream.read(FilterInputStream.java:116)
523           at org.apache.hadoop.ipc.Client$Connection$PingInputStream.read(Client.java:304)
524           at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
525           at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
526           - locked <0x00007f1808539178> (a java.io.BufferedInputStream)
527           at java.io.DataInputStream.readInt(DataInputStream.java:370)
528           at org.apache.hadoop.ipc.Client$Connection.receiveResponse(Client.java:569)
529           at org.apache.hadoop.ipc.Client$Connection.run(Client.java:477)
530 ----
532 And here is a master trying to recover a lease after a RegionServer died:
534 [source]
535 ----
536 "LeaseChecker" daemon prio=10 tid=0x00000000407ef800 nid=0x76cd waiting on condition [0x00007f6d0eae2000..0x00007f6d0eae2a70]
538    java.lang.Thread.State: WAITING (on object monitor)
539           at java.lang.Object.wait(Native Method)
540           at java.lang.Object.wait(Object.java:485)
541           at org.apache.hadoop.ipc.Client.call(Client.java:726)
542           - locked <0x00007f6d1cd28f80> (a org.apache.hadoop.ipc.Client$Call)
543           at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
544           at $Proxy1.recoverBlock(Unknown Source)
545           at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.processDatanodeError(DFSClient.java:2636)
546           at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.<init>(DFSClient.java:2832)
547           at org.apache.hadoop.hdfs.DFSClient.append(DFSClient.java:529)
548           at org.apache.hadoop.hdfs.DistributedFileSystem.append(DistributedFileSystem.java:186)
549           at org.apache.hadoop.fs.FileSystem.append(FileSystem.java:530)
550           at org.apache.hadoop.hbase.util.FSUtils.recoverFileLease(FSUtils.java:619)
551           at org.apache.hadoop.hbase.regionserver.wal.HLog.splitLog(HLog.java:1322)
552           at org.apache.hadoop.hbase.regionserver.wal.HLog.splitLog(HLog.java:1210)
553           at org.apache.hadoop.hbase.master.HMaster.splitLogAfterStartup(HMaster.java:648)
554           at org.apache.hadoop.hbase.master.HMaster.joinCluster(HMaster.java:572)
555           at org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:503)
556 ----
558 [[trouble.tools.opentsdb]]
559 ==== OpenTSDB
561 link:http://opentsdb.net[OpenTSDB] is an excellent alternative to Ganglia as it uses Apache HBase to store all the time series and doesn't have to downsample.
562 Monitoring your own HBase cluster that hosts OpenTSDB is a good exercise.
564 Here's an example of a cluster that's suffering from hundreds of compactions launched almost all around the same time, which severely affects the IO performance: (TODO: insert graph plotting compactionQueueSize)
566 It's a good practice to build dashboards with all the important graphs per machine and per cluster so that debugging issues can be done with a single quick look.
567 For example, at StumbleUpon there's one dashboard per cluster with the most important metrics from both the OS and Apache HBase.
568 You can then go down at the machine level and get even more detailed metrics.
570 [[trouble.tools.clustersshtop]]
571 ==== clusterssh+top
573 clusterssh+top, it's like a poor man's monitoring system and it can be quite useful when you have only a few machines as it's very easy to setup.
574 Starting clusterssh will give you one terminal per machine and another terminal in which whatever you type will be retyped in every window.
575 This means that you can type `top` once and it will start it for all of your machines at the same time giving you full view of the current state of your cluster.
576 You can also tail all the logs at the same time, edit files, etc.
578 [[trouble.client]]
579 == Client
581 For more information on the HBase client, see <<architecture.client,client>>.
583 [[trouble.client.scantimeout]]
584 === ScannerTimeoutException or UnknownScannerException
586 This is thrown if the time between RPC calls from the client to RegionServer exceeds the scan timeout.
587 For example, if `Scan.setCaching` is set to 500, then there will be an RPC call to fetch the next batch of rows every 500 `.next()` calls on the ResultScanner because data is being transferred in blocks of 500 rows to the client.
588 Reducing the setCaching value may be an option, but setting this value too low makes for inefficient processing on numbers of rows.
590 See <<perf.hbase.client.caching>>.
592 === Performance Differences in Thrift and Java APIs
594 Poor performance, or even `ScannerTimeoutExceptions`, can occur if `Scan.setCaching` is too high, as discussed in <<trouble.client.scantimeout>>.
595 If the Thrift client uses the wrong caching settings for a given workload, performance can suffer compared to the Java API.
596 To set caching for a given scan in the Thrift client, use the `scannerGetList(scannerId, numRows)` method, where `numRows` is an integer representing the number of rows to cache.
597 In one case, it was found that reducing the cache for Thrift scans from 1000 to 100 increased performance to near parity with the Java API given the same queries.
599 See also Jesse Andersen's link:http://blog.cloudera.com/blog/2014/04/how-to-use-the-hbase-thrift-interface-part-3-using-scans/[blog post] about using Scans with Thrift.
601 [[trouble.client.lease.exception]]
602 === `LeaseException` when calling `Scanner.next`
604 In some situations clients that fetch data from a RegionServer get a LeaseException instead of the usual <<trouble.client.scantimeout>>.
605 Usually the source of the exception is `org.apache.hadoop.hbase.regionserver.Leases.removeLease(Leases.java:230)` (line number may vary). It tends to happen in the context of a slow/freezing `RegionServer#next` call.
606 It can be prevented by having `hbase.rpc.timeout` > `hbase.client.scanner.timeout.period`.
607 Harsh J investigated the issue as part of the mailing list thread link:https://mail-archives.apache.org/mod_mbox/hbase-user/201209.mbox/%3CCAOcnVr3R-LqtKhFsk8Bhrm-YW2i9O6J6Fhjz2h7q6_sxvwd2yw%40mail.gmail.com%3E[HBase, mail # user - Lease does not exist exceptions]
609 [[trouble.client.scarylogs]]
610 === Shell or client application throws lots of scary exceptions during normal operation
612 Since 0.20.0 the default log level for `org.apache.hadoop.hbase.*`is DEBUG.
614 On your clients, edit _$HBASE_HOME/conf/log4j.properties_ and change this: `log4j.logger.org.apache.hadoop.hbase=DEBUG` to this: `log4j.logger.org.apache.hadoop.hbase=INFO`, or even `log4j.logger.org.apache.hadoop.hbase=WARN`.
616 [[trouble.client.longpauseswithcompression]]
617 === Long Client Pauses With Compression
619 This is a fairly frequent question on the Apache HBase dist-list.
620 The scenario is that a client is typically inserting a lot of data into a relatively un-optimized HBase cluster.
621 Compression can exacerbate the pauses, although it is not the source of the problem.
623 See <<precreate.regions>> on the pattern for pre-creating regions and confirm that the table isn't starting with a single region.
625 See <<perf.configurations>> for cluster configuration, particularly `hbase.hstore.blockingStoreFiles`, `hbase.hregion.memstore.block.multiplier`, `MAX_FILESIZE` (region size), and `MEMSTORE_FLUSHSIZE.`
627 A slightly longer explanation of why pauses can happen is as follows: Puts are sometimes blocked on the MemStores which are blocked by the flusher thread which is blocked because there are too many files to compact because the compactor is given too many small files to compact and has to compact the same data repeatedly.
628 This situation can occur even with minor compactions.
629 Compounding this situation, Apache HBase doesn't compress data in memory.
630 Thus, the 64MB that lives in the MemStore could become a 6MB file after compression - which results in a smaller StoreFile.
631 The upside is that more data is packed into the same region, but performance is achieved by being able to write larger files - which is why HBase waits until the flushsize before writing a new StoreFile.
632 And smaller StoreFiles become targets for compaction.
633 Without compression the files are much bigger and don't need as much compaction, however this is at the expense of I/O.
635 [[trouble.client.security.rpc.krb]]
636 === Secure Client Connect ([Caused by GSSException: No valid credentials provided...])
638 You may encounter the following error:
640 ----
641 Secure Client Connect ([Caused by GSSException: No valid credentials provided
642         (Mechanism level: Request is a replay (34) V PROCESS_TGS)])
643 ----
645 This issue is caused by bugs in the MIT Kerberos replay_cache component, link:http://krbdev.mit.edu/rt/Ticket/Display.html?id=1201[#1201] and link:http://krbdev.mit.edu/rt/Ticket/Display.html?id=5924[#5924].
646 These bugs caused the old version of krb5-server to erroneously block subsequent requests sent from a Principal.
647 This caused krb5-server to block the connections sent from one Client (one HTable instance with multi-threading connection instances for each RegionServer); Messages, such as `Request is a replay (34)`, are logged in the client log You can ignore the messages, because HTable will retry 5 * 10 (50) times for each failed connection by default.
648 HTable will throw IOException if any connection to the RegionServer fails after the retries, so that the user client code for HTable instance can handle it further.
649 NOTE: `HTable` is deprecated in HBase 1.0, in favor of `Table`.
651 Alternatively, update krb5-server to a version which solves these issues, such as krb5-server-1.10.3.
652 See JIRA link:https://issues.apache.org/jira/browse/HBASE-10379[HBASE-10379] for more details.
654 [[trouble.client.zookeeper]]
655 === ZooKeeper Client Connection Errors
657 Errors like this...
659 [source]
660 ----
662 11/07/05 11:26:41 WARN zookeeper.ClientCnxn: Session 0x0 for server null,
663  unexpected error, closing socket connection and attempting reconnect
664  java.net.ConnectException: Connection refused: no further information
665         at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
666         at sun.nio.ch.SocketChannelImpl.finishConnect(Unknown Source)
667         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1078)
668  11/07/05 11:26:43 INFO zookeeper.ClientCnxn: Opening socket connection to
669  server localhost/127.0.0.1:2181
670  11/07/05 11:26:44 WARN zookeeper.ClientCnxn: Session 0x0 for server null,
671  unexpected error, closing socket connection and attempting reconnect
672  java.net.ConnectException: Connection refused: no further information
673         at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
674         at sun.nio.ch.SocketChannelImpl.finishConnect(Unknown Source)
675         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1078)
676  11/07/05 11:26:45 INFO zookeeper.ClientCnxn: Opening socket connection to
677  server localhost/127.0.0.1:2181
678 ----
680 ...are either due to ZooKeeper being down, or unreachable due to network issues.
682 The utility <<trouble.tools.builtin.zkcli>> may help investigate ZooKeeper issues.
684 [[trouble.client.oome.directmemory.leak]]
685 === Client running out of memory though heap size seems to be stable (but the off-heap/direct heap keeps growing)
687 You are likely running into the issue that is described and worked through in the mail thread link:https://lists.apache.org/thread.html/d12bbe56be95cf68478d1528263042730670ff39159a01eaf06d8bc8%401322622090%40%3Cuser.hbase.apache.org%3E[HBase, mail # user - Suspected memory leak] and continued over in link:https://lists.apache.org/thread.html/621dde35479215f0b07b23af93b8fac52ff4729949b5c9af18e3a85b%401322971078%40%3Cuser.hbase.apache.org%3E[HBase, mail # dev - FeedbackRe: Suspected memory leak].
688 A workaround is passing your client-side JVM a reasonable value for `-XX:MaxDirectMemorySize`.
689 By default, the `MaxDirectMemorySize` is equal to your `-Xmx` max heapsize setting (if `-Xmx` is set). Try setting it to something smaller (for example, one user had success setting it to `1g` when they had a client-side heap of `12g`). If you set it too small, it will bring on `FullGCs` so keep it a bit hefty.
690 You want to make this setting client-side only especially if you are running the new experimental server-side off-heap cache since this feature depends on being able to use big direct buffers (You may have to keep separate client-side and server-side config dirs).
692 [[trouble.client.security.rpc]]
693 === Secure Client Cannot Connect ([Caused by GSSException: No valid credentials provided(Mechanism level: Failed to find any Kerberos tgt)])
695 There can be several causes that produce this symptom.
697 First, check that you have a valid Kerberos ticket.
698 One is required in order to set up communication with a secure Apache HBase cluster.
699 Examine the ticket currently in the credential cache, if any, by running the `klist` command line utility.
700 If no ticket is listed, you must obtain a ticket by running the `kinit` command with either a keytab specified, or by interactively entering a password for the desired principal.
702 Then, consult the link:http://docs.oracle.com/javase/1.5.0/docs/guide/security/jgss/tutorials/Troubleshooting.html[Java Security Guide troubleshooting section].
703 The most common problem addressed there is resolved by setting `javax.security.auth.useSubjectCredsOnly` system property value to `false`.
705 Because of a change in the format in which MIT Kerberos writes its credentials cache, there is a bug in the Oracle JDK 6 Update 26 and earlier that causes Java to be unable to read the Kerberos credentials cache created by versions of MIT Kerberos 1.8.1 or higher.
706 If you have this problematic combination of components in your environment, to work around this problem, first log in with `kinit` and then immediately refresh the credential cache with `kinit -R`.
707 The refresh will rewrite the credential cache without the problematic formatting.
709 Prior to JDK 1.4, the JCE was an unbundled product, and as such, the JCA and JCE were regularly referred to as separate, distinct components.
710 As JCE is now bundled in the JDK 7.0, the distinction is becoming less apparent. Since the JCE uses the same architecture as the JCA, the JCE should be more properly thought of as a part of the JCA.
712 You may need to install the link:https://docs.oracle.com/javase/1.5.0/docs/guide/security/jce/JCERefGuide.html[Java Cryptography Extension], or JCE because of JDK 1.5 or earlier version.
713 Insure the JCE jars are on the classpath on both server and client systems.
715 You may also need to download the link:http://www.oracle.com/technetwork/java/javase/downloads/jce-6-download-429243.html[unlimited strength JCE policy files].
716 Uncompress and extract the downloaded file, and install the policy jars into _<java-home>/lib/security_.
718 [[trouble.client.masterregistry]]
719 === Trouble shooting master registry issues
721 * For connectivity issues, usually an exception like "MasterRegistryFetchException: Exception making rpc to masters..." is logged in the client logs. The logging includes the
722 list of master end points that were attempted by the client. The bottom part of the stack trace should include the underlying reason. If you suspect connectivity
723 issues (ConnectionRefused?), make sure the master end points are accessible from client.
724 * If there is a suspicion of higher load on the masters due to hedging of RPCs, it can be controlled by either reducing the hedging fan out (via _hbase.rpc.hedged.fanout_) or
725 by restricting the set of masters that clients can access for the master registry purposes (via _hbase.masters_).
727 Refer to <<client.masterregistry>> and <<client_dependencies>> for more details.
729 [[trouble.mapreduce]]
730 == MapReduce
732 [[trouble.mapreduce.local]]
733 === You Think You're On The Cluster, But You're Actually Local
735 This following stacktrace happened using `ImportTsv`, but things like this can happen on any job with a mis-configuration.
737 [source,text]
738 ----
739     WARN mapred.LocalJobRunner: job_local_0001
740 java.lang.IllegalArgumentException: Can't read partitions file
741        at org.apache.hadoop.hbase.mapreduce.hadoopbackport.TotalOrderPartitioner.setConf(TotalOrderPartitioner.java:111)
742        at org.apache.hadoop.util.ReflectionUtils.setConf(ReflectionUtils.java:62)
743        at org.apache.hadoop.util.ReflectionUtils.newInstance(ReflectionUtils.java:117)
744        at org.apache.hadoop.mapred.MapTask$NewOutputCollector.<init>(MapTask.java:560)
745        at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:639)
746        at org.apache.hadoop.mapred.MapTask.run(MapTask.java:323)
747        at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:210)
748 Caused by: java.io.FileNotFoundException: File _partition.lst does not exist.
749        at org.apache.hadoop.fs.RawLocalFileSystem.getFileStatus(RawLocalFileSystem.java:383)
750        at org.apache.hadoop.fs.FilterFileSystem.getFileStatus(FilterFileSystem.java:251)
751        at org.apache.hadoop.fs.FileSystem.getLength(FileSystem.java:776)
752        at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1424)
753        at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1419)
754        at org.apache.hadoop.hbase.mapreduce.hadoopbackport.TotalOrderPartitioner.readPartitions(TotalOrderPartitioner.java:296)
755 ----
757 ...see the critical portion of the stack? It's...
759 [source]
760 ----
761 at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:210)
762 ----
764 LocalJobRunner means the job is running locally, not on the cluster.
766 To solve this problem, you should run your MR job with your `HADOOP_CLASSPATH` set to include the HBase dependencies.
767 The "hbase classpath" utility can be used to do this easily.
768 For example (substitute VERSION with your HBase version):
770 [source,bourne]
771 ----
772 HADOOP_CLASSPATH=`hbase classpath` hadoop jar $HBASE_HOME/hbase-mapreduce-VERSION.jar rowcounter usertable
773 ----
775 See <<hbase.mapreduce.classpath,HBase, MapReduce, and the CLASSPATH>> for more information on HBase MapReduce jobs and classpaths.
777 [[trouble.hbasezerocopybytestring]]
778 === Launching a job, you get java.lang.IllegalAccessError: com/google/protobuf/HBaseZeroCopyByteString or class com.google.protobuf.ZeroCopyLiteralByteString cannot access its superclass com.google.protobuf.LiteralByteString
780 See link:https://issues.apache.org/jira/browse/HBASE-10304[HBASE-10304 Running an hbase job jar: IllegalAccessError: class com.google.protobuf.ZeroCopyLiteralByteString cannot access its superclass com.google.protobuf.LiteralByteString] and link:https://issues.apache.org/jira/browse/HBASE-11118[HBASE-11118 non environment variable solution for "IllegalAccessError: class com.google.protobuf.ZeroCopyLiteralByteString cannot access its superclass com.google.protobuf.LiteralByteString"].
781 The issue can also show up when trying to run spark jobs.
782 See link:https://issues.apache.org/jira/browse/HBASE-10877[HBASE-10877 HBase non-retriable exception list should be expanded].
784 [[trouble.namenode]]
785 == NameNode
787 For more information on the NameNode, see <<arch.hdfs>>.
789 [[trouble.namenode.disk]]
790 === HDFS Utilization of Tables and Regions
792 To determine how much space HBase is using on HDFS use the `hadoop` shell commands from the NameNode.
793 For example...
796 [source,bourne]
797 ----
798 hadoop fs -dus /hbase/
799 ----
800 ...returns the summarized disk utilization for all HBase objects.
803 [source,bourne]
804 ----
805 hadoop fs -dus /hbase/myTable
806 ----
807 ...returns the summarized disk utilization for the HBase table 'myTable'.
810 [source,bourne]
811 ----
812 hadoop fs -du /hbase/myTable
813 ----
814 ...returns a list of the regions under the HBase table 'myTable' and their disk utilization.
816 For more information on HDFS shell commands, see the link:https://hadoop.apache.org/docs/stable/hadoop-project-dist/hadoop-common/FileSystemShell.html[HDFS FileSystem Shell documentation].
818 [[trouble.namenode.hbase.objects]]
819 === Browsing HDFS for HBase Objects
821 Sometimes it will be necessary to explore the HBase objects that exist on HDFS.
822 These objects could include the WALs (Write Ahead Logs), tables, regions, StoreFiles, etc.
823 The easiest way to do this is with the NameNode web application that runs on port 50070.
824 The NameNode web application will provide links to the all the DataNodes in the cluster so that they can be browsed seamlessly.
826 The HDFS directory structure of HBase tables in the cluster is...
827 [source]
828 ----
830 /hbase
831     /data
832         /<Namespace>                    (Namespaces in the cluster)
833             /<Table>                    (Tables in the cluster)
834                 /<Region>               (Regions for the table)
835                     /<ColumnFamily>     (ColumnFamilies for the Region for the table)
836                         /<StoreFile>    (StoreFiles for the ColumnFamily for the Regions for the table)
837 ----
839 The HDFS directory structure of HBase WAL is..
840 [source]
841 ----
843 /hbase
844     /WALs
845         /<RegionServer>    (RegionServers)
846             /<WAL>         (WAL files for the RegionServer)
847 ----
849 See the link:https://hadoop.apache.org/docs/stable/hadoop-project-dist/hadoop-hdfs/HdfsUserGuide.html[HDFS User Guide] for other non-shell diagnostic utilities like `fsck`.
851 [[trouble.namenode.0size.hlogs]]
852 ==== Zero size WALs with data in them
854 Problem: when getting a listing of all the files in a RegionServer's _WALs_ directory, one file has a size of 0 but it contains data.
856 Answer: It's an HDFS quirk.
857 A file that's currently being written to will appear to have a size of 0 but once it's closed it will show its true size
859 [[trouble.namenode.uncompaction]]
860 ==== Use Cases
862 Two common use-cases for querying HDFS for HBase objects is research the degree of uncompaction of a table.
863 If there are a large number of StoreFiles for each ColumnFamily it could indicate the need for a major compaction.
864 Additionally, after a major compaction if the resulting StoreFile is "small" it could indicate the need for a reduction of ColumnFamilies for the table.
866 === Unexpected Filesystem Growth
868 If you see an unexpected spike in filesystem usage by HBase, two possible culprits
869 are snapshots and WALs.
871 Snapshots::
872   When you create a snapshot, HBase retains everything it needs to recreate the table's
873   state at that time of the snapshot. This includes deleted cells or expired versions.
874   For this reason, your snapshot usage pattern should be well-planned, and you should
875   prune snapshots that you no longer need. Snapshots are stored in `/hbase/.hbase-snapshot`,
876   and archives needed to restore snapshots are stored in
877   `/hbase/archive/<_tablename_>/<_region_>/<_column_family_>/`.
879   *Do not* manage snapshots or archives manually via HDFS. HBase provides APIs and
880   HBase Shell commands for managing them. For more information, see <<ops.snapshots>>.
882 WAL::
883   Write-ahead logs (WALs) are stored in subdirectories of the HBase root directory,
884   typically `/hbase/`, depending on their status. Already-processed WALs are stored
885   in `/hbase/oldWALs/` and corrupt WALs are stored in `/hbase/.corrupt/` for examination.
886   If the size of one of these subdirectories is growing, examine the HBase
887   server logs to find the root cause for why WALs are not being processed correctly.
889 If you use replication and `/hbase/oldWALs/` is using more space than you expect,
890 remember that WALs are saved when replication is disabled, as long as there are peers.
892 *Do not* manage WALs manually via HDFS.
894 [[trouble.network]]
895 == Network
897 [[trouble.network.spikes]]
898 === Network Spikes
900 If you are seeing periodic network spikes you might want to check the `compactionQueues` to see if major compactions are happening.
902 See <<managed.compactions>> for more information on managing compactions.
904 [[trouble.network.loopback]]
905 === Loopback IP
907 HBase expects the loopback IP Address to be 127.0.0.1.
909 [[trouble.network.ints]]
910 === Network Interfaces
912 Are all the network interfaces functioning correctly? Are you sure? See the Troubleshooting Case Study in <<trouble.casestudy>>.
914 [[trouble.rs]]
915 == RegionServer
917 For more information on the RegionServers, see <<regionserver.arch>>.
919 [[trouble.rs.startup]]
920 === Startup Errors
922 [[trouble.rs.startup.master_no_region]]
923 ==== Master Starts, But RegionServers Do Not
925 The Master believes the RegionServers have the IP of 127.0.0.1 - which is localhost and resolves to the master's own localhost.
927 The RegionServers are erroneously informing the Master that their IP addresses are 127.0.0.1.
929 Modify _/etc/hosts_ on the region servers, from...
931 [source]
932 ----
933 # Do not remove the following line, or various programs
934 # that require network functionality will fail.
935 127.0.0.1               fully.qualified.regionservername regionservername  localhost.localdomain localhost
936 ::1             localhost6.localdomain6 localhost6
937 ----
939 \... to (removing the master node's name from localhost)...
941 [source]
942 ----
943 # Do not remove the following line, or various programs
944 # that require network functionality will fail.
945 127.0.0.1               localhost.localdomain localhost
946 ::1             localhost6.localdomain6 localhost6
947 ----
949 [[trouble.rs.startup.compression]]
950 ==== Compression Link Errors
952 Since compression algorithms such as LZO need to be installed and configured on each cluster this is a frequent source of startup error.
953 If you see messages like this...
955 [source]
956 ----
958 11/02/20 01:32:15 ERROR lzo.GPLNativeCodeLoader: Could not load native gpl library
959 java.lang.UnsatisfiedLinkError: no gplcompression in java.library.path
960         at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1734)
961         at java.lang.Runtime.loadLibrary0(Runtime.java:823)
962         at java.lang.System.loadLibrary(System.java:1028)
963 ----
965 \... then there is a path issue with the compression libraries.
966 See the Configuration section on link:[LZO compression configuration].
968 [[trouble.rs.startup.hsync]]
969 ==== RegionServer aborts due to lack of hsync for filesystem
971 In order to provide data durability for writes to the cluster HBase relies on the ability to durably save state in a write ahead log. When using a version of Apache Hadoop Common's filesystem API that supports checking on the availability of needed calls, HBase will proactively abort the cluster if it finds it can't operate safely.
973 For RegionServer roles, the failure will show up in logs like this:
975 ----
976 2018-04-05 11:36:22,785 ERROR [regionserver/192.168.1.123:16020] wal.AsyncFSWALProvider: The RegionServer async write ahead log provider relies on the ability to call hflush and hsync for proper operation during component failures, but the current FileSystem does not support doing so. Please check the config value of 'hbase.wal.dir' and ensure it points to a FileSystem mount that has suitable capabilities for output streams.
977 2018-04-05 11:36:22,799 ERROR [regionserver/192.168.1.123:16020] regionserver.HRegionServer: ***** ABORTING region server 192.168.1.123,16020,1522946074234: Unhandled: cannot get log writer *****
978 java.io.IOException: cannot get log writer
979         at org.apache.hadoop.hbase.wal.AsyncFSWALProvider.createAsyncWriter(AsyncFSWALProvider.java:112)
980         at org.apache.hadoop.hbase.regionserver.wal.AsyncFSWAL.createWriterInstance(AsyncFSWAL.java:612)
981         at org.apache.hadoop.hbase.regionserver.wal.AsyncFSWAL.createWriterInstance(AsyncFSWAL.java:124)
982         at org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL.rollWriter(AbstractFSWAL.java:759)
983         at org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL.rollWriter(AbstractFSWAL.java:489)
984         at org.apache.hadoop.hbase.regionserver.wal.AsyncFSWAL.<init>(AsyncFSWAL.java:251)
985         at org.apache.hadoop.hbase.wal.AsyncFSWALProvider.createWAL(AsyncFSWALProvider.java:69)
986         at org.apache.hadoop.hbase.wal.AsyncFSWALProvider.createWAL(AsyncFSWALProvider.java:44)
987         at org.apache.hadoop.hbase.wal.AbstractFSWALProvider.getWAL(AbstractFSWALProvider.java:138)
988         at org.apache.hadoop.hbase.wal.AbstractFSWALProvider.getWAL(AbstractFSWALProvider.java:57)
989         at org.apache.hadoop.hbase.wal.WALFactory.getWAL(WALFactory.java:252)
990         at org.apache.hadoop.hbase.regionserver.HRegionServer.getWAL(HRegionServer.java:2105)
991         at org.apache.hadoop.hbase.regionserver.HRegionServer.buildServerLoad(HRegionServer.java:1326)
992         at org.apache.hadoop.hbase.regionserver.HRegionServer.tryRegionServerReport(HRegionServer.java:1191)
993         at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:1007)
994         at java.lang.Thread.run(Thread.java:745)
995 Caused by: org.apache.hadoop.hbase.util.CommonFSUtils$StreamLacksCapabilityException: hflush and hsync
996         at org.apache.hadoop.hbase.io.asyncfs.AsyncFSOutputHelper.createOutput(AsyncFSOutputHelper.java:69)
997         at org.apache.hadoop.hbase.regionserver.wal.AsyncProtobufLogWriter.initOutput(AsyncProtobufLogWriter.java:168)
998         at org.apache.hadoop.hbase.regionserver.wal.AbstractProtobufLogWriter.init(AbstractProtobufLogWriter.java:167)
999         at org.apache.hadoop.hbase.wal.AsyncFSWALProvider.createAsyncWriter(AsyncFSWALProvider.java:99)
1000         ... 15 more
1002 ----
1004 If you are attempting to run in standalone mode and see this error, please walk back through the section <<quickstart>> and ensure you have included *all* the given configuration settings.
1006 [[trouble.rs.startup.asyncfs]]
1007 ==== RegionServer aborts due to can not initialize access to HDFS
1009 We will try to use _AsyncFSWAL_ for HBase-2.x as it has better performance while consuming less resources. But the problem for _AsyncFSWAL_ is that it hacks into the internal of the DFSClient implementation, so it will easily be broken when upgrading hadoop, even for a simple patch release.
1011 If you do not specify the wal provider, we will try to fall back to the old _FSHLog_ if we fail to initialize _AsyncFSWAL_, but it may not always work. The failure will show up in logs like this:
1013 ----
1014 18/07/02 18:51:06 WARN concurrent.DefaultPromise: An exception was
1015 thrown by org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutputHelper$13.operationComplete()
1016 java.lang.Error: Couldn't properly initialize access to HDFS
1017 internals. Please update your WAL Provider to not make use of the
1018 'asyncfs' provider. See HBASE-16110 for more information.
1019      at org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutputSaslHelper.<clinit>(FanOutOneBlockAsyncDFSOutputSaslHelper.java:268)
1020      at org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutputHelper.initialize(FanOutOneBlockAsyncDFSOutputHelper.java:661)
1021      at org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutputHelper.access$300(FanOutOneBlockAsyncDFSOutputHelper.java:118)
1022      at org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutputHelper$13.operationComplete(FanOutOneBlockAsyncDFSOutputHelper.java:720)
1023      at org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutputHelper$13.operationComplete(FanOutOneBlockAsyncDFSOutputHelper.java:715)
1024      at org.apache.hbase.thirdparty.io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:507)
1025      at org.apache.hbase.thirdparty.io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:500)
1026      at org.apache.hbase.thirdparty.io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:479)
1027      at org.apache.hbase.thirdparty.io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:420)
1028      at org.apache.hbase.thirdparty.io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:104)
1029      at org.apache.hbase.thirdparty.io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:82)
1030      at org.apache.hbase.thirdparty.io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.fulfillConnectPromise(AbstractEpollChannel.java:638)
1031      at org.apache.hbase.thirdparty.io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.finishConnect(AbstractEpollChannel.java:676)
1032      at org.apache.hbase.thirdparty.io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.epollOutReady(AbstractEpollChannel.java:552)
1033      at org.apache.hbase.thirdparty.io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:394)
1034      at org.apache.hbase.thirdparty.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:304)
1035      at org.apache.hbase.thirdparty.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
1036      at org.apache.hbase.thirdparty.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
1037      at java.lang.Thread.run(Thread.java:748)
1038  Caused by: java.lang.NoSuchMethodException:
1039 org.apache.hadoop.hdfs.DFSClient.decryptEncryptedDataEncryptionKey(org.apache.hadoop.fs.FileEncryptionInfo)
1040      at java.lang.Class.getDeclaredMethod(Class.java:2130)
1041      at org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutputSaslHelper.createTransparentCryptoHelper(FanOutOneBlockAsyncDFSOutputSaslHelper.java:232)
1042      at org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutputSaslHelper.<clinit>(FanOutOneBlockAsyncDFSOutputSaslHelper.java:262)
1043      ... 18 more
1044 ----
1046 If you hit this error, please specify _FSHLog_, i.e, _filesystem_, explicitly in your config file.
1048 [source,xml]
1049 ----
1050 <property>
1051   <name>hbase.wal.provider</name>
1052   <value>filesystem</value>
1053 </property>
1054 ----
1056 And do not forget to send an email to the user@hbase.apache.org or dev@hbase.apache.org to report the failure and also your hadoop version, we will try to fix the problem ASAP in the next release.
1058 [[trouble.rs.runtime]]
1059 === Runtime Errors
1061 [[trouble.rs.runtime.hang]]
1062 ==== RegionServer Hanging
1064 Are you running an old JVM (< 1.6.0_u21?)? When you look at a thread dump, does it look like threads are BLOCKED but no one holds the lock all are blocked on? See link:https://issues.apache.org/jira/browse/HBASE-3622[HBASE 3622 Deadlock in
1065             HBaseServer (JVM bug?)].
1066 Adding `-XX:+UseMembar` to the HBase `HBASE_OPTS` in _conf/hbase-env.sh_ may fix it.
1068 [[trouble.rs.runtime.filehandles]]
1069 ==== java.io.IOException...(Too many open files)
1071 If you see log messages like this...
1073 [source]
1074 ----
1076 2010-09-13 01:24:17,336 WARN org.apache.hadoop.hdfs.server.datanode.DataNode:
1077 Disk-related IOException in BlockReceiver constructor. Cause is java.io.IOException: Too many open files
1078         at java.io.UnixFileSystem.createFileExclusively(Native Method)
1079         at java.io.File.createNewFile(File.java:883)
1080 ----
1082 \... see the Getting Started section on link:[ulimit and nproc configuration].
1084 [[trouble.rs.runtime.xceivers]]
1085 ==== xceiverCount 258 exceeds the limit of concurrent xcievers 256
1087 This typically shows up in the DataNode logs.
1089 See the Getting Started section on link:[xceivers configuration].
1091 [[trouble.rs.runtime.oom_nt]]
1092 ==== System instability, and the presence of "java.lang.OutOfMemoryError: unable to createnew native thread in exceptions" HDFS DataNode logs or that of any system daemon
1094 See the Getting Started section on ulimit and nproc configuration.
1095 The default on recent Linux distributions is 1024 - which is far too low for HBase.
1097 [[trouble.rs.runtime.gc]]
1098 ==== DFS instability and/or RegionServer lease timeouts
1100 If you see warning messages like this...
1102 [source]
1103 ----
1105 2009-02-24 10:01:33,516 WARN org.apache.hadoop.hbase.util.Sleeper: We slept xxx ms, ten times longer than scheduled: 10000
1106 2009-02-24 10:01:33,516 WARN org.apache.hadoop.hbase.util.Sleeper: We slept xxx ms, ten times longer than scheduled: 15000
1107 2009-02-24 10:01:36,472 WARN org.apache.hadoop.hbase.regionserver.HRegionServer: unable to report to master for xxx milliseconds - retrying
1108 ----
1110 \... or see full GC compactions then you may be experiencing full GC's.
1112 [[trouble.rs.runtime.nolivenodes]]
1113 ==== "No live nodes contain current block" and/or YouAreDeadException
1115 These errors can happen either when running out of OS file handles or in periods of severe network problems where the nodes are unreachable.
1117 See the Getting Started section on ulimit and nproc configuration and check your network.
1119 [[trouble.rs.runtime.zkexpired]]
1120 ==== ZooKeeper SessionExpired events
1122 Master or RegionServers shutting down with messages like those in the logs:
1124 [source]
1125 ----
1127 WARN org.apache.zookeeper.ClientCnxn: Exception
1128 closing session 0x278bd16a96000f to sun.nio.ch.SelectionKeyImpl@355811ec
1129 java.io.IOException: TIMED OUT
1130        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:906)
1131 WARN org.apache.hadoop.hbase.util.Sleeper: We slept 79410ms, ten times longer than scheduled: 5000
1132 INFO org.apache.zookeeper.ClientCnxn: Attempting connection to server hostname/IP:PORT
1133 INFO org.apache.zookeeper.ClientCnxn: Priming connection to java.nio.channels.SocketChannel[connected local=/IP:PORT remote=hostname/IP:PORT]
1134 INFO org.apache.zookeeper.ClientCnxn: Server connection successful
1135 WARN org.apache.zookeeper.ClientCnxn: Exception closing session 0x278bd16a96000d to sun.nio.ch.SelectionKeyImpl@3544d65e
1136 java.io.IOException: Session Expired
1137        at org.apache.zookeeper.ClientCnxn$SendThread.readConnectResult(ClientCnxn.java:589)
1138        at org.apache.zookeeper.ClientCnxn$SendThread.doIO(ClientCnxn.java:709)
1139        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:945)
1140 ERROR org.apache.hadoop.hbase.regionserver.HRegionServer: ZooKeeper session expired
1141 ----
1143 The JVM is doing a long running garbage collecting which is pausing every threads (aka "stop the world"). Since the RegionServer's local ZooKeeper client cannot send heartbeats, the session times out.
1144 By design, we shut down any node that isn't able to contact the ZooKeeper ensemble after getting a timeout so that it stops serving data that may already be assigned elsewhere.
1146 * Make sure you give plenty of RAM (in _hbase-env.sh_), the default of 1GB won't be able to sustain long running imports.
1147 * Make sure you don't swap, the JVM never behaves well under swapping.
1148 * Make sure you are not CPU starving the RegionServer thread.
1149   For example, if you are running a MapReduce job using 6 CPU-intensive tasks on a machine with 4 cores, you are probably starving the RegionServer enough to create longer garbage collection pauses.
1150 * Increase the ZooKeeper session timeout
1152 If you wish to increase the session timeout, add the following to your _hbase-site.xml_ to increase the timeout from the default of 60 seconds to 120 seconds.
1154 [source,xml]
1155 ----
1156 <property>
1157   <name>zookeeper.session.timeout</name>
1158   <value>120000</value>
1159 </property>
1160 <property>
1161   <name>hbase.zookeeper.property.tickTime</name>
1162   <value>6000</value>
1163 </property>
1164 ----
1166 Be aware that setting a higher timeout means that the regions served by a failed RegionServer will take at least that amount of time to be transferred to another RegionServer.
1167 For a production system serving live requests, we would instead recommend setting it lower than 1 minute and over-provision your cluster in order the lower the memory load on each machines (hence having less garbage to collect per machine).
1169 If this is happening during an upload which only happens once (like initially loading all your data into HBase), consider bulk loading.
1171 See <<trouble.zookeeper.general>> for other general information about ZooKeeper troubleshooting.
1173 [[trouble.rs.runtime.notservingregion]]
1174 ==== NotServingRegionException
1176 This exception is "normal" when found in the RegionServer logs at DEBUG level.
1177 This exception is returned back to the client and then the client goes back to `hbase:meta` to find the new location of the moved region.
1179 However, if the NotServingRegionException is logged ERROR, then the client ran out of retries and something probably wrong.
1181 [[brand.new.compressor]]
1182 ==== Logs flooded with '2011-01-10 12:40:48,407 INFO org.apache.hadoop.io.compress.CodecPool: Gotbrand-new compressor' messages
1184 We are not using the native versions of compression libraries.
1185 See link:https://issues.apache.org/jira/browse/HBASE-1900[HBASE-1900 Put back native support when hadoop 0.21 is released].
1186 Copy the native libs from hadoop under HBase lib dir or symlink them into place and the message should go away.
1188 [[trouble.rs.runtime.client_went_away]]
1189 ==== Server handler X on 60020 caught: java.nio.channels.ClosedChannelException
1191 If you see this type of message it means that the region server was trying to read/send data from/to a client but it already went away.
1192 Typical causes for this are if the client was killed (you see a storm of messages like this when a MapReduce job is killed or fails) or if the client receives a SocketTimeoutException.
1193 It's harmless, but you should consider digging in a bit more if you aren't doing something to trigger them.
1195 === Snapshot Errors Due to Reverse DNS
1197 Several operations within HBase, including snapshots, rely on properly configured reverse DNS.
1198 Some environments, such as Amazon EC2, have trouble with reverse DNS.
1199 If you see errors like the following on your RegionServers, check your reverse DNS configuration:
1201 ----
1203 2013-05-01 00:04:56,356 DEBUG org.apache.hadoop.hbase.procedure.Subprocedure: Subprocedure 'backup1'
1204 coordinator notified of 'acquire', waiting on 'reached' or 'abort' from coordinator.
1205 ----
1207 In general, the hostname reported by the RegionServer needs to be the same as the hostname the Master is trying to reach.
1208 You can see a hostname mismatch by looking for the following type of message in the RegionServer's logs at start-up.
1210 ----
1212 2013-05-01 00:03:00,614 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Master passed us hostname
1213 to use. Was=myhost-1234, Now=ip-10-55-88-99.ec2.internal
1214 ----
1216 [[trouble.rs.shutdown]]
1217 === Shutdown Errors
1221 [[trouble.master]]
1222 == Master
1224 For more information on the Master, see <<architecture.master,master>>.
1226 [[trouble.master.startup]]
1227 === Startup Errors
1229 [[trouble.master.startup.migration]]
1230 ==== Master says that you need to run the HBase migrations script
1232 Upon running that, the HBase migrations script says no files in root directory.
1234 HBase expects the root directory to either not exist, or to have already been initialized by HBase running a previous time.
1235 If you create a new directory for HBase using Hadoop DFS, this error will occur.
1236 Make sure the HBase root directory does not currently exist or has been initialized by a previous run of HBase.
1237 Sure fire solution is to just use Hadoop dfs to delete the HBase root and let HBase create and initialize the directory itself.
1239 [[trouble.master.startup.zk.buffer]]
1240 ==== Packet len6080218 is out of range!
1242 If you have many regions on your cluster and you see an error like that reported above in this sections title in your logs, see link:https://issues.apache.org/jira/browse/HBASE-4246[HBASE-4246 Cluster with too many regions cannot withstand some master failover scenarios].
1244 [[trouble.master.startup.hsync]]
1245 ==== Master fails to become active due to lack of hsync for filesystem
1247 HBase's internal framework for cluster operations requires the ability to durably save state in a write ahead log. When using a version of Apache Hadoop Common's filesystem API that supports checking on the availability of needed calls, HBase will proactively abort the cluster if it finds it can't operate safely.
1249 For Master roles, the failure will show up in logs like this:
1251 ----
1252 2018-04-05 11:18:44,653 ERROR [Thread-21] master.HMaster: Failed to become active master
1253 java.lang.IllegalStateException: The procedure WAL relies on the ability to hsync for proper operation during component failures, but the underlying filesystem does not support doing so. Please check the config value of 'hbase.procedure.store.wal.use.hsync' to set the desired level of robustness and ensure the config value of 'hbase.wal.dir' points to a FileSystem mount that can provide it.
1254         at org.apache.hadoop.hbase.procedure2.store.wal.WALProcedureStore.rollWriter(WALProcedureStore.java:1034)
1255         at org.apache.hadoop.hbase.procedure2.store.wal.WALProcedureStore.recoverLease(WALProcedureStore.java:374)
1256         at org.apache.hadoop.hbase.procedure2.ProcedureExecutor.start(ProcedureExecutor.java:530)
1257         at org.apache.hadoop.hbase.master.HMaster.startProcedureExecutor(HMaster.java:1267)
1258         at org.apache.hadoop.hbase.master.HMaster.startServiceThreads(HMaster.java:1173)
1259         at org.apache.hadoop.hbase.master.HMaster.finishActiveMasterInitialization(HMaster.java:881)
1260         at org.apache.hadoop.hbase.master.HMaster.startActiveMasterManager(HMaster.java:2048)
1261         at org.apache.hadoop.hbase.master.HMaster.lambda$run$0(HMaster.java:568)
1262         at java.lang.Thread.run(Thread.java:745)
1263 ----
1265 If you are attempting to run in standalone mode and see this error, please walk back through the section <<quickstart>> and ensure you have included *all* the given configuration settings.
1267 [[trouble.master.shutdown]]
1268 === Shutdown Errors
1272 [[trouble.zookeeper]]
1273 == ZooKeeper
1275 [[trouble.zookeeper.startup]]
1276 === Startup Errors
1278 [[trouble.zookeeper.startup.address]]
1279 ==== Could not find my address: xyz in list of ZooKeeper quorum servers
1281 A ZooKeeper server wasn't able to start, throws that error.
1282 xyz is the name of your server.
1284 This is a name lookup problem.
1285 HBase tries to start a ZooKeeper server on some machine but that machine isn't able to find itself in the `hbase.zookeeper.quorum` configuration.
1287 Use the hostname presented in the error message instead of the value you used.
1288 If you have a DNS server, you can set `hbase.zookeeper.dns.interface` and `hbase.zookeeper.dns.nameserver` in _hbase-site.xml_ to make sure it resolves to the correct FQDN.
1290 [[trouble.zookeeper.general]]
1291 === ZooKeeper, The Cluster Canary
1293 ZooKeeper is the cluster's "canary in the mineshaft". It'll be the first to notice issues if any so making sure its happy is the short-cut to a humming cluster.
1295 See the link:https://cwiki.apache.org/confluence/display/HADOOP2/ZooKeeper+Troubleshooting[ZooKeeper Operating Environment Troubleshooting] page.
1296 It has suggestions and tools for checking disk and networking performance; i.e.
1297 the operating environment your ZooKeeper and HBase are running in.
1299 Additionally, the utility <<trouble.tools.builtin.zkcli>> may help investigate ZooKeeper issues.
1301 [[trouble.ec2]]
1302 == Amazon EC2
1304 [[trouble.ec2.zookeeper]]
1305 === ZooKeeper does not seem to work on Amazon EC2
1307 HBase does not start when deployed as Amazon EC2 instances.
1308 Exceptions like the below appear in the Master and/or RegionServer logs:
1310 [source]
1311 ----
1313   2009-10-19 11:52:27,030 INFO org.apache.zookeeper.ClientCnxn: Attempting
1314   connection to server ec2-174-129-15-236.compute-1.amazonaws.com/10.244.9.171:2181
1315   2009-10-19 11:52:27,032 WARN org.apache.zookeeper.ClientCnxn: Exception
1316   closing session 0x0 to sun.nio.ch.SelectionKeyImpl@656dc861
1317   java.net.ConnectException: Connection refused
1318 ----
1320 Security group policy is blocking the ZooKeeper port on a public address.
1321 Use the internal EC2 host names when configuring the ZooKeeper quorum peer list.
1323 [[trouble.ec2.instability]]
1324 === Instability on Amazon EC2
1326 Questions on HBase and Amazon EC2 come up frequently on the HBase dist-list.
1328 [[trouble.ec2.connection]]
1329 === Remote Java Connection into EC2 Cluster Not Working
1331 See Andrew's answer here, up on the user list: link:https://lists.apache.org/thread.html/666bfa863bc2eb2ec7bbe5ecfbee345e0cbf1d58aaa6c1636dfcb527%401269010842%40%3Cuser.hbase.apache.org%3E[Remote Java client connection into EC2 instance].
1333 [[trouble.versions]]
1334 == HBase and Hadoop version issues
1336 [[trouble.wrong.version]]
1337 === ...cannot communicate with client version...
1339 If you see something like the following in your logs [computeroutput]+... 2012-09-24
1340           10:20:52,168 FATAL org.apache.hadoop.hbase.master.HMaster: Unhandled exception. Starting
1341           shutdown. org.apache.hadoop.ipc.RemoteException: Server IPC version 7 cannot communicate
1342           with client version 4 ...+ ...are you trying to talk to an Hadoop 2.0.x from an HBase that has an Hadoop 1.0.x client? Use the HBase built against Hadoop 2.0 or rebuild your HBase passing the +-Dhadoop.profile=2.0+ attribute to Maven (See <<maven.build.hadoop>> for more).
1344 == HBase and HDFS
1346 General configuration guidance for Apache HDFS is out of the scope of this guide.
1347 Refer to the documentation available at https://hadoop.apache.org/ for extensive information about configuring HDFS.
1348 This section deals with HDFS in terms of HBase.
1350 In most cases, HBase stores its data in Apache HDFS.
1351 This includes the HFiles containing the data, as well as the write-ahead logs (WALs) which store data before it is written to the HFiles and protect against RegionServer crashes.
1352 HDFS provides reliability and protection to data in HBase because it is distributed.
1353 To operate with the most efficiency, HBase needs data to be available locally.
1354 Therefore, it is a good practice to run an HDFS DataNode on each RegionServer.
1356 .Important Information and Guidelines for HBase and HDFS
1358 HBase is a client of HDFS.::
1359   HBase is an HDFS client, using the HDFS `DFSClient` class, and references to this class appear in HBase logs with other HDFS client log messages.
1361 Configuration is necessary in multiple places.::
1362   Some HDFS configurations relating to HBase need to be done at the HDFS (server) side.
1363   Others must be done within HBase (at the client side). Other settings need to be set at both the server and client side.
1365 Write errors which affect HBase may be logged in the HDFS logs rather than HBase logs.::
1366   When writing, HDFS pipelines communications from one DataNode to another.
1367   HBase communicates to both the HDFS NameNode and DataNode, using the HDFS client classes.
1368   Communication problems between DataNodes are logged in the HDFS logs, not the HBase logs.
1370 HBase communicates with HDFS using two different ports.::
1371   HBase communicates with DataNodes using the `ipc.Client` interface and the `DataNode` class.
1372   References to these will appear in HBase logs.
1373   Each of these communication channels use a different port (50010 and 50020 by default). The ports are configured in the HDFS configuration, via the `dfs.datanode.address` and `dfs.datanode.ipc.address`            parameters.
1375 Errors may be logged in HBase, HDFS, or both.::
1376   When troubleshooting HDFS issues in HBase, check logs in both places for errors.
1378 HDFS takes a while to mark a node as dead. You can configure HDFS to avoid using stale DataNodes.::
1379   By default, HDFS does not mark a node as dead until it is unreachable for 630 seconds.
1380   In Hadoop 1.1 and Hadoop 2.x, this can be alleviated by enabling checks for stale DataNodes, though this check is disabled by default.
1381   You can enable the check for reads and writes separately, via `dfs.namenode.avoid.read.stale.datanode` and `dfs.namenode.avoid.write.stale.datanode settings`.
1382   A stale DataNode is one that has not been reachable for `dfs.namenode.stale.datanode.interval` (default is 30 seconds). Stale datanodes are avoided, and marked as the last possible target for a read or write operation.
1383   For configuration details, see the HDFS documentation.
1385 Settings for HDFS retries and timeouts are important to HBase.::
1386   You can configure settings for various retries and timeouts.
1387   Always refer to the HDFS documentation for current recommendations and defaults.
1388   Some of the settings important to HBase are listed here.
1389   Defaults are current as of Hadoop 2.3.
1390   Check the Hadoop documentation for the most current values and recommendations.
1392 The HBase Balancer and HDFS Balancer are incompatible::
1393   The HDFS balancer attempts to spread HDFS blocks evenly among DataNodes. HBase relies
1394   on compactions to restore locality after a region split or failure. These two types
1395   of balancing do not work well together.
1397 In the past, the generally accepted advice was to turn off the HDFS load balancer and rely
1398 on the HBase balancer, since the HDFS balancer would degrade locality. This advice
1399 is still valid if your HDFS version is lower than 2.7.1.
1401 link:https://issues.apache.org/jira/browse/HDFS-6133[HDFS-6133] provides the ability
1402 to exclude favored-nodes (pinned) blocks from the HDFS load balancer, by setting the
1403 `dfs.datanode.block-pinning.enabled` property to `true` in the HDFS service
1404 configuration.
1406 HBase can be enabled to use the HDFS favored-nodes feature by switching the HBase balancer
1407 class (conf: `hbase.master.loadbalancer.class`) to `org.apache.hadoop.hbase.favored.FavoredNodeLoadBalancer`
1408 which is documented link:https://hbase.apache.org/devapidocs/org/apache/hadoop/hbase/favored/FavoredNodeLoadBalancer.html[here].
1410 NOTE: HDFS-6133 is available in HDFS 2.7.0 and higher, but HBase does not support
1411 running on HDFS 2.7.0, so you must be using HDFS 2.7.1 or higher to use this feature
1412 with HBase.
1414 .Connection Timeouts
1415 Connection timeouts occur between the client (HBASE) and the HDFS DataNode.
1416 They may occur when establishing a connection, attempting to read, or attempting to write.
1417 The two settings below are used in combination, and affect connections between the DFSClient and the DataNode, the ipc.cClient and the DataNode, and communication between two DataNodes.
1419 `dfs.client.socket-timeout` (default: 60000)::
1420   The amount of time before a client connection times out when establishing a connection or reading.
1421   The value is expressed in milliseconds, so the default is 60 seconds.
1423 `dfs.datanode.socket.write.timeout` (default: 480000)::
1424   The amount of time before a write operation times out.
1425   The default is 8 minutes, expressed as milliseconds.
1427 .Typical Error Logs
1428 The following types of errors are often seen in the logs.
1430 `INFO HDFS.DFSClient: Failed to connect to /xxx50010, add to deadNodes and
1431             continue java.net.SocketTimeoutException: 60000 millis timeout while waiting for channel
1432             to be ready for connect. ch : java.nio.channels.SocketChannel[connection-pending
1433             remote=/region-server-1:50010]`::
1434   All DataNodes for a block are dead, and recovery is not possible.
1435   Here is the sequence of events that leads to this error:
1437 `INFO org.apache.hadoop.HDFS.DFSClient: Exception in createBlockOutputStream
1438             java.net.SocketTimeoutException: 69000 millis timeout while waiting for channel to be
1439             ready for connect. ch : java.nio.channels.SocketChannel[connection-pending remote=/
1440             xxx:50010]`::
1441   This type of error indicates a write issue.
1442   In this case, the master wants to split the log.
1443   It does not have a local DataNodes so it tries to connect to a remote DataNode, but the DataNode is dead.
1445 [[trouble.tests]]
1446 == Running unit or integration tests
1448 [[trouble.hdfs_2556]]
1449 === Runtime exceptions from MiniDFSCluster when running tests
1451 If you see something like the following
1453 [source]
1454 ----
1456 java.lang.NullPointerException: null
1457 at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes
1458 at org.apache.hadoop.hdfs.MiniDFSCluster.<init>
1459 at org.apache.hadoop.hbase.MiniHBaseCluster.<init>
1460 at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniDFSCluster
1461 at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster
1463 ----
1467 [source]
1468 ----
1470 java.io.IOException: Shutting down
1471 at org.apache.hadoop.hbase.MiniHBaseCluster.init
1472 at org.apache.hadoop.hbase.MiniHBaseCluster.<init>
1473 at org.apache.hadoop.hbase.MiniHBaseCluster.<init>
1474 at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniHBaseCluster
1475 at org.apache.hadoop.hbase.HBaseTestingUtility.startMiniCluster
1477 ----
1479 \... then try issuing the command +umask 022+ before launching tests.
1480 This is a workaround for link:https://issues.apache.org/jira/browse/HDFS-2556[HDFS-2556]
1482 [[trouble.casestudy]]
1483 == Case Studies
1485 For Performance and Troubleshooting Case Studies, see <<casestudies>>.
1487 [[trouble.crypto]]
1488 == Cryptographic Features
1490 [[trouble.crypto.hbase_10132]]
1491 === sun.security.pkcs11.wrapper.PKCS11Exception: CKR_ARGUMENTS_BAD
1493 This problem manifests as exceptions ultimately caused by:
1495 [source]
1496 ----
1497 Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_ARGUMENTS_BAD
1498   at sun.security.pkcs11.wrapper.PKCS11.C_DecryptUpdate(Native Method)
1499   at sun.security.pkcs11.P11Cipher.implDoFinal(P11Cipher.java:795)
1500 ----
1502 This problem appears to affect some versions of OpenJDK 7 shipped by some Linux vendors.
1503 NSS is configured as the default provider.
1504 If the host has an x86_64 architecture, depending on if the vendor packages contain the defect, the NSS provider will not function correctly.
1506 To work around this problem, find the JRE home directory and edit the file _lib/security/java.security_.
1507 Edit the file to comment out the line:
1509 [source]
1510 ----
1511 security.provider.1=sun.security.pkcs11.SunPKCS11 ${java.home}/lib/security/nss.cfg
1512 ----
1514 Then renumber the remaining providers accordingly.
1516 == Operating System Specific Issues
1518 === Page Allocation Failure
1520 NOTE: This issue is known to affect CentOS 6.2 and possibly CentOS 6.5.
1521 It may also affect some versions of Red Hat Enterprise Linux, according to https://bugzilla.redhat.com/show_bug.cgi?id=770545.
1523 Some users have reported seeing the following error:
1525 ----
1526 kernel: java: page allocation failure. order:4, mode:0x20
1527 ----
1529 Raising the value of `min_free_kbytes` was reported to fix this problem.
1530 This parameter is set to a percentage of the amount of RAM on your system, and is described in more detail at http://www.centos.org/docs/5/html/5.1/Deployment_Guide/s3-proc-sys-vm.html.
1532 To find the current value on your system, run the following command:
1534 ----
1535 [user@host]# cat /proc/sys/vm/min_free_kbytes
1536 ----
1538 Next, raise the value.
1539 Try doubling, then quadrupling the value.
1540 Note that setting the value too low or too high could have detrimental effects on your system.
1541 Consult your operating system vendor for specific recommendations.
1543 Use the following command to modify the value of `min_free_kbytes`, substituting _<value>_ with your intended value:
1545 ----
1546 [user@host]# echo <value> > /proc/sys/vm/min_free_kbytes
1547 ----
1549 == JDK Issues
1551 === NoSuchMethodError: java.util.concurrent.ConcurrentHashMap.keySet
1553 If you see this in your logs:
1554 [source]
1555 ----
1556 Caused by: java.lang.NoSuchMethodError: java.util.concurrent.ConcurrentHashMap.keySet()Ljava/util/concurrent/ConcurrentHashMap$KeySetView;
1557   at org.apache.hadoop.hbase.master.ServerManager.findServerWithSameHostnamePortWithLock(ServerManager.java:393)
1558   at org.apache.hadoop.hbase.master.ServerManager.checkAndRecordNewServer(ServerManager.java:307)
1559   at org.apache.hadoop.hbase.master.ServerManager.regionServerStartup(ServerManager.java:244)
1560   at org.apache.hadoop.hbase.master.MasterRpcServices.regionServerStartup(MasterRpcServices.java:304)
1561   at org.apache.hadoop.hbase.protobuf.generated.RegionServerStatusProtos$RegionServerStatusService$2.callBlockingMethod(RegionServerStatusProtos.java:7910)
1562   at org.apache.hadoop.hbase.ipc.RpcServer.call(RpcServer.java:2020)
1563   ... 4 more
1564 ----
1565 then check if you compiled with jdk8 and tried to run it on jdk7.
1566 If so, this won't work.
1567 Run on jdk8 or recompile with jdk7.
1568 See link:https://issues.apache.org/jira/browse/HBASE-10607[HBASE-10607 JDK8 NoSuchMethodError involving ConcurrentHashMap.keySet if running on JRE 7].