The master does another lookup independent of the region server using the
hostname given by the region server:
ServerManager.java, regionServerReport() does:
HServerInfo storedInfo = serversToServerInfo.get(info.getServerName()); //
info.getServerName() is hostname
Which eventually does:
HServerAddress.getHostname()
HServerAddress' constructor creates the InetSocketAddress from the
hostname:port, which involves mapping the hostname to the ip address using a
lookup.
Thanks
Karthik
-----Original Message-----
From: Joydeep Sarma [mailto:[email protected]]
Sent: Friday, January 29, 2010 9:46 AM
To: [email protected]
Subject: Re: Cannot locate root region
@Kannan - Karthik's mail said the reverse lookup happens in the RS
(not the master). the master simply tried to match the offered
hostname.
i dont know whose reading is right - but if it's the RS - i didn't
understand why that wasn't just the reverse lookup done once at
bootstrap time (which wouldn't be affected by ongoing DNS badness).
On Fri, Jan 29, 2010 at 9:39 AM, Jean-Daniel Cryans <[email protected]> wrote:
> 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
> <[email protected]> wrote:
>> @Joy: The info stored in .META. for various regions as well as in the
>> ephemeral nodes for region servers in zookeeper are both already IP address
>> based. So doesn't look like multi-homing and/or the other flexibilities you
>> mention 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
>> the sending region server's identity in IP address format.
>>
>> The master, in ServerManager class, maintains a serversToServerInfo map
>> which is hostname based. Every time a master receives a regionServerReport
>> it converts the IP address based name to a hostname via the
>> info.getServerName() call. Normally this call returns the hostname, but we
>> suspect that during 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:
>>
>> HServerInfo storedInfo = serversToServerInfo.get(info.getServerName());
>> if (storedInfo == null) {
>> if (LOG.isDebugEnabled()) {
>> LOG.debug("Received report from unknown server -- telling it " +
>> <<============
>> "to " + CALL_SERVER_STARTUP + ": " + info.getServerName());
>> <<============
>> }
>>
>> 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 would
>> return the info in hostname format.
>>
>> 2010-01-28 11:21:34,539 DEBUG org.apache.hadoop.hbase.master.ServerManager:
>> Received report from unknown server -- telling it to
>> MSG_CALL_SERVER_STARTUP: 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 the
>> hostname on every heartbeat.
>>
>> regards,
>> Kannan
>> ________________________________________
>> From: Joydeep Sarma [[email protected]]
>> Sent: Friday, January 29, 2010 1:20 AM
>> To: [email protected]
>> 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 DNS being
>> flaky after the cluster was up and running).
>>
>> On Thu, Jan 28, 2010 at 9:30 PM, Karthik Ranganathan
>> <[email protected]> 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 pass
>>> that to the HMaster. The HMaster finds the server info by using this
>>> hostname as the key in the HashMap.
>>>
>>> HRegionServer.java
>>> reinitialize() -
>>> this.serverInfo = new HServerInfo(new HServerAddress(
>>> new InetSocketAddress(address.getBindAddress(),
>>> this.server.getListenerAddress().getPort())),
>>> System.currentTimeMillis(),
>>> this.conf.getInt("hbase.regionserver.info.port", 60030), machineName);
>>>
>>> In run() -
>>> HMsg msgs[] = hbaseMaster.regionServerReport(
>>> serverInfo, outboundArray, getMostLoadedRegions());
>>>
>>>
>>> 2. I have observed in the past that there could be some DNS flakiness which
>>> 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 as
>>> the server name). It gets and does not find the entry in its map. So it
>>> assumes 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 happens.
>>>
>>> ServerManager.java in regionServerReport() -
>>> HServerInfo storedInfo = serversToServerInfo.get(info.getServerName());
>>> if (storedInfo == null) {
>>> // snip...
>>> return new HMsg[] {CALL_SERVER_STARTUP};
>>> }
>>>
>>>
>>> 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:[email protected]]
>>> Sent: Thursday, January 28, 2010 3:58 PM
>>> To: [email protected]
>>> Subject: Cannot locate root region
>>>
>>> Hey guys,
>>>
>>> Ran into some issues while testing and wanted to understand what has
>>> happened 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.hbase.NotServingRegionException: .META.,,1
>>> at
>>> org.apache.hadoop.hbase.regionserver.HRegionServer.getRegion(HRegionServer.java:2254)
>>> at
>>> org.apache.hadoop.hbase.regionserver.HRegionServer.openScanner(HRegionServer.java:1837)
>>> at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
>>> at
>>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>> at java.lang.reflect.Method.invoke(Method.java:597)
>>> at
>>> org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:648)
>>> at
>>> org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
>>>
>>>
>>> From a program that reads from a HBase table:
>>> java.lang.reflect.UndeclaredThrowableException
>>> at $Proxy1.getRegionInfo(Unknown Source)
>>> at
>>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRootRegion(HConnectionManager.java:985)
>>> at
>>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:625)
>>> at
>>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegion(HConnectionManager.java:601)
>>> at
>>> org.apache.hadoop.hbase.client.HConnectionManager$TableServers.locateRegionInMeta(HConnectionManager.java:675)
>>> <snip>
>>>
>>>
>>> Followed up 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.ServerManager:
>>> Received report from unknown server -- telling it to
>>> MSG_CALL_SERVER_STARTUP: 10.129.68.203,60020,1263605543210
>>> 2010-01-28 11:21:35,622 INFO org.apache.hadoop.hbase.master.ServerManager:
>>> Received start message from:
>>> hbasetest004.ash1.facebook.com,60020,1264706494600
>>> 2010-01-28 11:21:36,649 DEBUG
>>> org.apache.hadoop.hbase.zookeeper.ZooKeeperWrapper: Updated ZNode
>>> /hbase/rs/1264706494600 with data 10.129.68.203:60020
>>> 2010-01-28 11:21:40,704 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
>>> handler 39 on 60000, call createTable({NAME => 'test1', FAMILIES => [{NAME
>>> => 'cf1', VERSIONS => '3', COMPRESSION => 'NONE', TTL => '2147483647',
>>> BLOCKSIZE => '65536', IN_MEMORY => 'false', BLOCKCACHE => 'true'}]}) from
>>> 10.131.29.183:63308: error: org.apache.hadoop.hbase.TableExistsException:
>>> test1
>>> org.apache.hadoop.hbase.TableExistsException: test1
>>> at
>>> org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:792)
>>> at
>>> org.apache.hadoop.hbase.master.HMaster.createTable(HMaster.java:756)
>>> at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
>>> at
>>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>> at java.lang.reflect.Method.invoke(Method.java:597)
>>> at
>>> org.apache.hadoop.hbase.ipc.HBaseRPC$Server.call(HBaseRPC.java:648)
>>> at
>>> org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:915)
>>>
>>> From a hregionserver's logs:
>>>
>>> 2010-01-28 11:20:22,589 DEBUG
>>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
>>> Total=19.661453MB (20616528), Free=2377.0137MB (2492479408), Max=2396.675MB
>>> (2513095936), Counts: Blocks=0, Access=0, Hit=0, Miss=0, Evictions=0,
>>> Evicted=0, Ratios: Hit Ratio=NaN%, Miss Ratio=NaN%, Evicted/Run=NaN
>>> 2010-01-28 11:21:22,588 DEBUG
>>> org.apache.hadoop.hbase.io.hfile.LruBlockCache: Cache Stats: Sizes:
>>> Total=19.661453MB (20616528), Free=2377.0137MB (2492479408), Max=2396.675MB
>>> (2513095936), Counts: Blocks=0, Access=0, Hit=0, Miss=0, Evictions=0,
>>> Evicted=0, Ratios: Hit Ratio=NaN%, Miss Ratio=NaN%, Evicted/Run=NaN
>>> 2010-01-28 11:22:18,794 INFO
>>> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_CALL_SERVER_STARTUP
>>>
>>>
>>> The code says the following:
>>> case MSG_CALL_SERVER_STARTUP:
>>> // We the MSG_CALL_SERVER_STARTUP on startup but we can also
>>> // get it when the master is panicking because for instance
>>> // the HDFS has been yanked out from under it. Be wary of
>>> // 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
>>> clusters at almost the same time. Also, what is the most graceful/simplest
>>> way to recover from this?
>>>
>>>
>>> Thanks
>>> Karthik
>>>
>>>
>>
>
