Return-Path: X-Original-To: apmail-hbase-user-archive@www.apache.org Delivered-To: apmail-hbase-user-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 0D17CC4C4 for ; Tue, 3 Jul 2012 17:33:08 +0000 (UTC) Received: (qmail 65941 invoked by uid 500); 3 Jul 2012 17:33:06 -0000 Delivered-To: apmail-hbase-user-archive@hbase.apache.org Received: (qmail 65901 invoked by uid 500); 3 Jul 2012 17:33:06 -0000 Mailing-List: contact user-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user@hbase.apache.org Delivered-To: mailing list user@hbase.apache.org Received: (qmail 65892 invoked by uid 99); 3 Jul 2012 17:33:05 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 03 Jul 2012 17:33:05 +0000 X-ASF-Spam-Status: No, hits=-0.7 required=5.0 tests=FSL_RCVD_USER,RCVD_IN_DNSWL_LOW,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of nkeywal@gmail.com designates 74.125.82.51 as permitted sender) Received: from [74.125.82.51] (HELO mail-wg0-f51.google.com) (74.125.82.51) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 03 Jul 2012 17:33:00 +0000 Received: by wgbed3 with SMTP id ed3so4871052wgb.20 for ; Tue, 03 Jul 2012 10:32:39 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type; bh=J47n81UZWfaf6H+1SwxS/90AzcxkV3sGebvBdAVCJH0=; b=0sFDrQuJiYToDmmnZj7HstauWhUl/lIyy8BHoQ83mYLQP3srl0buNo3OH5cSIp0yuQ kM++Fpou7iAK5bdFuiEpg+kmSTMd4T15Kahs1gLYMOKRU5T6RPf7MZbJtAkfY1YNStOz 3XR3VRj7oCrbEIZXGPTZSv6ODdv0h61ppOkXni1mT1G3Zm+UCDIJHYlxVYB3H8UUGq2Q mAFw9Ibe1iG4xLg7wnlRfXG8VfqmZt/N/ncgR9wOLL6rK3w4H10Oig3nbh5NPmARgIjH kTBUa/dkm8w7pMBieroYphLn6zbWTKmmpc7fuBr/Z+An+jhENMuCYo02piYE+82c2PEz aONw== MIME-Version: 1.0 Received: by 10.180.14.34 with SMTP id m2mr26869363wic.22.1341336759174; Tue, 03 Jul 2012 10:32:39 -0700 (PDT) Received: by 10.194.8.197 with HTTP; Tue, 3 Jul 2012 10:32:39 -0700 (PDT) In-Reply-To: <4FF3270C.6030603@circle-cross-jn.com> References: <4FF3270C.6030603@circle-cross-jn.com> Date: Tue, 3 Jul 2012 19:32:39 +0200 Message-ID: Subject: Re: HMASTER -- odd messages ? From: N Keywal To: user@hbase.apache.org Content-Type: text/plain; charset=ISO-8859-1 X-Virus-Checked: Checked by ClamAV on apache.org > 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 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 >