You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by Jay Wilson <re...@circle-cross-jn.com> on 2012/07/03 19:08:28 UTC
HMASTER -- odd messages ?
My HMaster and HRegionservers start and run for awhile.
Looking at the messages, there are appear to be some Datanodes with some
issues, HLogSplitter has some block issues, the HMaster appears to drop
off the network (i know bad), then it comes back, and then the cluster
runs for about 10 more minutes before everything aborts.
Questions:
. Are HLogSplitter block error messages common?
. Would Datanode issues impact the HMaster stability?
. Other than an actual network issue is there anything that can cause
a "No route to host"
Thank you
---
Jay Wilson
2012-07-03 09:04:58,266 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
finished
2012-07-03 09:04:58,273 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Archived
processed log
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-03,60020,1341328322971-splitting/devrackA-03%3A60020.1341328323503
to
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.oldlogs/devrackA-03%3A60020.1341328323503
2012-07-03 09:04:58,275 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: hlog file
splitting completed in 1052 ms for
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-03,60020,1341328322971-splitting
2012-07-03 09:04:58,277 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1
hlog(s) in
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting
2012-07-03 09:04:58,277 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-0,5,main]: starting
2012-07-03 09:04:58,277 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-1,5,main]: starting
2012-07-03 09:04:58,278 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-2,5,main]: starting
2012-07-03 09:04:58,278 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1
of 1:
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517,
length=124
2012-07-03 09:04:58,278 INFO org.apache.hadoop.hbase.util.FSUtils:
Recovering file
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517
2012-07-03 09:04:59,282 INFO org.apache.hadoop.hbase.util.FSUtils:
Finished lease recover attempt for
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517
2012-07-03 09:04:59,339 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=0 entries
from
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517
2012-07-03 09:04:59,341 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split
writer threads to finish
2012-07-03 09:04:59,342 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
finished
2012-07-03 09:04:59,347 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Archived
processed log
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517
to
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.oldlogs/devrackA-04%3A60020.1341328323517
2012-07-03 09:04:59,349 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: hlog file
splitting completed in 1073 ms for
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting
2012-07-03 09:04:59,352 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1
hlog(s) in
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting
2012-07-03 09:04:59,352 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-0,5,main]: starting
2012-07-03 09:04:59,352 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-1,5,main]: starting
2012-07-03 09:04:59,352 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1
of 1:
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502,
length=295
2012-07-03 09:04:59,353 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-2,5,main]: starting
2012-07-03 09:04:59,353 INFO org.apache.hadoop.hbase.util.FSUtils:
Recovering file
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
2012-07-03 09:05:00,356 INFO org.apache.hadoop.hbase.util.FSUtils:
Finished lease recover attempt for
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
2012-07-03 09:05:00,373 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=1 entries
from
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
2012-07-03 09:05:00,375 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split
writer threads to finish
2012-07-03 09:05:00,394 DEBUG
org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: using
new createWriter -- HADOOP-6840
2012-07-03 09:05:00,395 DEBUG
org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter:
Path=hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp,
syncFs=true, hflush=false
2012-07-03 09:05:00,395 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer
path=hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
region=70236052
2012-07-03 09:05:00,395 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
finished
2012-07-03 09:05:00,400 INFO org.apache.hadoop.hdfs.DFSClient: Exception
in createBlockOutputStream 172.18.0.9:50010
java.net.NoRouteToHostException: No route to host
2012-07-03 09:05:00,400 INFO org.apache.hadoop.hdfs.DFSClient:
Abandoning block blk_6816372941597656825_1399
2012-07-03 09:05:00,401 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
datanode 172.18.0.9:50010
2012-07-03 09:05:00,465 INFO org.apache.hadoop.hdfs.DFSClient: Exception
in createBlockOutputStream 172.18.0.85:50010 java.io.IOException: Bad
connect ack with firstBadLink as 172.18.0.19:50010
2012-07-03 09:05:00,465 INFO org.apache.hadoop.hdfs.DFSClient:
Abandoning block blk_7510580014836927340_1399
2012-07-03 09:05:00,466 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
datanode 172.18.0.19:50010
2012-07-03 09:05:00,524 INFO org.apache.hadoop.hdfs.DFSClient: Exception
in createBlockOutputStream 172.18.0.86:50010 java.io.IOException: Bad
connect ack with firstBadLink as 172.18.0.2:50010
2012-07-03 09:05:00,524 INFO org.apache.hadoop.hdfs.DFSClient:
Abandoning block blk_-8919183185614310524_1399
2012-07-03 09:05:00,525 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
datanode 172.18.0.2:50010
2012-07-03 09:05:00,527 INFO org.apache.hadoop.hdfs.DFSClient: Exception
in createBlockOutputStream 172.18.0.8:50010
java.net.NoRouteToHostException: No route to host
2012-07-03 09:05:00,527 INFO org.apache.hadoop.hdfs.DFSClient:
Abandoning block blk_-4401944489880007215_1399
2012-07-03 09:05:00,528 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
datanode 172.18.0.8:50010
2012-07-03 09:05:00,528 WARN org.apache.hadoop.hdfs.DFSClient:
DataStreamer Exception: java.io.IOException: Unable to create new block.
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:3539)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2300(DFSClient.java:2720)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2915)
2012-07-03 09:05:00,528 WARN org.apache.hadoop.hdfs.DFSClient: Error
Recovery for block blk_-4401944489880007215_1399 bad datanode[0] nodes
== null
2012-07-03 09:05:00,529 WARN org.apache.hadoop.hdfs.DFSClient: Could not
get block locations. Source file
"/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp"
- Aborting...
2012-07-03 09:05:00,530 ERROR
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Couldn't close
log at
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
java.net.NoRouteToHostException: No route to host
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at
sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:567)
at
org.apache.hadoop.net.SocketIOWithTimeout.connect(SocketIOWithTimeout.java:206)
at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:429)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.createBlockOutputStream(DFSClient.java:3567)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:3522)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2300(DFSClient.java:2720)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2915)
2012-07-03 09:05:00,536 WARN
org.apache.hadoop.hbase.master.MasterFileSystem: Failed splitting of
[devrackA-03,60020,1341328322971, devrackA-04,60020,1341328322988,
devrackA-05,60020,1341328322976]
java.net.NoRouteToHostException: No route to host
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at
sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:567)
at
org.apache.hadoop.net.SocketIOWithTimeout.connect(SocketIOWithTimeout.java:206)
at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:429)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.createBlockOutputStream(DFSClient.java:3567)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:3522)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2300(DFSClient.java:2720)
at
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2915)
2012-07-03 09:05:30,546 INFO
org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting
doesn't belong to a known region server, splitting
2012-07-03 09:05:30,546 INFO
org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-06,60020,1341331494245
belongs to an existing region server
2012-07-03 09:05:30,546 INFO
org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackB-07,60020,1341331494221
belongs to an existing region server
2012-07-03 09:05:30,547 INFO
org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackB-08,60020,1341331494254
belongs to an existing region server
2012-07-03 09:05:30,552 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1
hlog(s) in
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting
2012-07-03 09:05:30,553 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-0,5,main]: starting
2012-07-03 09:05:30,553 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-1,5,main]: starting
2012-07-03 09:05:30,553 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1
of 1:
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502,
length=295
2012-07-03 09:05:30,553 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
Thread[WriterThread-2,5,main]: starting
2012-07-03 09:05:30,553 INFO org.apache.hadoop.hbase.util.FSUtils:
Recovering file
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
2012-07-03 09:05:31,556 INFO org.apache.hadoop.hbase.util.FSUtils:
Finished lease recover attempt for
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
2012-07-03 09:05:31,562 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=1 entries
from
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
2012-07-03 09:05:31,564 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split
writer threads to finish
2012-07-03 09:05:31,570 DEBUG
org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: using
new createWriter -- HADOOP-6840
2012-07-03 09:05:31,571 DEBUG
org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter:
Path=hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp,
syncFs=true, hflush=false
2012-07-03 09:05:31,571 DEBUG
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer
path=hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
region=70236052
2012-07-03 09:05:31,571 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
finished
2012-07-03 09:05:31,573 INFO org.apache.hadoop.hdfs.DFSClient: Exception
in createBlockOutputStream 172.18.0.12:50010
java.net.NoRouteToHostException: No route to host
2012-07-03 09:05:31,573 INFO org.apache.hadoop.hdfs.DFSClient:
Abandoning block blk_6969426679504099105_1401
2012-07-03 09:05:31,574 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
datanode 172.18.0.12:50010
2012-07-03 09:05:31,712 INFO
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
(wrote 1 edits in 8ms)
2012-07-03 09:05:31,714 WARN
org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Found existing
old edits file. It could be the result of a previous failed split
attempt. Deleting
hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046,
length=0
Re: HMASTER -- odd messages ?
Posted by Amandeep Khurana <am...@gmail.com>.
On Tuesday, July 3, 2012 at 10:08 AM, Jay Wilson wrote:
> 2012-07-03 09:05:00,530 ERROR
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Couldn't close
> log at
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
> java.net.NoRouteToHostException: No route to host
> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:567)
> at
> org.apache.hadoop.net.SocketIOWithTimeout.connect(SocketIOWithTimeout.java:206)
> at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:429)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.createBlockOutputStream(DFSClient.java:3567)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:3522)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2300(DFSClient.java:2720)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2915)
> 2012-07-03 09:05:00,536 WARN
> org.apache.hadoop.hbase.master.MasterFileSystem: Failed splitting of
> [devrackA-03,60020,1341328322971, devrackA-04,60020,1341328322988,
> devrackA-05,60020,1341328322976]
> java.net.NoRouteToHostException: No route to host
> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:567)
> at
> org.apache.hadoop.net.SocketIOWithTimeout.connect(SocketIOWithTimeout.java:206)
> at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:429)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.createBlockOutputStream(DFSClient.java:3567)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:3522)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2300(DFSClient.java:2720)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2915)
NoRouteToHostException hints at some network trouble… Region servers aren't able to talk to the underlying Datanode processes. That would cause grief for sure.
Looks like you have been having network trouble from the ZK issues that you mentioned earlier too. Maybe your TOR is dropping packets or something like that? A ping won't tell you that though. Do you have any sort of monitoring in place that can give you insight into how the network is performing?
Re: HMASTER -- odd messages ?
Posted by N Keywal <nk...@gmail.com>.
> Would Datanode issues impact the HMaster stability?
Yes and no. If you have only a few datanodes down, their should be no
issue. When there are enough missing datanodes to make some blocks not
available at all in the cluster, there are many tasks that can not be
done anymore (to say the least, and depending on the blocks), for the
master or for the region server. In this case the ideal contract for
the master would be to survive, does the tasks it can do, logs the
tasks it can't do. Today, the contract for the master in such
situation is more "do your best but don't corrupt anything". Note that
there is an autorestart option in the scripts in the planned 0.96, so
the master can be asked to restart automatically if not stopped
properly.
N.
On Tue, Jul 3, 2012 at 7:08 PM, Jay Wilson
<re...@circle-cross-jn.com> wrote:
> My HMaster and HRegionservers start and run for awhile.
>
> Looking at the messages, there are appear to be some Datanodes with some
> issues, HLogSplitter has some block issues, the HMaster appears to drop
> off the network (i know bad), then it comes back, and then the cluster
> runs for about 10 more minutes before everything aborts.
>
> Questions:
> . Are HLogSplitter block error messages common?
> . Would Datanode issues impact the HMaster stability?
> . Other than an actual network issue is there anything that can cause
> a "No route to host"
>
> Thank you
> ---
> Jay Wilson
>
> 2012-07-03 09:04:58,266 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
> finished
> 2012-07-03 09:04:58,273 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Archived
> processed log
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-03,60020,1341328322971-splitting/devrackA-03%3A60020.1341328323503
> to
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.oldlogs/devrackA-03%3A60020.1341328323503
> 2012-07-03 09:04:58,275 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: hlog file
> splitting completed in 1052 ms for
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-03,60020,1341328322971-splitting
> 2012-07-03 09:04:58,277 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1
> hlog(s) in
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting
> 2012-07-03 09:04:58,277 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-0,5,main]: starting
> 2012-07-03 09:04:58,277 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-1,5,main]: starting
> 2012-07-03 09:04:58,278 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-2,5,main]: starting
> 2012-07-03 09:04:58,278 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1
> of 1:
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517,
> length=124
> 2012-07-03 09:04:58,278 INFO org.apache.hadoop.hbase.util.FSUtils:
> Recovering file
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517
> 2012-07-03 09:04:59,282 INFO org.apache.hadoop.hbase.util.FSUtils:
> Finished lease recover attempt for
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517
> 2012-07-03 09:04:59,339 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=0 entries
> from
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517
> 2012-07-03 09:04:59,341 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split
> writer threads to finish
> 2012-07-03 09:04:59,342 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
> finished
> 2012-07-03 09:04:59,347 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Archived
> processed log
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting/devrackA-04%3A60020.1341328323517
> to
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.oldlogs/devrackA-04%3A60020.1341328323517
> 2012-07-03 09:04:59,349 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: hlog file
> splitting completed in 1073 ms for
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-04,60020,1341328322988-splitting
> 2012-07-03 09:04:59,352 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1
> hlog(s) in
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting
> 2012-07-03 09:04:59,352 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-0,5,main]: starting
> 2012-07-03 09:04:59,352 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-1,5,main]: starting
> 2012-07-03 09:04:59,352 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1
> of 1:
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502,
> length=295
> 2012-07-03 09:04:59,353 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-2,5,main]: starting
> 2012-07-03 09:04:59,353 INFO org.apache.hadoop.hbase.util.FSUtils:
> Recovering file
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
> 2012-07-03 09:05:00,356 INFO org.apache.hadoop.hbase.util.FSUtils:
> Finished lease recover attempt for
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
> 2012-07-03 09:05:00,373 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=1 entries
> from
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
> 2012-07-03 09:05:00,375 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split
> writer threads to finish
> 2012-07-03 09:05:00,394 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: using
> new createWriter -- HADOOP-6840
> 2012-07-03 09:05:00,395 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter:
> Path=hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp,
> syncFs=true, hflush=false
> 2012-07-03 09:05:00,395 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer
> path=hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
> region=70236052
> 2012-07-03 09:05:00,395 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
> finished
> 2012-07-03 09:05:00,400 INFO org.apache.hadoop.hdfs.DFSClient: Exception
> in createBlockOutputStream 172.18.0.9:50010
> java.net.NoRouteToHostException: No route to host
> 2012-07-03 09:05:00,400 INFO org.apache.hadoop.hdfs.DFSClient:
> Abandoning block blk_6816372941597656825_1399
> 2012-07-03 09:05:00,401 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
> datanode 172.18.0.9:50010
> 2012-07-03 09:05:00,465 INFO org.apache.hadoop.hdfs.DFSClient: Exception
> in createBlockOutputStream 172.18.0.85:50010 java.io.IOException: Bad
> connect ack with firstBadLink as 172.18.0.19:50010
> 2012-07-03 09:05:00,465 INFO org.apache.hadoop.hdfs.DFSClient:
> Abandoning block blk_7510580014836927340_1399
> 2012-07-03 09:05:00,466 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
> datanode 172.18.0.19:50010
> 2012-07-03 09:05:00,524 INFO org.apache.hadoop.hdfs.DFSClient: Exception
> in createBlockOutputStream 172.18.0.86:50010 java.io.IOException: Bad
> connect ack with firstBadLink as 172.18.0.2:50010
> 2012-07-03 09:05:00,524 INFO org.apache.hadoop.hdfs.DFSClient:
> Abandoning block blk_-8919183185614310524_1399
> 2012-07-03 09:05:00,525 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
> datanode 172.18.0.2:50010
> 2012-07-03 09:05:00,527 INFO org.apache.hadoop.hdfs.DFSClient: Exception
> in createBlockOutputStream 172.18.0.8:50010
> java.net.NoRouteToHostException: No route to host
> 2012-07-03 09:05:00,527 INFO org.apache.hadoop.hdfs.DFSClient:
> Abandoning block blk_-4401944489880007215_1399
> 2012-07-03 09:05:00,528 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
> datanode 172.18.0.8:50010
> 2012-07-03 09:05:00,528 WARN org.apache.hadoop.hdfs.DFSClient:
> DataStreamer Exception: java.io.IOException: Unable to create new block.
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:3539)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2300(DFSClient.java:2720)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2915)
>
> 2012-07-03 09:05:00,528 WARN org.apache.hadoop.hdfs.DFSClient: Error
> Recovery for block blk_-4401944489880007215_1399 bad datanode[0] nodes
> == null
> 2012-07-03 09:05:00,529 WARN org.apache.hadoop.hdfs.DFSClient: Could not
> get block locations. Source file
> "/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp"
> - Aborting...
> 2012-07-03 09:05:00,530 ERROR
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Couldn't close
> log at
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
> java.net.NoRouteToHostException: No route to host
> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:567)
> at
> org.apache.hadoop.net.SocketIOWithTimeout.connect(SocketIOWithTimeout.java:206)
> at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:429)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.createBlockOutputStream(DFSClient.java:3567)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:3522)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2300(DFSClient.java:2720)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2915)
> 2012-07-03 09:05:00,536 WARN
> org.apache.hadoop.hbase.master.MasterFileSystem: Failed splitting of
> [devrackA-03,60020,1341328322971, devrackA-04,60020,1341328322988,
> devrackA-05,60020,1341328322976]
> java.net.NoRouteToHostException: No route to host
> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
> at
> sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:567)
> at
> org.apache.hadoop.net.SocketIOWithTimeout.connect(SocketIOWithTimeout.java:206)
> at org.apache.hadoop.net.NetUtils.connect(NetUtils.java:429)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.createBlockOutputStream(DFSClient.java:3567)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.nextBlockOutputStream(DFSClient.java:3522)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2300(DFSClient.java:2720)
> at
> org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2915)
> 2012-07-03 09:05:30,546 INFO
> org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting
> doesn't belong to a known region server, splitting
> 2012-07-03 09:05:30,546 INFO
> org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-06,60020,1341331494245
> belongs to an existing region server
> 2012-07-03 09:05:30,546 INFO
> org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackB-07,60020,1341331494221
> belongs to an existing region server
> 2012-07-03 09:05:30,547 INFO
> org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackB-08,60020,1341331494254
> belongs to an existing region server
> 2012-07-03 09:05:30,552 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1
> hlog(s) in
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting
> 2012-07-03 09:05:30,553 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-0,5,main]: starting
> 2012-07-03 09:05:30,553 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-1,5,main]: starting
> 2012-07-03 09:05:30,553 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1
> of 1:
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502,
> length=295
> 2012-07-03 09:05:30,553 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-2,5,main]: starting
> 2012-07-03 09:05:30,553 INFO org.apache.hadoop.hbase.util.FSUtils:
> Recovering file
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
> 2012-07-03 09:05:31,556 INFO org.apache.hadoop.hbase.util.FSUtils:
> Finished lease recover attempt for
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
> 2012-07-03 09:05:31,562 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=1 entries
> from
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/.logs/devrackA-05,60020,1341328322976-splitting/devrackA-05%3A60020.1341328323502
> 2012-07-03 09:05:31,564 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split
> writer threads to finish
> 2012-07-03 09:05:31,570 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: using
> new createWriter -- HADOOP-6840
> 2012-07-03 09:05:31,571 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter:
> Path=hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp,
> syncFs=true, hflush=false
> 2012-07-03 09:05:31,571 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer
> path=hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
> region=70236052
> 2012-07-03 09:05:31,571 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
> finished
> 2012-07-03 09:05:31,573 INFO org.apache.hadoop.hdfs.DFSClient: Exception
> in createBlockOutputStream 172.18.0.12:50010
> java.net.NoRouteToHostException: No route to host
> 2012-07-03 09:05:31,573 INFO org.apache.hadoop.hdfs.DFSClient:
> Abandoning block blk_6969426679504099105_1401
> 2012-07-03 09:05:31,574 INFO org.apache.hadoop.hdfs.DFSClient: Excluding
> datanode 172.18.0.12:50010
> 2012-07-03 09:05:31,712 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046.temp
> (wrote 1 edits in 8ms)
> 2012-07-03 09:05:31,714 WARN
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Found existing
> old edits file. It could be the result of a previous failed split
> attempt. Deleting
> hdfs://devrackA-00:8020/var/hbase-hadoop/hbase/-ROOT-/70236052/recovered.edits/0000000000000000046,
> length=0
>