[ACCUMULO-3849] Proxy sets incorrect primary for SASL server transport

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Fix Version/s: 1.7.1, 1.8.0
• Component/s: proxy
• Assignee: Josh Elser
• Reporter: Josh Elser
• Created: 22/May/15 23:11
• Updated: 22/May/15 23:56
• Resolved: 22/May/15 23:56

Description

A doozie for a Friday afternoon before a long weekend:

On SuSE11, KerberosProxyIT was failing with the client unable to set up the SASL handshake.

2015-05-20 06:27:44,670 [proxy.Proxy] INFO : Proxy server started on ip-172-31-5-57.ec2.internal:57147
2015-05-20 06:27:45,227 [transport.TSaslServerTransport] DEBUG: transport map does not contain key
2015-05-20 06:27:45,232 [transport.TSaslServerTransport] DEBUG: Received start message with status START
2015-05-20 06:27:45,232 [transport.TSaslServerTransport] DEBUG: Received mechanism name 'GSSAPI'
2015-05-20 06:27:45,248 [transport.TSaslTransport] ERROR: SASL negotiation failure
javax.security.sasl.SaslException: Failure to initialize security context [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos credentails)]
	at com.sun.security.sasl.gsskerb.GssKrb5Server.<init>(GssKrb5Server.java:125)
	at com.sun.security.sasl.gsskerb.FactoryImpl.createSaslServer(FactoryImpl.java:85)
	at javax.security.sasl.Sasl.createSaslServer(Sasl.java:524)
	at org.apache.thrift.transport.TSaslServerTransport.handleSaslStartMessage(TSaslServerTransport.java:140)
	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:253)
	at org.apache.thrift.transport.TSaslServerTransport.open(TSaslServerTransport.java:41)
	at org.apache.thrift.transport.TSaslServerTransport$Factory.getTransport(TSaslServerTransport.java:216)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory$1.run(UGIAssumingTransportFactory.java:51)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory$1.run(UGIAssumingTransportFactory.java:48)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:360)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1637)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory.getTransport(UGIAssumingTransportFactory.java:48)
	at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:208)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.accumulo.fate.util.LoggingRunnable.run(LoggingRunnable.java:35)
	at java.lang.Thread.run(Thread.java:745)
Caused by: GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos credentails)
	at sun.security.jgss.krb5.Krb5AcceptCredential.getInstance(Krb5AcceptCredential.java:87)
	at sun.security.jgss.krb5.Krb5MechFactory.getCredentialElement(Krb5MechFactory.java:127)
	at sun.security.jgss.GSSManagerImpl.getCredentialElement(GSSManagerImpl.java:193)
	at sun.security.jgss.GSSCredentialImpl.add(GSSCredentialImpl.java:427)
	at sun.security.jgss.GSSCredentialImpl.<init>(GSSCredentialImpl.java:62)
	at sun.security.jgss.GSSManagerImpl.createCredential(GSSManagerImpl.java:154)
	at com.sun.security.sasl.gsskerb.GssKrb5Server.<init>(GssKrb5Server.java:108)
	... 17 more
2015-05-20 06:27:45,254 [transport.TSaslServerTransport] DEBUG: failed to open server transport
org.apache.thrift.transport.TTransportException: Failure to initialize security context
	at org.apache.thrift.transport.TSaslTransport.sendAndThrowMessage(TSaslTransport.java:221)
	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:297)
	at org.apache.thrift.transport.TSaslServerTransport.open(TSaslServerTransport.java:41)
	at org.apache.thrift.transport.TSaslServerTransport$Factory.getTransport(TSaslServerTransport.java:216)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory$1.run(UGIAssumingTransportFactory.java:51)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory$1.run(UGIAssumingTransportFactory.java:48)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:360)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1637)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory.getTransport(UGIAssumingTransportFactory.java:48)
	at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:208)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.accumulo.fate.util.LoggingRunnable.run(LoggingRunnable.java:35)
	at java.lang.Thread.run(Thread.java:745)
2015-05-20 06:27:45,260 [server.TThreadPoolServer] ERROR: Error occurred during processing of message.
java.lang.RuntimeException: org.apache.thrift.transport.TTransportException: Failure to initialize security context
	at org.apache.thrift.transport.TSaslServerTransport$Factory.getTransport(TSaslServerTransport.java:219)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory$1.run(UGIAssumingTransportFactory.java:51)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory$1.run(UGIAssumingTransportFactory.java:48)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:360)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1637)
	at org.apache.accumulo.core.rpc.UGIAssumingTransportFactory.getTransport(UGIAssumingTransportFactory.java:48)
	at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:208)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at org.apache.accumulo.fate.util.LoggingRunnable.run(LoggingRunnable.java:35)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.thrift.transport.TTransportException: Failure to initialize security context
	at org.apache.thrift.transport.TSaslTransport.sendAndThrowMessage(TSaslTransport.java:221)
	at org.apache.thrift.transport.TSaslTransport.open(TSaslTransport.java:297)
	at org.apache.thrift.transport.TSaslServerTransport.open(TSaslServerTransport.java:41)
	at org.apache.thrift.transport.TSaslServerTransport$Factory.getTransport(TSaslServerTransport.java:216)
	... 11 more

So, the Thrift code is unable to actually use the KRB credentials we know we logged in with. Strange.

Looking a bit earlier, we can see that we did log in.

2015-05-20 06:27:44,498 [security.UserGroupInformation] INFO : Login successful for user proxy/[e-mail] using keytab file /grid/0/hadoopqe/artifacts/accumulo/test/target/kerberos/keytabs/proxy.keytab
2015-05-20 06:27:44,498 [proxy.Proxy] INFO : Logged in as proxy/[e-mail]

So, for some reason, when we log in on SuSE, we somehow later dont' have the right credentials?

Just after we log in, we start the Thrift server for the proxy

2015-05-20 06:27:44,516 [rpc.TServerUtils] DEBUG: Instantiating SASL Thrift server
2015-05-20 06:27:44,524 [rpc.TServerUtils] INFO : Creating SASL thread pool thrift server on listening on hostname:57147
2015-05-20 06:27:44,532 [rpc.TServerUtils] DEBUG: Logged in as proxy/[e-mail] (auth:KERBEROS), creating TSaslServerTransport factory with accumulo/hostname

Hold up:

proxy/[e-mail] != accumulo/hostname

Turns out, when we created the ClientConfiguration for the ProxyServer, we didn't actually set the kerberosPrimary (the client needs to know the 'primary' of the principal of the server in which it's authenticating with). Somehow, on every other OS and environment this didn't error out like it should have. I have no explanation why.

Sorry, SuSE. You did it right.