Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

initialization failed with secure HBase #2162

Closed
ss666 opened this issue Aug 24, 2021 · 1 comment
Closed

initialization failed with secure HBase #2162

ss666 opened this issue Aug 24, 2021 · 1 comment

Comments

@ss666
Copy link

ss666 commented Aug 24, 2021 •
edited
Loading

I've installed the openTSDB in a secure HBase cluster (with kerberos) and created needed tables in HBase (tsdb, tsdb-uid, tsdb-tree and tsdb-meta). When I tried to start it, some errors happened:

2021-08-24 11:09:33,053 ERROR [AsyncHBase I/O Worker #10] RegionClient: Unexpected exception from downstream on [id: 0x37394008, /10.4.132.9:45646 => /10.4.132.8:16020]
java.lang.SecurityException: Sasl initialization failed with a status of [1] and exception [javax.security.sasl.SaslException] and message [GSS initiate failed]: org.hbase.async.SecureRpcHelper96@4fddcf7d
        at org.hbase.async.SecureRpcHelper96.handleResponse(SecureRpcHelper96.java:133) ~[asynchbase-1.8.2.jar:na]
        at org.hbase.async.RegionClient.decode(RegionClient.java:1423) ~[asynchbase-1.8.2.jar:na]
        at org.hbase.async.RegionClient.decode(RegionClient.java:88) ~[asynchbase-1.8.2.jar:na]
        at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:500) ~[netty-3.10.6.Final.jar:na]

(more log info could be seen at the very end)

The command I used to start is:
JVMARGS="-Djava.security.auth.login.config=./jaas/jaas.conf -Dzookeeper.sasl.client=false" ./tsdb tsd

the jaas.conf is:

Client {
  com.sun.security.auth.module.Krb5LoginModule required
  useKeyTab=true
  storeKey=true
  useTicketCache=false
  keyTab="/etc/security/keytabs/hbase.service.keytab"
  principal="hbase/[email protected]";
};

the configuration appended in opentsdb.conf is:

#--------KERBEROS-----   
  hbase.security.auth.enable=true  
  hbase.security.authentication=kerberos  
  hbase.sasl.clientconfig=Client  
  hbase.kerberos.regionserver.principal=hbase/[email protected]

MORE LOG INFO:

