Return-Path: X-Original-To: apmail-hive-issues-archive@minotaur.apache.org Delivered-To: apmail-hive-issues-archive@minotaur.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id E7E5F10F57 for ; Fri, 10 Apr 2015 07:12:12 +0000 (UTC) Received: (qmail 87671 invoked by uid 500); 10 Apr 2015 07:12:12 -0000 Delivered-To: apmail-hive-issues-archive@hive.apache.org Received: (qmail 87635 invoked by uid 500); 10 Apr 2015 07:12:12 -0000 Mailing-List: contact issues-help@hive.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@hive.apache.org Delivered-To: mailing list issues@hive.apache.org Received: (qmail 87625 invoked by uid 99); 10 Apr 2015 07:12:12 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 10 Apr 2015 07:12:12 +0000 Date: Fri, 10 Apr 2015 07:12:12 +0000 (UTC) From: "Olaf Flebbe (JIRA)" To: issues@hive.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (HIVE-10240) Patch HIVE-9473 breaks KERBEROS MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/HIVE-10240?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14489084#comment-14489084 ] Olaf Flebbe commented on HIVE-10240: ------------------------------------ [~vgumashta]: Thanks for digging out HIVE-9685! > Patch HIVE-9473 breaks KERBEROS > ------------------------------- > > Key: HIVE-10240 > URL: https://issues.apache.org/jira/browse/HIVE-10240 > Project: Hive > Issue Type: Bug > Components: Authentication, HiveServer2 > Affects Versions: 1.0.0 > Reporter: Olaf Flebbe > Assignee: Vaibhav Gumashta > Fix For: 1.0.1 > > > The patch from HIVE-9473 introduces a regression. Hive-Server2 does not start properly any more for our config (more or less the bigtop environment) > sql std auth enabled, enableDoAs disabled, tez enabled, kerberos enabled. > Problem seems to be that the kerberos ticket is not present when hive-server2 tries first to access HDFS. When HIVE-9473 is reverted getting the ticket is one of the first things hive-server2 does. > Posting startup of vanilla hive-1.0.0 and startup of a hive-1.0.0 with this commit revoked, where hive-server2 correctly starts. > {code} > commit 35582c2065a6b90b003a656bdb3b0ff08b0c35b9 > Author: Thejas Nair > Date: Fri Jan 30 00:05:50 2015 +0000 > HIVE-9473 : sql std auth should disallow built-in udfs that allow any java methods to be called (Thejas Nair, reviewed by Jason Dere) > > git-svn-id: https://svn.apache.org/repos/asf/hive/branches/branch-1.0@1655891 13f79535-47bb-0310-9956-ffa450edef68 > {code} > revoked. > Startup of vanilla hive-1.0.0 hive-server2 > {code} > STARTUP_MSG: build = git://os2-debian80/net/os2-debian80/fs1/olaf/bigtop/output/hive/hive-1.0.0 -r 813996292c9f966109f990127ddd5673cf813125; compiled by 'olaf' on Tue Apr 7 09:33:01 CEST 2015 > ************************************************************/ > 2015-04-07 10:23:52,579 INFO [main]: server.HiveServer2 (HiveServer2.java:startHiveServer2(292)) - Starting HiveServer2 > 2015-04-07 10:23:53,104 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:newRawStore(556)) - 0: Opening raw store with implemenation class:org.apache.hadoop.hive.metastore.ObjectStore > 2015-04-07 10:23:53,135 INFO [main]: metastore.ObjectStore (ObjectStore.java:initialize(264)) - ObjectStore, initialize called > 2015-04-07 10:23:54,775 INFO [main]: metastore.ObjectStore (ObjectStore.java:getPMF(345)) - Setting MetaStore object pin classes with hive.metastore.cache.pinobjtypes="Table,StorageDescriptor,SerDeInfo,Pa > rtition,Database,Type,FieldSchema,Order" > 2015-04-07 10:23:56,953 INFO [main]: metastore.MetaStoreDirectSql (MetaStoreDirectSql.java:(132)) - Using direct SQL, underlying DB is DERBY > 2015-04-07 10:23:56,954 INFO [main]: metastore.ObjectStore (ObjectStore.java:setConf(247)) - Initialized ObjectStore > 2015-04-07 10:23:57,275 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:createDefaultRoles_core(630)) - Added admin role in metastore > 2015-04-07 10:23:57,276 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:createDefaultRoles_core(639)) - Added public role in metastore > 2015-04-07 10:23:58,241 WARN [main]: ipc.Client (Client.java:run(675)) - Exception encountered while connecting to the server : javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)] > 2015-04-07 10:23:58,248 WARN [main]: ipc.Client (Client.java:run(675)) - Exception encountered while connecting to the server : javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)] > 2015-04-07 10:23:58,249 INFO [main]: retry.RetryInvocationHandler (RetryInvocationHandler.java:invoke(140)) - Exception while invoking getFileInfo of class ClientNamenodeProtocolTranslatorPB over node2.proto.bsi.de/192.168.100.22:8020 after 1 fail over attempts. Trying to fail over immediately. > java.io.IOException: Failed on local exception: java.io.IOException: javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)]; Host Details : local host is: "node2.proto.bsi.de/192.168.100.22"; destination host is: "node2.proto.bsi.de":8020; > at org.apache.hadoop.net.NetUtils.wrapException(NetUtils.java:772) > at org.apache.hadoop.ipc.Client.call(Client.java:1472) > at org.apache.hadoop.ipc.Client.call(Client.java:1399) > at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:232) > at com.sun.proxy.$Proxy14.getFileInfo(Unknown Source) > at org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getFileInfo(ClientNamenodeProtocolTranslatorPB.java:752) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:187) > at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:102) > at com.sun.proxy.$Proxy15.getFileInfo(Unknown Source) > at org.apache.hadoop.hdfs.DFSClient.getFileInfo(DFSClient.java:1988) > at org.apache.hadoop.hdfs.DistributedFileSystem$18.doCall(DistributedFileSystem.java:1118) > at org.apache.hadoop.hdfs.DistributedFileSystem$18.doCall(DistributedFileSystem.java:1114) > at org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystemLinkResolver.java:81) > at org.apache.hadoop.hdfs.DistributedFileSystem.getFileStatus(DistributedFileSystem.java:1114) > at org.apache.hadoop.fs.FileSystem.exists(FileSystem.java:1400) > at org.apache.hadoop.hive.ql.session.SessionState.createRootHDFSDir(SessionState.java:520) > at org.apache.hadoop.hive.ql.session.SessionState.createSessionDirs(SessionState.java:478) > at org.apache.hadoop.hive.ql.session.SessionState.start(SessionState.java:430) > at org.apache.hive.service.cli.CLIService.applyAuthorizationConfigPolicy(CLIService.java:123) > at org.apache.hive.service.cli.CLIService.init(CLIService.java:81) > at org.apache.hive.service.CompositeService.init(CompositeService.java:59) > at org.apache.hive.service.server.HiveServer2.init(HiveServer2.java:89) > at org.apache.hive.service.server.HiveServer2.startHiveServer2(HiveServer2.java:298) > at org.apache.hive.service.server.HiveServer2.access$400(HiveServer2.java:65) > at org.apache.hive.service.server.HiveServer2$StartOptionExecutor.execute(HiveServer2.java:508) > at org.apache.hive.service.server.HiveServer2.main(HiveServer2.java:381) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:606) > at org.apache.hadoop.util.RunJar.run(RunJar.java:221) > at org.apache.hadoop.util.RunJar.main(RunJar.java:136) > Caused by: java.io.IOException: javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Failed to find any Kerberos tgt)] > at org.apache.hadoop.ipc.Client$Connection$1.run(Client.java:680) > at java.security.AccessController.doPrivileged(Native Method) > at javax.security.auth.Subject.doAs(Subject.java:415) > {code} > And now startup log of reverted patch > {code} > 2015-04-07 16:38:40,862 INFO [main]: server.HiveServer2 (HiveServer2.java:startHiveServer2(292)) - Starting HiveServer2 > 2015-04-07 16:38:41,384 INFO [main]: security.UserGroupInformation (UserGroupInformation.java:loginUserFromKeytab(938)) - Login successful for user hive/node2.proto.bsi.de@PROTO.BSI.DE using keytab file /etc/hive.keytab > 2015-04-07 16:38:41,384 INFO [main]: cli.CLIService (CLIService.java:init(100)) - SPNego httpUGI not created, spNegoPrincipal: , ketabFile: > 2015-04-07 16:38:42,044 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:newRawStore(556)) - 0: Opening raw store with implemenation class:org.apache.hadoop.hive.metastore.ObjectStore > 2015-04-07 16:38:42,074 INFO [main]: metastore.ObjectStore (ObjectStore.java:initialize(264)) - ObjectStore, initialize called > 2015-04-07 16:38:44,682 INFO [main]: metastore.ObjectStore (ObjectStore.java:getPMF(345)) - Setting MetaStore object pin classes with hive.metastore.cache.pinobjtypes="Table,StorageDescriptor,SerDeInfo,Partition,Database,Type,FieldSchema,Order" > 2015-04-07 16:38:46,762 INFO [main]: metastore.MetaStoreDirectSql (MetaStoreDirectSql.java:(132)) - Using direct SQL, underlying DB is DERBY > 2015-04-07 16:38:46,762 INFO [main]: metastore.ObjectStore (ObjectStore.java:setConf(247)) - Initialized ObjectStore > 2015-04-07 16:38:47,067 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:createDefaultRoles_core(630)) - Added admin role in metastore > 2015-04-07 16:38:47,068 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:createDefaultRoles_core(639)) - Added public role in metastore > 2015-04-07 16:38:48,101 INFO [main]: session.SessionState (SessionState.java:createPath(558)) - Created local directory: /tmp/7a90155d-fbd9-4991-bce6-f583a9ef259f_resources > 2015-04-07 16:38:48,111 INFO [main]: session.SessionState (SessionState.java:createPath(558)) - Created HDFS directory: /tmp/hive/hive/7a90155d-fbd9-4991-bce6-f583a9ef259f > 2015-04-07 16:38:48,113 INFO [main]: session.SessionState (SessionState.java:createPath(558)) - Created local directory: /tmp/hive/7a90155d-fbd9-4991-bce6-f583a9ef259f > 2015-04-07 16:38:48,118 INFO [main]: session.SessionState (SessionState.java:createPath(558)) - Created HDFS directory: /tmp/hive/hive/7a90155d-fbd9-4991-bce6-f583a9ef259f/_tmp_space.db > 2015-04-07 16:38:48,120 INFO [main]: session.SessionState (SessionState.java:start(460)) - No Tez session required at this point. hive.execution.engine=mr. > 2015-04-07 16:38:48,134 INFO [main]: sqlstd.SQLStdHiveAccessController (SQLStdHiveAccessController.java:(95)) - Created SQLStdHiveAccessController for session context : HiveAuthzSessionContext [sessionString=7a90155d-fbd9-4991-bce6-f583a9ef259f, clientType=HIVESERVER2] > 2015-04-07 16:38:48,148 INFO [main]: service.CompositeService (SessionManager.java:initOperationLogRootDir(148)) - Operation log root directory is created: /tmp/hive/operation_logs > 2015-04-07 16:38:48,153 INFO [main]: service.CompositeService (SessionManager.java:createBackgroundOperationPool(96)) - HiveServer2: Background operation thread pool size: 100 > 2015-04-07 16:38:48,153 INFO [main]: service.CompositeService (SessionManager.java:createBackgroundOperationPool(98)) - HiveServer2: Background operation thread wait queue size: 100 > 2015-04-07 16:38:48,153 INFO [main]: service.CompositeService (SessionManager.java:createBackgroundOperationPool(101)) - HiveServer2: Background operation thread keepalive time: 10 seconds > 2015-04-07 16:38:48,157 INFO [main]: service.AbstractService (AbstractService.java:init(89)) - Service:OperationManager is inited. > 2015-04-07 16:38:48,157 INFO [main]: service.AbstractService (AbstractService.java:init(89)) - Service:SessionManager is inited. > 2015-04-07 16:38:48,157 INFO [main]: service.AbstractService (AbstractService.java:init(89)) - Service:CLIService is inited. > 2015-04-07 16:38:48,158 INFO [main]: service.AbstractService (AbstractService.java:init(89)) - Service:ThriftBinaryCLIService is inited. > 2015-04-07 16:38:48,158 INFO [main]: service.AbstractService (AbstractService.java:init(89)) - Service:HiveServer2 is inited. > 2015-04-07 16:38:48,158 INFO [main]: service.AbstractService (AbstractService.java:start(104)) - Service:OperationManager is started. > 2015-04-07 16:38:48,158 INFO [main]: service.AbstractService (AbstractService.java:start(104)) - Service:SessionManager is started. > 2015-04-07 16:38:48,158 INFO [main]: service.AbstractService (AbstractService.java:start(104)) - Service:CLIService is started. > 2015-04-07 16:38:48,161 INFO [main]: metastore.ObjectStore (ObjectStore.java:initialize(264)) - ObjectStore, initialize called > 2015-04-07 16:38:48,167 INFO [main]: metastore.MetaStoreDirectSql (MetaStoreDirectSql.java:(132)) - Using direct SQL, underlying DB is DERBY > 2015-04-07 16:38:48,167 INFO [main]: metastore.ObjectStore (ObjectStore.java:setConf(247)) - Initialized ObjectStore > 2015-04-07 16:38:48,168 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:logInfo(713)) - 0: get_databases: default > 2015-04-07 16:38:48,168 INFO [main]: HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(339)) - ugi=hive/node2.proto.bsi.de@PROTO.BSI.DE ip=unknown-ip-addr cmd=get_databases: default > 2015-04-07 16:38:48,193 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:logInfo(713)) - 0: Shutting down the object store... > 2015-04-07 16:38:48,193 INFO [main]: HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(339)) - ugi=hive/node2.proto.bsi.de@PROTO.BSI.DE ip=unknown-ip-addr cmd=Shutting down the object store... > 2015-04-07 16:38:48,193 INFO [main]: metastore.HiveMetaStore (HiveMetaStore.java:logInfo(713)) - 0: Metastore shutdown complete. > 2015-04-07 16:38:48,194 INFO [main]: HiveMetaStore.audit (HiveMetaStore.java:logAuditEvent(339)) - ugi=hive/node2.proto.bsi.de@PROTO.BSI.DE ip=unknown-ip-addr cmd=Metastore shutdown complete. > > 2015-04-07 16:38:48,194 INFO [main]: service.AbstractService (AbstractService.java:start(104)) - Service:ThriftBinaryCLIService is started. > 2015-04-07 16:38:48,194 INFO [main]: service.AbstractService (AbstractService.java:start(104)) - Service:HiveServer2 is started. > {code} -- This message was sent by Atlassian JIRA (v6.3.4#6332)