Return-Path: Delivered-To: apmail-hadoop-hbase-dev-archive@minotaur.apache.org Received: (qmail 86796 invoked from network); 29 Jan 2010 17:40:04 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.3) by minotaur.apache.org with SMTP; 29 Jan 2010 17:40:04 -0000 Received: (qmail 60221 invoked by uid 500); 29 Jan 2010 17:40:04 -0000 Delivered-To: apmail-hadoop-hbase-dev-archive@hadoop.apache.org Received: (qmail 60159 invoked by uid 500); 29 Jan 2010 17:40:04 -0000 Mailing-List: contact hbase-dev-help@hadoop.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: hbase-dev@hadoop.apache.org Delivered-To: mailing list hbase-dev@hadoop.apache.org Received: (qmail 60149 invoked by uid 99); 29 Jan 2010 17:40:04 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 29 Jan 2010 17:40:04 +0000 X-ASF-Spam-Status: No, hits=1.3 required=10.0 tests=SPF_PASS,URI_HEX X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of jdcryans@gmail.com designates 209.85.210.199 as permitted sender) Received: from [209.85.210.199] (HELO mail-yx0-f199.google.com) (209.85.210.199) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 29 Jan 2010 17:39:57 +0000 Received: by yxe37 with SMTP id 37so1934259yxe.31 for ; Fri, 29 Jan 2010 09:39:36 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:sender:received:in-reply-to :references:date:x-google-sender-auth:message-id:subject:from:to :content-type:content-transfer-encoding; bh=ftmOcaIrY7AtVomwFEF1cm2NbkCN3OjE9il69vloE5A=; b=qXULFvlWXI0/XvRa0eGox39QD3M6HwlJxuaeRaRJY28YlS4/+/PqpgbVR+f06gLM9f vc7l24+vyhuUeLJBTagg/3SHkJXcq6VrclrJrlD0rVZplKUpb9T+RG60MHjZFYS64U4k pnm014aHYvxKo/kc7emTBo3LrloijV3mpFU+s= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=mime-version:sender:in-reply-to:references:date :x-google-sender-auth:message-id:subject:from:to:content-type :content-transfer-encoding; b=LRdyHaX1TNihkjjOebnA6dvmwBSXStFkAJoDKe+dlpaJgAom+jE2b7t4zNSMZDSrNu 0YPqO2TjP/e/ysH8tTukYEksabPzGLo6Bx75uCOA2IL+Ulk+vqo6OSngahAtAcBpWxVo AihpWMsFOw+Iso3wJAn+L5Sd2K6Gz/lQuygPM= MIME-Version: 1.0 Sender: jdcryans@gmail.com Received: by 10.91.121.2 with SMTP id y2mr1215107agm.105.1264786775493; Fri, 29 Jan 2010 09:39:35 -0800 (PST) In-Reply-To: <7BC93F71D08F104A907F273FC6FF60AA6CED904F54@SC-MBXC1.TheFacebook.com> References: <7BC93F71D08F104A907F273FC6FF60AA6CEC50FF57@SC-MBXC1.TheFacebook.com> <7BC93F71D08F104A907F273FC6FF60AA6CED0C48E8@SC-MBXC1.TheFacebook.com> <7BC93F71D08F104A907F273FC6FF60AA6CED904F54@SC-MBXC1.TheFacebook.com> Date: Fri, 29 Jan 2010 09:39:35 -0800 X-Google-Sender-Auth: 830b6d2b3e8b26ec Message-ID: <31a243e71001290939x2b929632kb4c77ea02acc337@mail.gmail.com> Subject: Re: Cannot locate root region From: Jean-Daniel Cryans To: hbase-dev@hadoop.apache.org Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable I just created https://issues.apache.org/jira/browse/HBASE-2174 We handle addresses in different ways depending on which part of the code you're in. We should correct that everywhere by implementing a solution that also solves what you guys are seeing. J-D On Fri, Jan 29, 2010 at 8:33 AM, Kannan Muthukkaruppan wrote: > @Joy: The info stored in .META. for various regions as well as in the eph= emeral nodes for region servers in zookeeper are both already IP address ba= sed. So doesn't look like multi-homing and/or the other flexibilities you m= ention were a design goal as far as I can tell. > > Regarding: <<< doesn't the reverse ip lookup just once at RS startup time= ?>>>, what seems to be happening is this: > > A regionServer periodically sends a regionServerReport (RPC call) to the = master. A HServerInfo argument is passed as an argument and it identifies t= he sending region server's identity in IP address format. > > The master, in ServerManager class, maintains a serversToServerInfo map w= hich is hostname based. Every time a master receives a regionServerReport i= t converts the IP address based name to a hostname via the info.getServerNa= me() call. Normally this call returns the hostname, but we suspect that dur= ing the DNS flakiness, it returned an IP address based string. And so, this= caused ServerManager.java to think that it was hearing from a new server. = And this lead to: > > =A0HServerInfo storedInfo =3D serversToServerInfo.get(info.getServerName(= )); > =A0 =A0if (storedInfo =3D=3D null) { > =A0 =A0 =A0if (LOG.isDebugEnabled()) { > =A0 =A0 =A0 =A0LOG.debug("Received report from unknown server -- telling = it " + =A0 <<=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > =A0 =A0 =A0 =A0 =A0"to " + CALL_SERVER_STARTUP + ": " + info.getServerNam= e()); =A0<<=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > =A0 =A0 =A0} > > and bad things down the road. > > The above error message in our logs (example below) indeed identified the= host in IP address syntax, even though normally the getServerName call wou= ld return the info in hostname format. > > 2010-01-28 11:21:34,539 DEBUG org.apache.hadoop.hbase.master.ServerManage= r: Received report from unknown server -- telling it to MSG_CALL_SERVER_STA= RTUP: 10.129.68.203,60020,1263605543210 > > This affected three of our test clusters at the same time! > > Perhaps all we need to do is to change the ServerManager's internal maps = to all be IP based? That way we avoid/bypass the master having to look up t= he hostname on every heartbeat. > > regards, > Kannan > ________________________________________ > From: Joydeep Sarma [jsensarma@gmail.com] > Sent: Friday, January 29, 2010 1:20 AM > To: hbase-dev@hadoop.apache.org > Subject: Re: Cannot locate root region > > hadoop also uses the hostnames. if a host is multi-homed - it's > hostname is a better identifier (which still allows it to use > different nics/ips for actual traffic). it can help in the case the > cluster is migrated for example (all the ips change). one could have > the same hostname resolve to different ips depending on who's doing > the lookup (this happens in AWS where the same elastic hostname > resolves to private or public ip depending on where the peer is. so > clients can talk from outside AWS via public ips and master etc. can > talk over private ips). > > so lots of reasons i guess. doesn't the reverse ip lookup just once at > RS startup time? (wondering how this reconciles with the =A0DNS being > flaky after the cluster was up and running). > > On Thu, Jan 28, 2010 at 9:30 PM, Karthik Ranganathan > wrote: >> >> We did some more digging into this and here is the theory. >> >> 1. The regionservers use their local ip to lookup their hostnames and pa= ss that to the HMaster. The HMaster finds the server info by using this hos= tname as the key in the HashMap. >> >> HRegionServer.java >> reinitialize() - >> this.serverInfo =3D new HServerInfo(new HServerAddress( >> =A0 =A0 =A0new InetSocketAddress(address.getBindAddress(), >> =A0 =A0 =A0this.server.getListenerAddress().getPort())), System.currentT= imeMillis(), >> =A0 =A0 =A0this.conf.getInt("hbase.regionserver.info.port", 60030), mach= ineName); >> >> In run() - >> HMsg msgs[] =3D hbaseMaster.regionServerReport( >> =A0 =A0 =A0 =A0 =A0 =A0 =A0serverInfo, outboundArray, getMostLoadedRegio= ns()); >> >> >> 2. I have observed in the past that there could be some DNS flakiness wh= ich causes the IP address of the machines to be returned as their hostnames= . Guessing this is what happened. >> >> >> 3. The HMaster looks in the map for the above IP address (masquerading a= s the server name). It gets and does not find the entry in its map. So it a= ssumes that this is a new region server and issues a CALL_SERVER_STARTUP. >> >> >> 4. The region server that receives it is in fact already running (under = its real hostname) and enters the "HMaster panic" mode and bad stuff happen= s. >> >> ServerManager.java in regionServerReport() - >> =A0 =A0HServerInfo storedInfo =3D serversToServerInfo.get(info.getServer= Name()); >> =A0 =A0if (storedInfo =3D=3D null) { >> =A0 =A0 =A0// snip... >> =A0 =A0 =A0return new HMsg[] {CALL_SERVER_STARTUP}; >> =A0 =A0} >> >> >> Any reason why we use the hostname instead of the ip address in the map = that stores the regionserver info? >> >> Thanks >> Karthik >> >> >> -----Original Message----- >> From: Karthik Ranganathan [mailto:kranganathan@facebook.com] >> Sent: Thursday, January 28, 2010 3:58 PM >> To: hbase-dev@hadoop.apache.org >> Subject: Cannot locate root region >> >> Hey guys, >> >> Ran into some issues while testing and wanted to understand what has hap= pened better. Got the following exception when I went to the web UI >> >> Trying to contact region server 10.129.68.204:60020 for region .META.,,1= , row '', but failed after 3 attempts. >> Exceptions: >> org.apache.hadoop.hbase.NotServingRegionException: org.apache.hadoop.hba= se.NotServingRegionException: .META.,,1 >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.regionserver.HRegionServer.get= Region(HRegionServer.java:2254) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.regionserver.HRegionServer.ope= nScanner(HRegionServer.java:1837) >> =A0 =A0 =A0 =A0at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown So= urce) >> =A0 =A0 =A0 =A0at sun.reflect.DelegatingMethodAccessorImpl.invoke(Delega= tingMethodAccessorImpl.java:25) >> =A0 =A0 =A0 =A0at java.lang.reflect.Method.invoke(Method.java:597) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBase= RPC.java:648) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HB= aseServer.java:915) >> >> >> From a program that reads from a HBase table: >> java.lang.reflect.UndeclaredThrowableException >> =A0 =A0 =A0 =A0at $Proxy1.getRegionInfo(Unknown Source) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.client.HConnectionManager$Tabl= eServers.locateRootRegion(HConnectionManager.java:985) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.client.HConnectionManager$Tabl= eServers.locateRegion(HConnectionManager.java:625) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.client.HConnectionManager$Tabl= eServers.locateRegion(HConnectionManager.java:601) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.client.HConnectionManager$Tabl= eServers.locateRegionInMeta(HConnectionManager.java:675) >> >> >> >> Followed =A0up on the hmaster's log: >> >> 2010-01-28 11:21:16,148 INFO org.apache.hadoop.hbase.master.BaseScanner:= RegionManager.metaScanner scan of 1 row(s) of meta region {server: 10.129.= 68.204:60020, regionname: .META.,,1, startKey: <>} complete >> 2010-01-28 11:21:16,148 INFO org.apache.hadoop.hbase.master.BaseScanner:= All 1 .META. region(s) scanned >> 2010-01-28 11:21:34,539 DEBUG org.apache.hadoop.hbase.master.ServerManag= er: Received report from unknown server -- telling it to MSG_CALL_SERVER_ST= ARTUP: 10.129.68.203,60020,1263605543210 >> 2010-01-28 11:21:35,622 INFO org.apache.hadoop.hbase.master.ServerManage= r: Received start message from: hbasetest004.ash1.facebook.com,60020,126470= 6494600 >> 2010-01-28 11:21:36,649 DEBUG org.apache.hadoop.hbase.zookeeper.ZooKeepe= rWrapper: Updated ZNode /hbase/rs/1264706494600 with data 10.129.68.203:600= 20 >> 2010-01-28 11:21:40,704 INFO org.apache.hadoop.ipc.HBaseServer: IPC Serv= er handler 39 on 60000, call createTable({NAME =3D> 'test1', FAMILIES =3D> = [{NAME =3D> 'cf1', VERSIONS =3D> '3', COMPRESSION =3D> 'NONE', TTL =3D> '21= 47483647', BLOCKSIZE =3D> '65536', IN_MEMORY =3D> 'false', BLOCKCACHE =3D> = 'true'}]}) from 10.131.29.183:63308: error: org.apache.hadoop.hbase.TableEx= istsException: test1 >> org.apache.hadoop.hbase.TableExistsException: test1 >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.master.HMaster.createTable(HMa= ster.java:792) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.master.HMaster.createTable(HMa= ster.java:756) >> =A0 =A0 =A0 =A0at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown So= urce) >> =A0 =A0 =A0 =A0at sun.reflect.DelegatingMethodAccessorImpl.invoke(Delega= tingMethodAccessorImpl.java:25) >> =A0 =A0 =A0 =A0at java.lang.reflect.Method.invoke(Method.java:597) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBase= RPC.java:648) >> =A0 =A0 =A0 =A0at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HB= aseServer.java:915) >> >> From a hregionserver's logs: >> >> 2010-01-28 11:20:22,589 DEBUG org.apache.hadoop.hbase.io.hfile.LruBlockC= ache: Cache Stats: Sizes: Total=3D19.661453MB (20616528), Free=3D2377.0137M= B (2492479408), Max=3D2396.675MB (2513095936), Counts: Blocks=3D0, Access= =3D0, Hit=3D0, Miss=3D0, Evictions=3D0, Evicted=3D0, Ratios: Hit Ratio=3DNa= N%, Miss Ratio=3DNaN%, Evicted/Run=3DNaN >> 2010-01-28 11:21:22,588 DEBUG org.apache.hadoop.hbase.io.hfile.LruBlockC= ache: Cache Stats: Sizes: Total=3D19.661453MB (20616528), Free=3D2377.0137M= B (2492479408), Max=3D2396.675MB (2513095936), Counts: Blocks=3D0, Access= =3D0, Hit=3D0, Miss=3D0, Evictions=3D0, Evicted=3D0, Ratios: Hit Ratio=3DNa= N%, Miss Ratio=3DNaN%, Evicted/Run=3DNaN >> 2010-01-28 11:22:18,794 INFO org.apache.hadoop.hbase.regionserver.HRegio= nServer: MSG_CALL_SERVER_STARTUP >> >> >> The code says the following: >> =A0 =A0 =A0 =A0 =A0 =A0 =A0case MSG_CALL_SERVER_STARTUP: >> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0// We the MSG_CALL_SERVER_STARTUP on star= tup but we can also >> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0// get it when the master is panicking be= cause for instance >> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0// the HDFS has been yanked out from unde= r it. =A0Be wary of >> =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0// this message. >> >> Any ideas on what is going on? The best I can come up with is perhaps a = flaky DNS - would that explain this? This happened on three of our test clu= sters at almost the same time. Also, what is the most graceful/simplest way= to recover from this? >> >> >> Thanks >> Karthik >> >> >