2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:java.io.tmpdir=/tmp
2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:java.compiler=<NA>
2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:os.name=Linux
2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:os.arch=amd64
2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:os.version=3.10.0-1127.8.2.el7.x86_64
2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:user.name=hbase
2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:user.home=/home/hbase
2021-08-24 11:12:52,132 INFO  [main] ZooKeeper: Client environment:user.dir=/home/m_zjh/lius/opentsdb-2.4.1-SNAPSHOT/build
2021-08-24 11:12:52,133 INFO  [main] ZooKeeper: Initiating client connection, connectString=tst04:2181,tst05:2181,tst06:2181 sessionTimeout=5000 watcher=org.hbase.async.HBaseClient$ZKClient@281e3708
2021-08-24 11:12:52,142 INFO  [main] HBaseClient: Need to find the -ROOT- region
2021-08-24 11:12:52,148 INFO  [main-SendThread(tst04.bj2.sdbmcc.com:2181)] ClientCnxn: Opening socket connection to server tst04.bj2.sdbmcc.com/10.4.132.7:2181
2021-08-24 11:12:52,234 INFO  [main-SendThread(tst04.bj2.sdbmcc.com:2181)] ClientCnxn: Socket connection established to tst04.bj2.sdbmcc.com/10.4.132.7:2181, initiating session
2021-08-24 11:12:52,239 INFO  [main-SendThread(tst04.bj2.sdbmcc.com:2181)] ClientCnxn: Session establishment complete on server tst04.bj2.sdbmcc.com/10.4.132.7:2181, sessionid = 0x1775c2aaae0020f, negotiated timeout = 6000
2021-08-24 11:12:52,270 INFO  [main-EventThread] HBaseClient: Resolved IP address for host: tst05.bj2.sdbmcc.com is: 10.4.132.8
2021-08-24 11:12:52,271 INFO  [main-EventThread] HBaseClient: Connecting to .META. region @ 10.4.132.8:16020
2021-08-24 11:12:52,321 INFO  [main-EventThread] ZooKeeper: Session: 0x1775c2aaae0020f closed
2021-08-24 11:12:52,322 INFO  [main-EventThread] ClientCnxn: EventThread shut down
2021-08-24 11:12:52,434 INFO  [AsyncHBase I/O Worker #1] Login: Successfully logged in.
2021-08-24 11:12:52,445 INFO  [AsyncHBase I/O Worker #1] Login: TGT valid starting at:        Tue Aug 24 11:12:52 CST 2021
2021-08-24 11:12:52,445 INFO  [AsyncHBase I/O Worker #1] Login: TGT expires:                  Wed Aug 25 11:12:52 CST 2021
2021-08-24 11:12:52,446 INFO  [AsyncHBase I/O Worker #1] Login: Scheduled ticket renewal in 73267871 ms
2021-08-24 11:12:52,446 INFO  [AsyncHBase I/O Worker #1] Login: Initialized kerberos login context
2021-08-24 11:12:52,449 INFO  [AsyncHBase I/O Worker #1] KerberosClientAuthProvider: Connecting to hbase/[email protected]
2021-08-24 11:12:52,451 INFO  [AsyncHBase I/O Worker #1] KerberosClientAuthProvider: Client will use GSSAPI as SASL mechanism.
2021-08-24 11:12:52,488 INFO  [AsyncHBase I/O Worker #1] RegionClient: Initialized security helper: org.hbase.async.SecureRpcHelper96@51a1ef3c for region client: RegionClient@1572717789(chan=null, #pending_rpcs=2, #batched=0, #rpcs_inflight=0)
2021-08-24 11:12:52,497 ERROR [AsyncHBase I/O Worker #1] RegionClient: Unexpected exception from downstream on [id: 0xdc48e63a, /10.4.132.9:51318 => /10.4.132.8:16020]
java.lang.SecurityException: Sasl initialization failed with a status of [1] and exception [javax.security.sasl.SaslException] and message [GSS initiate failed]: org.hbase.async.SecureRpcHelper96@51a1ef3c
        at org.hbase.async.SecureRpcHelper96.handleResponse(SecureRpcHelper96.java:133) ~[asynchbase-1.8.2.jar:na]
        at org.hbase.async.RegionClient.decode(RegionClient.java:1423) ~[asynchbase-1.8.2.jar:na]
        at org.hbase.async.RegionClient.decode(RegionClient.java:88) ~[asynchbase-1.8.2.jar:na]
        at org.jboss.netty.handler.codec.replay.ReplayingDecoder.callDecode(ReplayingDecoder.java:500) ~[netty-3.10.6.Final.jar:na]
        at org.jboss.netty.handler.codec.replay.ReplayingDecoder.messageReceived(ReplayingDecoder.java:435) ~[netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.10.6.Final.jar:na]
        at org.hbase.async.RegionClient.handleUpstream(RegionClient.java:1230) ~[asynchbase-1.8.2.jar:na]
        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.SimpleChannelHandler.messageReceived(SimpleChannelHandler.java:142) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.handler.timeout.IdleStateAwareChannelHandler.handleUpstream(IdleStateAwareChannelHandler.java:36) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.handler.timeout.IdleStateHandler.messageReceived(IdleStateHandler.java:294) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.10.6.Final.jar:na]
        at org.hbase.async.HBaseClient$RegionClientPipeline.sendUpstream(HBaseClient.java:3857) [asynchbase-1.8.2.jar:na]
        at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:337) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.10.6.Final.jar:na]
        at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.10.6.Final.jar:na]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_252]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_252]
        at java.lang.Thread.run(Thread.java:748) [na:1.8.0_252]
2021-08-24 11:12:52,499 INFO  [AsyncHBase I/O Worker #1] HBaseClient: Channel [id: 0xdc48e63a, /10.4.132.9:51318 => /10.4.132.8:16020] is disconnecting: [id: 0xdc48e63a, /10.4.132.9:51318 => /10.4.132.8:16020] CLOSE
2021-08-24 11:12:52,499 INFO  [AsyncHBase I/O Worker #1] HBaseClient: Lost connection with the .META. region
2021-08-24 11:12:52,501 INFO  [AsyncHBase I/O Worker #1] HBaseClient: Invalidated cache for .META. as null seems to be splitting or closing it.
2021-08-24 11:12:52,915 INFO  [AsyncHBase Timer HBaseClient #1] ZooKeeper: Initiating client connection, connectString=tst04:2181,tst05:2181,tst06:2181 sessionTimeout=5000 watcher=org.hbase.async.HBaseClient$ZKClient@281e3708
2021-08-24 11:12:52,916 INFO  [AsyncHBase Timer HBaseClient #1] HBaseClient: Need to find the .META. region
2021-08-24 11:12:52,917 INFO  [AsyncHBase Timer HBaseClient #1-SendThread(tst06.bj2.sdbmcc.com:2181)] ClientCnxn: Opening socket connection to server tst06.bj2.sdbmcc.com/10.4.132.9:2181
2021-08-24 11:12:52,917 INFO  [AsyncHBase Timer HBaseClient #1-SendThread(tst06.bj2.sdbmcc.com:2181)] ClientCnxn: Socket connection established to tst06.bj2.sdbmcc.com/10.4.132.9:2181, initiating session
2021-08-24 11:12:52,919 INFO  [AsyncHBase Timer HBaseClient #1-SendThread(tst06.bj2.sdbmcc.com:2181)] ClientCnxn: Session establishment complete on server tst06.bj2.sdbmcc.com/10.4.132.9:2181, sessionid = 0x3775c2aaaf8bc7f, negotiated timeout = 6000
2021-08-24 11:12:52,920 INFO  [AsyncHBase Timer HBaseClient #1-EventThread] HBaseClient: Resolved IP address for host: tst05.bj2.sdbmcc.com is: 10.4.132.8
2021-08-24 11:12:52,921 INFO  [AsyncHBase Timer HBaseClient #1-EventThread] HBaseClient: Connecting to .META. region @ 10.4.132.8:16020
2021-08-24 11:12:52,922 INFO  [AsyncHBase I/O Worker #2] KerberosClientAuthProvider: Connecting to hbase/[email protected]
2021-08-24 11:12:52,922 INFO  [AsyncHBase I/O Worker #2] KerberosClientAuthProvider: Client will use GSSAPI as SASL mechanism.
2021-08-24 11:12:52,922 INFO  [AsyncHBase Timer HBaseClient #1-EventThread] ZooKeeper: Session: 0x3775c2aaaf8bc7f closed
2021-08-24 11:12:52,922 INFO  [AsyncHBase Timer HBaseClient #1-EventThread] ClientCnxn: EventThread shut down
2021-08-24 11:12:52,930 INFO  [AsyncHBase I/O Worker #2] RegionClient: Initialized security helper: org.hbase.async.SecureRpcHelper96@745d89fc for region client: RegionClient@204342634(chan=null, #pending_rpcs=1, #batched=0, #rpcs_inflight=0)
.....
Caused by: org.hbase.async.NonRecoverableException: Too many attempts: HBaseRpc(method=getClosestRowBefore, table="hbase:meta", key=[116, 115, 100, 98, 44, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 58, 65, 115, 121, 110, 99, 72, 66, 97, 115, 101, 126, 112, 114, 111, 98, 101, 126, 60, 59, 95, 60, 44, 58], region=RegionInfo(table="hbase:meta", region_name="hbase:meta,,1", stop_key=""), attempt=11, timeout=-1, hasTimedout=false)
        at org.hbase.async.HBaseClient.tooManyAttempts(HBaseClient.java:2556)
        at org.hbase.async.HBaseClient.handleNSRE(HBaseClient.java:3591)
        ... 69 more
Caused by: org.hbase.async.NotServingRegionException: Connection reset: [id: 0x26792fe2, /10.4.132.9:46430 :> /10.4.132.8:16020] got disconnected
Caused by RPC: HBaseRpc(method=getClosestRowBefore, table="hbase:meta", key=[116, 115, 100, 98, 44, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 58, 65, 115, 121, 110, 99, 72, 66, 97, 115, 101, 126, 112, 114, 111, 98, 101, 126, 60, 59, 95, 60, 44, 58], region=RegionInfo(table="hbase:meta", region_name="hbase:meta,,1", stop_key=""), attempt=0, timeout=-1, hasTimedout=false)
        at org.hbase.async.RegionClient.failOrRetryRpcs(RegionClient.java:1215)

Hope someone could give me some advice on it, thanks!
@ss666 ss666 closed this as completed Aug 30, 2021
@AhDEV-free
Copy link

@ss666 hi How did you solve this problem

@AhDEV-free AhDEV-free mentioned this issue Jan 9, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ss666 @AhDEV-free