最近公司HBase(CDH-4.6.0)遇到了一个麻烦问题,觉得有必要记录下整个解决的过程。
问题起因
用户在跑mapreduce任务,从hdfs读取文件想写入到hbase table的时候失败了(这是hbase提供的一种mapred能力)。这个问题发现在A环境(一个测试环境),自从启用了kerberos之后。运行了用户给的程序和自己写的sample之后,发现程序最后挂在NullPointerException上。这个NPE指示的是服务端的一个叫currentKey的变量为null。
[email protected],java.io.IOException: java.io.IOException: java.lang.NullPointerException
at org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager.createPassword(AuthenticationTokenSecretManager.java:129)
at org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager.createPassword(AuthenticationTokenSecretManager.java:57)
at org.apache.hadoop.security.token.Token.<init>(Token.java:70)
at org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager.generateToken(AuthenticationTokenSecretManager.java:162)
at org.apache.hadoop.hbase.security.token.TokenProvider.getAuthenticationToken(TokenProvider.java:91)
at sun.reflect.GeneratedMethodAccessor56.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.regionserver.HRegion.exec(HRegion.java:5610)
at org.apache.hadoop.hbase.regionserver.HRegionServer.execCoprocessor(HRegionServer.java:3918)
at sun.reflect.GeneratedMethodAccessor39.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.SecureRpcEngine$Server.call(SecureRpcEngine.java:311)
at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1428)
AuthenticationTokenSecretManager:
@Override
protected byte[] createPassword(AuthenticationTokenIdentifier identifier) {
long now = EnvironmentEdgeManager.currentTimeMillis();
AuthenticationKey secretKey = currentKey; //currentKey赋给secretKey
identifier.setKeyId(secretKey.getKeyId()); //NPE在这里抛出的,也就是currentKey为null
identifier.setIssueDate(now);
identifier.setExpirationDate(now + tokenMaxLifetime);
identifier.setSequenceNumber(tokenSeq.getAndIncrement());
return createPassword(WritableUtils.toByteArray(identifier),
secretKey.getKey());
}
问题定位
既然currentKey为null,那我们就去找它在哪里赋值的。阅读源码之后,了解到整个过程是这样的:
1.在开启kerberos之后,每个RegionServer都会有一个AuthenticationTokenSecretManager用来管理token。
2.这些manager中,只有一个leader,只有它能生产token,然后放到zookeeper里。其它manager通过感知zookeeper的变化来同步leader生产的token。leader通过竞争产生,谁先在ZK上创建 /hbase/tokenauth/keymaster 节点,谁就是leader。
AuthenticationTokenSecretManager$LeaderElector:
public void run() {
zkLeader.start();
zkLeader.waitToBecomeLeader(); //没有成为leader的人会一直阻塞在这里,直到感知到当前leader挂掉才会开始新一轮竞争
isMaster = true;
while (!stopped) {
long now = EnvironmentEdgeManager.currentTimeMillis();
// clear any expired
removeExpiredKeys(); //清除过期的token,同时也把它从ZK上移除
if (lastKeyUpdate + keyUpdateInterval < now) { //默认的周期是1天
// roll a new master key
rollCurrentKey(); //就是这个函数产生新的token,替换currenKey
}
try {
Thread.sleep(5000);
} catch (InterruptedException ie) {
if (LOG.isDebugEnabled()) {
LOG.debug("Interrupted waiting for next update", ie);
}
}
}
}
AuthenticationTokenSecretManager:
synchronized void rollCurrentKey() {
if (!leaderElector.isMaster()) {
LOG.info("Skipping rollCurrentKey() because not running as master.");
return;
}
long now = EnvironmentEdgeManager.currentTimeMillis();
AuthenticationKey prev = currentKey;
AuthenticationKey newKey = new AuthenticationKey(++idSeq,
Long.MAX_VALUE, // don‘t allow to expire until it‘s replaced by a new key
generateSecret());
allKeys.put(newKey.getKeyId(), newKey);
currentKey = newKey; //滚动currentKey,置为newKey
zkWatcher.addKeyToZK(newKey); //把新的token放到zookeeper
lastKeyUpdate = now;
if (prev != null) {
// make sure previous key is still stored
prev.setExpiration(now + tokenMaxLifetime); //prev是原来的newKey,是不会过期的,当有新的newKey替代它后,它的期限默认设置是7天
allKeys.put(prev.getKeyId(), prev);
zkWatcher.updateKeyInZK(prev);
}
}
3.既然token是由leader生产的,除非没有leader,才会没人生产。验证这个想法,我在zookeeper和一些region server启动当天的日志里找到了证据:
a) zk中的 /hbase/tokenauth/keymaster 节点用来存放leader的信息,然后进入zookeeper-client查看了下,根本没这个节点。
b) 一些尚有保留集群启动当天日志的region server上找到了如下异常:
org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager: Zookeeper initialization failed
org.apache.zookeeper.KeeperException$NoAuthException: KeeperErrorCode = NoAuth for /hbase/tokenauth/keys
at org.apache.zookeeper.KeeperException.create(KeeperException.java:113)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.createNonSequential(RecoverableZooKeeper.java:421)
at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.create(RecoverableZooKeeper.java:403)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.createWithParents(ZKUtil.java:1164)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.createWithParents(ZKUtil.java:1142)
at org.apache.hadoop.hbase.security.token.ZKSecretWatcher.start(ZKSecretWatcher.java:58)
at org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager.start(AuthenticationTokenSecretManager.java:105)
at org.apache.hadoop.hbase.ipc.SecureRpcEngine$Server.startThreads(SecureRpcEngine.java:275)
at org.apache.hadoop.hbase.ipc.HBaseServer.start(HBaseServer.java:1650)
at org.apache.hadoop.hbase.regionserver.HRegionServer.startServiceThreads(HRegionServer.java:1728)
at org.apache.hadoop.hbase.regionserver.HRegionServer.handleReportForDutyResponse(HRegionServer.java:1105)
at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer.java:753)
at java.lang.Thread.run(Thread.java:662)
这是AuthenticationTokenSecretManager启动时候失败了,启动的时候会先在ZK上创建/hbase/tokenauth/keys这个目录(即便这个目录已经存在也会执行这个操作,这是一种保证),这个目录用来存放leader生成的token。结果大家都没有/hbase/tokenauth的权限,所以都失败了(NoAuth for /hbase/tokenauth/keys,这里的提示有点瑕疵,实际上/hbase/tokenauth没有权限导致的)。然而发生这样的严重错误,server的启动并没有被终止,而是继续运行下去,留下了隐患。
AuthenticationTokenSecretManager:
public void start() {
try {
// populate any existing keys
this.zkWatcher.start(); //这里抛出的KeeperException
// try to become leader
this.leaderElector.start(); //这里竞争leader,但是因为异常这里不会被执行,所以没有人去竞争leader
} catch (KeeperException ke) {
LOG.error("Zookeeper initialization failed", ke); //发生异常,仅仅是打印一条error信息,而没有abort。在Hbase的很多地方,发生这样的错误都是会abort server的。
}
}
4.错误原因就是/hbase/tokenauth权限问题,在zookeeper-client里查看了下它的权限是这样的:
[zk: localhost:2181(CONNECTED) 0] getAcl /hbase/tokenauth
‘sasl,‘hbase/[email protected]
: cdrwa
但很奇怪的是不管我切换什么账户也无法访问这个节点,想通过setAcl设置它的权限为anyone也是失败的。原因很显然,因为我不是“hbase/[email protected]”,我没任何权限操作。
Authentication is not valid : /hbase/tokenauth
可为什么4048这台机子也没能成为leader呢(问题[1])?
第一次解决(day 0)
尝试各种办法也无法获得/hbase/tokenauth的控制权,我们只好暂时通过在zookeeper配置文件zoo.cfg添加参数skipACL=true,重启zookeeper,这样不会验证ACL。
重启hbase,触发AuthenticationTokenSecretManager.start,大家开始竞争成为leader,于是有了leader,leader是4048这台机子。
然后再通过zookeeper-client的setAcl命令把这个点的权限改成anyone,再关闭skipACL,重启zookeeper。
这些是我同事操作的,操作完之后集群一切正常,mapreduce也可以跑了。不过还有一个隐患,我注意到了/hbase/tokenauth/keys的权限也是4048专属,如果4048挂掉了,别人也无法顺利成为leader,但是想想它挂掉的概率比较低,等它挂掉再说吧,于是就没去理会了。
问题2 (day 1)
今天中午的时候,集群突然奔溃了,所有region server都挂掉了。 我上去查了一下日志,结果竟然和我昨天考虑到的隐患一样,4048挂掉了,然后其他人竞争leader的时候没有权限也挂掉了。4048为什么会挂掉(问题[2])? 当时我没怎么看4048的日志,不知道它为什么挂掉,只觉得很巧。
这是从4050这台机子的region server上截取的两条日志,它先是成为了leader,然后因为没有权限维护/hbase/tokenauth/keys,自然想访问里面的key也是失败的。其他机子挂掉的原因也一样。
2015-08-25 14:35:08,273 DEBUG org.apache.hadoop.hbase.zookeeper.ZKLeaderManager: Claimed the leader znode as ‘SVR4050HW2285.hadoop.xxx.com,60020,1440397852179‘
2015-08-25 14:35:08,288 FATAL org.apache.hadoop.hbase.regionserver.HRegionServer: ABORTING region server SVR4050HW2285.hadoop.xxx.com,60020,1440397852179: Unable to synchronize secretkey 3 in zookeeper
org.apache.zookeeper.KeeperException$NoAuthException: KeeperErrorCode = NoAuth for /hbase/tokenauth/keys/3
at org.apache.zookeeper.KeeperException.create(KeeperException.java:113)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.setData(ZooKeeper.java:1266)
at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.setData(RecoverableZooKeeper.java:349)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.updateExistingNodeData(ZKUtil.java:814)
at org.apache.hadoop.hbase.security.token.ZKSecretWatcher.updateKeyInZK(ZKSecretWatcher.java:197)
at org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager.rollCurrentKey(AuthenticationTokenSecretManager.java:257)
at org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager$LeaderElector.run(AuthenticationTokenSecretManager.java:317)
第二次解决(day 1)
添加skipACL后重启ZK,重启HBase。就这样暂时保持skipACL开启,保证hbase正常运行。
思考(day 2)
我们总不能这样开着skipACL,这对资源隔离不是很友好。我查看了下HBase的ZKUtil.java的代码。
这是创建ZNode时候,创建ACL的函数。它对一些特定节点使用CREATOR_ALL_AND_WORLD_READABLE
权限,其余使用CREATOR_ALL_ACL
权限。前者是创建者有所有权限,其余人有只读权限。后者是创建者有所有权限。
private static ArrayList<ACL> createACL(ZooKeeperWatcher zkw, String node) {
if (isSecureZooKeeper(zkw.getConfiguration())) {
// Certain znodes are accessed directly by the client,
// so they must be readable by non-authenticated clients
if ((node.equals(zkw.baseZNode) == true) ||
(node.equals(zkw.rootServerZNode) == true) ||
(node.equals(zkw.masterAddressZNode) == true) ||
(node.equals(zkw.clusterIdZNode) == true) ||
(node.equals(zkw.rsZNode) == true) ||
(node.equals(zkw.backupMasterAddressesZNode) == true) ||
(node.startsWith(zkw.assignmentZNode) == true) ||
(node.startsWith(zkw.masterTableZNode) == true) ||
(node.startsWith(zkw.masterTableZNode92) == true)) {
return ZooKeeperWatcher.CREATOR_ALL_AND_WORLD_READABLE;
}
return Ids.CREATOR_ALL_ACL;
} else {
return Ids.OPEN_ACL_UNSAFE;
}
}
/hbase/tokenauth及其子节点显然使用的是CREATOR_ALL_ACL
权限。那4048创建了key,然后又挂掉的话,那其它机子显然不可能成为leader。这种权限设定似乎有点不科学。
因为B环境权限都很正常的,没出什么问题,我又对比了下A和B的权限和配置。
B leader生产的token的权限:
[zk: localhost:2181(CONNECTED) 4] getAcl /hbase/tokenauth/keys/67
‘sasl,‘hbase
: cdrwa
A leader生产的token的权限:
[zk: localhost:2181(CONNECTED) 1] getAcl /hbase/tokenauth/keys/2
‘sasl,‘hbase/[email protected]
: cdrwa
前者非常统一的使用hbase这个principal,后者则带上了hostname。
问题必定出在这里!
我又对比了hbase的zk-jaas.conf,没区别。这个配置文件里配置了访问zk的principal,它们都是带hostname的。
Client {
com.sun.security.auth.module.Krb5LoginModule required
useKeyTab=true
useTicketCache=false
keyTab="/etc/hbase.keytab"
principal="hbase/[email protected]";
};
可为什么B最后的principal却没带hostname,我又对比了zookeeper的配置文件zoo.cfg。
B的有下面两行设置:
kerberos.removeHostFromPrincipal=true
kerberos.removeRealmFromPrincipal=true
而A呢?居然也有。。。
和同事讨论了下,他告诉我A这两行配置不是一开始就有的,是后来加上去的,当时A最早上kerberos还出了很多问题。我瞬间就懂了,一切疑惑都解开了。
问题[1]:为什么4048这台机子也没能成为leader呢?
因为当初集群最早上kerberos启动的时候没加那两行remove配置,所以/hbase/tokenauth和/hbase/tokenauth/keys的权限都是归4048专属。后来因为出了问题,这两行配置被加上去,hbase重启。此时大家的principal都变成了hbase(包括4048),没有人能访问这个4048专属的目录。于是包括4048在内,没人成为leader。
问题[2]:4048为什么会挂掉?
这个是因为我们第一次解决的时候,只修复了/hbase/tokenauth而没有修复/hbase/tokenauth/keys,它的权限依然是4048所有。
[zk: localhost:2181(CONNECTED) 0] getAcl /hbase/tokenauth/keys
‘sasl,‘hbase/[email protected]
: cdrwa
当时重启hbase的时候还是开着skipACL的,所以leader顺利的在/hbase/tokenauth/keys下面创建了token,集群正常启动,一切正常。
然后我们关闭了skipACL,似乎也没有问题,可为什么恰好第二天就奔溃了?
因为leader去更新token的默认周期恰好是一天,第二天它想更新的时候因为没有/hbase/tokenauth/keys的权限而挂掉。
因为我们加了那两行remove配置,即使这个leader是4048,它也无法访问,道理同问题[1]。
这个证据也很好找。
这是第一次解决时,新写入的token,它的创建时间是24号下午2点半。
[zk: localhost:2181(CONNECTED) 3] stat /hbase/tokenauth/keys/3
cZxid = 0x1900000097
ctime = Mon Aug 24 14:30:48 CST 2015
mZxid = 0x1c000000e8
mtime = Tue Aug 25 15:35:36 CST 2015
pZxid = 0x1900000097
cversion = 0
dataVersion = 1
aclVersion = 0
ephemeralOwner = 0x0
dataLength = 42
numChildren = 0
这是leader挂掉的日志,时间是第二天下午2点半,集群奔溃也是在2点半左右,刚好间隔24小时左右。
2015-08-25 14:33:01,515 FATAL org.apache.hadoop.hbase.security.token.ZKSecretWatcher: Unable to synchronize master key 4 to znode /hbase/tokenauth/keys/4
org.apache.zookeeper.KeeperException$NoAuthException: KeeperErrorCode = NoAuth for /hbase/tokenauth/keys/4
at org.apache.zookeeper.KeeperException.create(KeeperException.java:113)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.createNonSequential(RecoverableZooKeeper.java:421)
at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.create(RecoverableZooKeeper.java:403)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.createWithParents(ZKUtil.java:1164)
at org.apache.hadoop.hbase.zookeeper.ZKUtil.createSetData(ZKUtil.java:868)
at org.apache.hadoop.hbase.security.token.ZKSecretWatcher.addKeyToZK(ZKSecretWatcher.java:180)
at org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager.rollCurrentKey(AuthenticationTokenSecretManager.java:250)
at org.apache.hadoop.hbase.security.token.AuthenticationTokenSecretManager$LeaderElector.run(AuthenticationTokenSecretManager.java:317)
2015-08-25 14:33:01,516 FATAL org.apache.hadoop.hbase.regionserver.HRegionServer: ABORTING region server SVR4048HW2285.hadoop.xxx.com
,60020,1440397852099: Unable to synchronize secret key 4 in zookeeper
日志显示它想写入新的token 4失败而终止,昨天写入的是3。因为新的token的id比旧的大一,所以正好挂在想写入4的时候。
AuthenticationTokenSecretManager:
synchronized void rollCurrentKey() {
if (!leaderElector.isMaster()) {
LOG.info("Skipping rollCurrentKey() because not running as master.");
return;
}
long now = EnvironmentEdgeManager.currentTimeMillis();
AuthenticationKey prev = currentKey;
AuthenticationKey newKey = new AuthenticationKey(++idSeq, //新token的id比上一次大一
Long.MAX_VALUE, // don‘t allow to expire until it‘s replaced by a new key
generateSecret());
allKeys.put(newKey.getKeyId(), newKey);
currentKey = newKey;
zkWatcher.addKeyToZK(newKey); //试图向zk写入新token
lastKeyUpdate = now;
if (prev != null) {
// make sure previous key is still stored
prev.setExpiration(now + tokenMaxLifetime);
allKeys.put(prev.getKeyId(), prev);
zkWatcher.updateKeyInZK(prev);
}
}
第三次解决(day 2)
修复zk上所有权限有问题的节点(设置权限为anyone),删除过期的token(这些token因为没有权限,没被人删除),关闭skipACL,重启zk。
因为已经添加了remove配置,现在不同region server访问zookeeper的principal都是一样的,不会再出现权限问题。
后记
为了保证不同region server访问zookeeper的principal一样,我们必须在zoo.cfg里添加remove配置,这种做法似乎不是特别科学。
因为作为hbase,你不能保证zookeeper里会有remove配置。假如zookeeper是另一个团队维护,他们觉得添加了这样的配置对其它app有影响呢?
事实上hbase作为client,zookeeper作为server,我们似乎可以给hbase配置统一的client身份?
zk-jaas.conf 类似这样:
Client {
com.sun.security.auth.module.Krb5LoginModule required
useKeyTab=true
keyTab="/path/to/zkcli.keytab"
storeKey=true
useTicketCache=false
principal="[email protected]<YOUR-REALM>";
};
而不是这样:
Client {
com.sun.security.auth.module.Krb5LoginModule required
useKeyTab=true
useTicketCache=false
keyTab="/etc/hbase.keytab"
principal="hbase/[email protected]";
};
这样就不会带上hostname了吧?
附录
HBase as a MapReduce Job Data Source and Data Sink
版权声明:本文为我原创文章,转载请注明出处