[ https://issues.apache.org/jira/browse/SENTRY-858?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15316818#comment-15316818 ]
Hadoop QA commented on SENTRY-858: ---------------------------------- Here are the results of testing the latest attachment https://issues.apache.org/jira/secure/attachment/12807904/SENTRY-858.patch against master. {color:red}Overall:{color} -1 due to 2 errors {color:red}ERROR:{color} mvn test exited 1 {color:red}ERROR:{color} Failed: org.apache.sentry.provider.db.generic.service.persistent.TestPrivilegeOperatePersistence Console output: https://builds.apache.org/job/PreCommit-SENTRY-Build/1676/console This message is automatically generated. > Add a test case for - Database prefix is not honoured when executing grant > statement > ------------------------------------------------------------------------------------- > > Key: SENTRY-858 > URL: https://issues.apache.org/jira/browse/SENTRY-858 > Project: Sentry > Issue Type: Test > Components: Hive Plugin, Sentry > Affects Versions: 1.4.0 > Reporter: Subroto Sanyal > Assignee: Rahul Sharma > Priority: Minor > Attachments: SENTRY-858.patch > > > h5. Steps to reproduce > # Sentry enabled secured hive environment > # Create a database _newdb_ and a table _smallairport_ in it (expecting > _default_ db to be available) > # Create a role _grp2_role_ and grant _select_ privilege to the same role for > table _smallairport_ in _newdb_. > # Check the granted role on console and log. The role is granted to a table > _smallairport_ in *default* database > {noformat}beeline> !connect > jdbc:hive2://ip-10-87-39-41.eu-west-1.compute.internal:10004/;principal=hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > Connecting to > jdbc:hive2://ip-10-87-39-41.eu-west-1.compute.internal:10004/;principal=hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > Enter username for > jdbc:hive2://ip-10-87-39-41.eu-west-1.compute.internal:10004/;principal=hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL: > > Enter password for > jdbc:hive2://ip-10-87-39-41.eu-west-1.compute.internal:10004/;principal=hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL: > > Connected to: Apache Hive (version 1.1.0-cdh5.4.0) > Driver: Hive JDBC (version 1.1.0-cdh5.4.0) > Transaction isolation: TRANSACTION_REPEATABLE_READ > 0: jdbc:hive2://ip-10-87-39-41.eu-west-1.comp> GRANT SELECT ON TABLE > `newdb.smallairport` TO ROLE grp2_role; > Getting log thread is interrupted, since query is done! > No rows affected (0.074 seconds) > 0: jdbc:hive2://ip-10-87-39-41.eu-west-1.comp> GRANT INSERT ON TABLE > `newdb.smallairport` TO ROLE grp2_role; > Getting log thread is interrupted, since query is done! > No rows affected (0.067 seconds) > 0: jdbc:hive2://ip-10-87-39-41.eu-west-1.comp> show grant role grp2_role; > Getting log thread is interrupted, since query is done! > +-----------+---------------+------------+---------+-----------------+-----------------+------------+---------------+-------------------+----------+--+ > | database | table | partition | column | principal_name | > principal_type | privilege | grant_option | grant_time | grantor | > +-----------+---------------+------------+---------+-----------------+-----------------+------------+---------------+-------------------+----------+--+ > | default | smallairport | | | grp2_role | ROLE > | select | false | 1440167849130000 | -- | > | default | smallairport | | | grp2_role | ROLE > | insert | false | 1440168392394000 | -- | > +-----------+---------------+------------+---------+-----------------+-----------------+------------+---------------+-------------------+----------+--+ > 2 rows selected (0.085 seconds) > {noformat} > h6. Logs on Sentry side: > {noformat}15/08/25 08:47:40 INFO ddl.logger: > {"serviceName":"Sentry-Service","userName":"hive","impersonator":"hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL","ipAddress":"/10.87.39.41","operation":"GRANT_PRIVILEGE","eventTime":"1440506860675","operationText":"GRANT > SELECT ON TABLE smallairport TO ROLE > grp2_role","allowed":"true","databaseName":"default","tableName":"smallairport","resourcePath":"","objectType":"PRINCIPAL"}{noformat} > h6. Logs on Hive side: > {noformat}2015-08-25 08:47:40,428 WARN [pool-6-thread-1]: > hdfs.MetastorePlugin (MetastorePlugin.java:run(74)) - #### Synced Sentry with > update [5] > 2015-08-25 08:47:40,613 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:readFrame(459)) - SERVER: > reading data length: 167 > 2015-08-25 08:47:40,613 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > parse.VariableSubstitution (VariableSubstitution.java:substitute(53)) - > Substitution is on: GRANT SELECT ON TABLE `newdb.smallairport` TO ROLE > grp2_role > 2015-08-25 08:47:40,614 INFO [HiveServer2-Handler-Pool: Thread-1038]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG method=compile > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,614 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > parse.VariableSubstitution (VariableSubstitution.java:substitute(53)) - > Substitution is on: GRANT SELECT ON TABLE `newdb.smallairport` TO ROLE > grp2_role > 2015-08-25 08:47:40,614 INFO [HiveServer2-Handler-Pool: Thread-1038]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG method=parse > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,614 INFO [HiveServer2-Handler-Pool: Thread-1038]: > parse.ParseDriver (ParseDriver.java:parse(185)) - Parsing command: GRANT > SELECT ON TABLE `newdb.smallairport` TO ROLE grp2_role > 2015-08-25 08:47:40,615 INFO [HiveServer2-Handler-Pool: Thread-1038]: > parse.ParseDriver (ParseDriver.java:parse(206)) - Parse Completed > 2015-08-25 08:47:40,615 INFO [HiveServer2-Handler-Pool: Thread-1038]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG method=parse > start=1440506860614 end=1440506860615 duration=1 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,615 INFO [HiveServer2-Handler-Pool: Thread-1038]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG > method=semanticAnalyze from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,615 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > exec.Utilities (Utilities.java:getSessionSpecifiedClassLoader(2130)) - Use > session specified class loader > 2015-08-25 08:47:40,623 WARN [HiveServer2-Handler-Pool: Thread-1038]: > conf.Configuration (Configuration.java:loadProperty(2578)) - > mapred-site.xml:an attempt to override final parameter: > mapreduce.cluster.local.dir; Ignoring. > 2015-08-25 08:47:40,629 INFO [HiveServer2-Handler-Pool: Thread-1038]: > conf.HiveAuthzConf (HiveAuthzConf.java:<init>(157)) - DefaultFS: > hdfs://ip-10-87-39-41.eu-west-1.compute.internal:8020 > 2015-08-25 08:47:40,640 WARN [HiveServer2-Handler-Pool: Thread-1038]: > conf.Configuration (Configuration.java:loadProperty(2578)) - > mapred-site.xml:an attempt to override final parameter: > mapreduce.cluster.local.dir; Ignoring. > 2015-08-25 08:47:40,648 INFO [HiveServer2-Handler-Pool: Thread-1038]: > conf.HiveAuthzConf (HiveAuthzConf.java:<init>(160)) - DefaultFS: > hdfs://ip-10-87-39-41.eu-west-1.compute.internal:8020 > 2015-08-25 08:47:40,648 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > authz.HiveAuthzBinding (HiveAuthzBinding.java:validateHiveServer2Config(163)) > - Testing mode is false > 2015-08-25 08:47:40,648 WARN [HiveServer2-Handler-Pool: Thread-1038]: > conf.HiveAuthzConf (HiveAuthzConf.java:get(206)) - Using the deprecated > config setting hive.sentry.provider instead of sentry.provider > 2015-08-25 08:47:40,648 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > authz.HiveAuthzBinding (HiveAuthzBinding.java:getAuthProvider(198)) - Using > authorization provider > org.apache.sentry.provider.file.HadoopGroupResourceAuthorizationProvider with > resource , policy engine org.apache.sentry.policy.db.SimpleDBPolicyEngine, > provider backend org.apache.sentry.provider.db.SimpleDBProviderBackend > 2015-08-25 08:47:40,649 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.SentryPolicyServiceClient (SentryPolicyServiceClient.java:<init>(143)) > - Using server kerberos principal: > sentry/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,650 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > security.UserGroupInformation (UserGroupInformation.java:getTGT(871)) - Found > tgt Ticket (hex) = > 0000: 61 82 01 72 30 82 01 6E A0 03 02 01 05 A1 0E 1B a..r0..n........ > 0010: 0C 45 43 32 2E 49 4E 54 45 52 4E 41 4C A2 21 30 .EC2.INTERNAL.!0 > 0020: 1F A0 03 02 01 02 A1 18 30 16 1B 06 6B 72 62 74 ........0...krbt > 0030: 67 74 1B 0C 45 43 32 2E 49 4E 54 45 52 4E 41 4C gt..EC2.INTERNAL > 0040: A3 82 01 32 30 82 01 2E A0 03 02 01 10 A1 03 02 ...20........... > 0050: 01 01 A2 82 01 20 04 82 01 1C AE 31 13 F6 95 B5 ..... .....1.... > 0060: 48 50 02 45 F7 CF 45 3A EF C4 18 70 7A EC 35 FD HP.E..E:...pz.5. > 0070: 41 A3 36 F8 63 F3 B1 A2 90 41 F1 B8 11 39 EA 2A A.6.c....A...9.* > 0080: B8 57 F2 53 67 FC 4F 3C 70 2F AB 88 32 F7 B3 FC .W.Sg.O<p/..2... > 0090: EB 3A D3 D5 F7 1A 69 08 D9 22 95 5B 1F 1C EF 1F .:....i..".[.... > 00A0: F6 AE FF A4 7F B5 EF 0C 04 02 84 FF C1 B1 42 AA ..............B. > 00B0: A5 32 CD 7C EF 59 DB 34 80 EF 9C 0D 2A 64 64 B6 .2...Y.4....*dd. > 00C0: 2E BF 45 D0 FD 37 8E C7 70 0F 62 1D 21 4E 77 43 ..E..7..p.b.!NwC > 00D0: A7 09 9F C6 9C F4 34 EA 03 BE AB AB 13 97 88 86 ......4......... > 00E0: 14 44 24 CF 47 B7 E8 C5 7A FA 50 F0 05 C2 C8 A6 .D$.G...z.P..... > 00F0: 0A F9 39 58 91 5F 2C 92 30 96 32 AA EB 29 AA EA ..9X._,.0.2..).. > 0100: B5 71 78 1C 75 90 76 53 43 53 49 A2 42 90 44 40 .qx.u.vSCSI.B.D@ > 0110: EA C4 45 36 76 57 0F 73 2B E5 5E 94 52 0C 38 3E ..E6vW.s+.^.R.8> > 0120: C3 EC 5A 20 59 5E 92 7C 13 DD EE 8D 3B F3 71 36 ..Z Y^......;.q6 > 0130: 82 97 57 F4 1B 23 AD 06 CE 33 5B 60 64 F8 41 0B ..W..#...3[`d.A. > 0140: 12 00 9B 9E 5F 4C 7C 72 FD 1C A1 13 1E 9E 86 BA ...._L.r........ > 0150: 7E 5E D5 1B B2 8C 43 4E DE FD 88 4B B0 13 A9 DA .^....CN...K.... > 0160: 13 29 F3 04 98 70 A1 12 42 65 F6 FD E5 18 50 83 .)...p..Be....P. > 0170: D5 AE 4E 84 76 15 ..N.v. > Client Principal = hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > Server Principal = krbtgt/EC2.INTERNAL@EC2.INTERNAL > Session Key = EncryptionKey: keyType=16 keyBytes (hex dump)= > 0000: 73 E9 CE 43 AB 62 57 3B D5 FE C4 10 E5 20 3B 5E s..C.bW;..... ;^ > 0010: 07 5B EC A1 37 C8 D3 9B .[..7... > Forwardable Ticket true > Forwarded Ticket false > Proxiable Ticket false > Proxy Ticket false > Postdated Ticket false > Renewable Ticket false > Initial Ticket false > Auth Time = Mon Aug 24 03:20:39 EDT 2015 > Start Time = Mon Aug 24 03:20:39 EDT 2015 > End Time = Wed Aug 26 03:20:39 EDT 2015 > Renew Till = null > Client Addresses Null > 2015-08-25 08:47:40,650 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > security.UserGroupInformation > (UserGroupInformation.java:logPrivilegedAction(1693)) - PrivilegedAction > as:hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > (auth:KERBEROS) > from:org.apache.sentry.provider.db.service.thrift.SentryPolicyServiceClient$UgiSaslClientTransport.open(SentryPolicyServiceClient.java:105) > 2015-08-25 08:47:40,650 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:open(261)) - opening transport > org.apache.sentry.provider.db.service.thrift.SentryPolicyServiceClient$UgiSaslClientTransport@10547c9a > 2015-08-25 08:47:40,651 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslClientTransport > (TSaslClientTransport.java:handleSaslStartMessage(96)) - Sending mechanism > name GSSAPI and initial response of length 712 > 2015-08-25 08:47:40,651 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:sendSaslMessage(162)) - CLIENT: > Writing message with status START and payload length 6 > 2015-08-25 08:47:40,651 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:sendSaslMessage(162)) - CLIENT: > Writing message with status OK and payload length 712 > 2015-08-25 08:47:40,652 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:open(273)) - CLIENT: Start > message handled > 2015-08-25 08:47:40,653 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:receiveSaslMessage(206)) - > CLIENT: Received message with status OK and payload length 110 > 2015-08-25 08:47:40,654 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:sendSaslMessage(162)) - CLIENT: > Writing message with status OK and payload length 0 > 2015-08-25 08:47:40,654 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:receiveSaslMessage(206)) - > CLIENT: Received message with status OK and payload length 65 > 2015-08-25 08:47:40,654 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:sendSaslMessage(162)) - CLIENT: > Writing message with status COMPLETE and payload length 65 > 2015-08-25 08:47:40,655 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:open(296)) - CLIENT: Main > negotiation loop complete > 2015-08-25 08:47:40,655 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:open(306)) - CLIENT: SASL > Client receiving last message > 2015-08-25 08:47:40,655 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:receiveSaslMessage(206)) - > CLIENT: Received message with status COMPLETE and payload length 0 > 2015-08-25 08:47:40,655 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.SentryPolicyServiceClient (SentryPolicyServiceClient.java:<init>(161)) > - Successfully opened transport: > org.apache.sentry.provider.db.service.thrift.SentryPolicyServiceClient$UgiSaslClientTransport@10547c9a > to ip-10-87-39-41.eu-west-1.compute.internal/10.87.39.41:8038 > 2015-08-25 08:47:40,655 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.SentryPolicyServiceClient (SentryPolicyServiceClient.java:<init>(174)) > - Successfully created client > 2015-08-25 08:47:40,655 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > hive.SentryHiveAuthorizationTaskFactoryImpl > (SentryHiveAuthorizationTaskFactoryImpl.java:analyzePrincipalListDef(350)) - > ## Principal : [ grp2_role, ROLE] > 2015-08-25 08:47:40,656 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > security.Groups (Groups.java:getGroups(165)) - Returning cached groups for > 'hive' > 2015-08-25 08:47:40,656 INFO [HiveServer2-Handler-Pool: Thread-1038]: > ql.Driver (Driver.java:compile(433)) - Semantic Analysis Completed > 2015-08-25 08:47:40,656 INFO [HiveServer2-Handler-Pool: Thread-1038]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG > method=semanticAnalyze start=1440506860615 end=1440506860656 duration=41 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,656 INFO [HiveServer2-Handler-Pool: Thread-1038]: > ql.Driver (Driver.java:getSchema(239)) - Returning Hive schema: > Schema(fieldSchemas:null, properties:null) > 2015-08-25 08:47:40,656 INFO [HiveServer2-Handler-Pool: Thread-1038]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG method=compile > start=1440506860614 end=1440506860656 duration=42 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,657 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > cli.CLIService (CLIService.java:executeStatementAsync(273)) - SessionHandle > [a5845416-64e7-4cf5-ab57-fd7b5ad9d4a8]: executeStatementAsync() > 2015-08-25 08:47:40,657 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:flush(498)) - writing data > length: 109 > 2015-08-25 08:47:40,657 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > security.UserGroupInformation > (UserGroupInformation.java:logPrivilegedAction(1693)) - PrivilegedAction > as:hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > (auth:KERBEROS) > from:org.apache.hive.service.cli.operation.SQLOperation$1.run(SQLOperation.java:209) > 2015-08-25 08:47:40,660 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(654)) - > AUTH ID ======>hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,660 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(691)) - > Set remoteUser :hive, from endUser > :hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,660 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:readFrame(459)) - SERVER: > reading data length: 117 > 2015-08-25 08:47:40,661 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > cli.CLIService (CLIService.java:fetchResults(453)) - OperationHandle > [opType=EXECUTE_STATEMENT, > getHandleIdentifier()=b0ca3408-4b09-47e2-8174-f7aa66cb35c0]: fetchResults() > 2015-08-25 08:47:40,661 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:flush(498)) - writing data > length: 96 > 2015-08-25 08:47:40,661 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(654)) - > AUTH ID ======>hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,661 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(691)) - > Set remoteUser :hive, from endUser > :hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,661 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:readFrame(459)) - SERVER: > reading data length: 100 > 2015-08-25 08:47:40,661 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG > method=Driver.run from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,661 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG > method=TimeToSubmit from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,662 INFO [HiveServer2-Background-Pool: Thread-1889]: > ql.Driver (Driver.java:checkConcurrency(159)) - Concurrency mode is disabled, > not creating a lock manager > 2015-08-25 08:47:40,662 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG > method=Driver.execute from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,662 INFO [HiveServer2-Background-Pool: Thread-1889]: > ql.Driver (Driver.java:execute(1317)) - Starting command: GRANT SELECT ON > TABLE `newdb.smallairport` TO ROLE grp2_role > 2015-08-25 08:47:40,662 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG > method=TimeToSubmit start=1440506860661 end=1440506860662 duration=1 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,662 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG method=runTasks > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,662 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG > method=task.SENTRY.Stage-0 from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,662 INFO [HiveServer2-Background-Pool: Thread-1889]: > ql.Driver (Driver.java:launchTask(1636)) - Starting task [Stage-0:DDL] in > serial mode > 2015-08-25 08:47:40,663 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > thrift.SentryPolicyServiceClient (SentryPolicyServiceClient.java:<init>(143)) > - Using server kerberos principal: > sentry/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,663 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > security.UserGroupInformation (UserGroupInformation.java:getTGT(871)) - Found > tgt Ticket (hex) = > 0000: 61 82 01 72 30 82 01 6E A0 03 02 01 05 A1 0E 1B a..r0..n........ > 0010: 0C 45 43 32 2E 49 4E 54 45 52 4E 41 4C A2 21 30 .EC2.INTERNAL.!0 > 0020: 1F A0 03 02 01 02 A1 18 30 16 1B 06 6B 72 62 74 ........0...krbt > 0030: 67 74 1B 0C 45 43 32 2E 49 4E 54 45 52 4E 41 4C gt..EC2.INTERNAL > 0040: A3 82 01 32 30 82 01 2E A0 03 02 01 10 A1 03 02 ...20........... > 0050: 01 01 A2 82 01 20 04 82 01 1C AE 31 13 F6 95 B5 ..... .....1.... > 0060: 48 50 02 45 F7 CF 45 3A EF C4 18 70 7A EC 35 FD HP.E..E:...pz.5. > 0070: 41 A3 36 F8 63 F3 B1 A2 90 41 F1 B8 11 39 EA 2A A.6.c....A...9.* > 0080: B8 57 F2 53 67 FC 4F 3C 70 2F AB 88 32 F7 B3 FC .W.Sg.O<p/..2... > 0090: EB 3A D3 D5 F7 1A 69 08 D9 22 95 5B 1F 1C EF 1F .:....i..".[.... > 00A0: F6 AE FF A4 7F B5 EF 0C 04 02 84 FF C1 B1 42 AA ..............B. > 00B0: A5 32 CD 7C EF 59 DB 34 80 EF 9C 0D 2A 64 64 B6 .2...Y.4....*dd. > 00C0: 2E BF 45 D0 FD 37 8E C7 70 0F 62 1D 21 4E 77 43 ..E..7..p.b.!NwC > 00D0: A7 09 9F C6 9C F4 34 EA 03 BE AB AB 13 97 88 86 ......4......... > 00E0: 14 44 24 CF 47 B7 E8 C5 7A FA 50 F0 05 C2 C8 A6 .D$.G...z.P..... > 00F0: 0A F9 39 58 91 5F 2C 92 30 96 32 AA EB 29 AA EA ..9X._,.0.2..).. > 0100: B5 71 78 1C 75 90 76 53 43 53 49 A2 42 90 44 40 .qx.u.vSCSI.B.D@ > 0110: EA C4 45 36 76 57 0F 73 2B E5 5E 94 52 0C 38 3E ..E6vW.s+.^.R.8> > 0120: C3 EC 5A 20 59 5E 92 7C 13 DD EE 8D 3B F3 71 36 ..Z Y^......;.q6 > 0130: 82 97 57 F4 1B 23 AD 06 CE 33 5B 60 64 F8 41 0B ..W..#...3[`d.A. > 0140: 12 00 9B 9E 5F 4C 7C 72 FD 1C A1 13 1E 9E 86 BA ...._L.r........ > 0150: 7E 5E D5 1B B2 8C 43 4E DE FD 88 4B B0 13 A9 DA .^....CN...K.... > 0160: 13 29 F3 04 98 70 A1 12 42 65 F6 FD E5 18 50 83 .)...p..Be....P. > 0170: D5 AE 4E 84 76 15 ..N.v. > Client Principal = hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > Server Principal = krbtgt/EC2.INTERNAL@EC2.INTERNAL > Session Key = EncryptionKey: keyType=16 keyBytes (hex dump)= > 0000: 73 E9 CE 43 AB 62 57 3B D5 FE C4 10 E5 20 3B 5E s..C.bW;..... ;^ > 0010: 07 5B EC A1 37 C8 D3 9B .[..7... > Forwardable Ticket true > Forwarded Ticket false > Proxiable Ticket false > Proxy Ticket false > Postdated Ticket false > Renewable Ticket false > Initial Ticket false > Auth Time = Mon Aug 24 03:20:39 EDT 2015 > Start Time = Mon Aug 24 03:20:39 EDT 2015 > End Time = Wed Aug 26 03:20:39 EDT 2015 > Renew Till = null > Client Addresses Null > 2015-08-25 08:47:40,664 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > security.UserGroupInformation > (UserGroupInformation.java:logPrivilegedAction(1693)) - PrivilegedAction > as:hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > (auth:KERBEROS) > from:org.apache.sentry.provider.db.service.thrift.SentryPolicyServiceClient$UgiSaslClientTransport.open(SentryPolicyServiceClient.java:105) > 2015-08-25 08:47:40,664 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:open(261)) - opening transport > org.apache.sentry.provider.db.service.thrift.SentryPolicyServiceClient$UgiSaslClientTransport@302d394d > 2015-08-25 08:47:40,665 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslClientTransport > (TSaslClientTransport.java:handleSaslStartMessage(96)) - Sending mechanism > name GSSAPI and initial response of length 712 > 2015-08-25 08:47:40,665 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:sendSaslMessage(162)) - CLIENT: > Writing message with status START and payload length 6 > 2015-08-25 08:47:40,665 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:sendSaslMessage(162)) - CLIENT: > Writing message with status OK and payload length 712 > 2015-08-25 08:47:40,665 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:open(273)) - CLIENT: Start > message handled > 2015-08-25 08:47:40,667 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:receiveSaslMessage(206)) - > CLIENT: Received message with status OK and payload length 110 > 2015-08-25 08:47:40,667 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:sendSaslMessage(162)) - CLIENT: > Writing message with status OK and payload length 0 > 2015-08-25 08:47:40,667 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:receiveSaslMessage(206)) - > CLIENT: Received message with status OK and payload length 65 > 2015-08-25 08:47:40,667 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:sendSaslMessage(162)) - CLIENT: > Writing message with status COMPLETE and payload length 65 > 2015-08-25 08:47:40,668 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:open(296)) - CLIENT: Main > negotiation loop complete > 2015-08-25 08:47:40,668 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:open(306)) - CLIENT: SASL > Client receiving last message > 2015-08-25 08:47:40,668 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:receiveSaslMessage(206)) - > CLIENT: Received message with status COMPLETE and payload length 0 > 2015-08-25 08:47:40,668 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > thrift.SentryPolicyServiceClient (SentryPolicyServiceClient.java:<init>(161)) > - Successfully opened transport: > org.apache.sentry.provider.db.service.thrift.SentryPolicyServiceClient$UgiSaslClientTransport@302d394d > to ip-10-87-39-41.eu-west-1.compute.internal/10.87.39.41:8038 > 2015-08-25 08:47:40,668 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > thrift.SentryPolicyServiceClient (SentryPolicyServiceClient.java:<init>(174)) > - Successfully created client > 2015-08-25 08:47:40,668 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:flush(490)) - data length > before wrap: 198 > 2015-08-25 08:47:40,669 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:flush(498)) - writing data > length: 258 > 2015-08-25 08:47:40,676 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:readFrame(459)) - CLIENT: > reading data length: 234 > 2015-08-25 08:47:40,676 DEBUG [HiveServer2-Background-Pool: Thread-1889]: > transport.TSaslTransport (TSaslTransport.java:readFrame(463)) - data length > after unwrap: 169 > 2015-08-25 08:47:40,676 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG method=runTasks > start=1440506860662 end=1440506860676 duration=14 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,676 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG > method=Driver.execute start=1440506860662 end=1440506860676 duration=14 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,676 INFO [HiveServer2-Background-Pool: Thread-1889]: > ql.Driver (SessionState.java:printInfo(852)) - OK > 2015-08-25 08:47:40,676 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG > method=releaseLocks from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,677 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG > method=releaseLocks start=1440506860676 end=1440506860677 duration=1 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,677 INFO [HiveServer2-Background-Pool: Thread-1889]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG > method=Driver.run start=1440506860661 end=1440506860677 duration=16 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,677 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > cli.CLIService (CLIService.java:getOperationStatus(400)) - OperationHandle > [opType=EXECUTE_STATEMENT, > getHandleIdentifier()=b0ca3408-4b09-47e2-8174-f7aa66cb35c0]: > getOperationStatus() > 2015-08-25 08:47:40,677 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:flush(498)) - writing data > length: 53 > 2015-08-25 08:47:40,677 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(654)) - > AUTH ID ======>hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,677 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(691)) - > Set remoteUser :hive, from endUser > :hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,678 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:readFrame(459)) - SERVER: > reading data length: 117 > 2015-08-25 08:47:40,678 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > cli.CLIService (CLIService.java:fetchResults(453)) - OperationHandle > [opType=EXECUTE_STATEMENT, > getHandleIdentifier()=b0ca3408-4b09-47e2-8174-f7aa66cb35c0]: fetchResults() > 2015-08-25 08:47:40,678 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:flush(498)) - writing data > length: 96 > 2015-08-25 08:47:40,678 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(654)) - > AUTH ID ======>hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,678 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(691)) - > Set remoteUser :hive, from endUser > :hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,678 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:readFrame(459)) - SERVER: > reading data length: 117 > 2015-08-25 08:47:40,679 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > cli.CLIService (CLIService.java:fetchResults(453)) - OperationHandle > [opType=EXECUTE_STATEMENT, > getHandleIdentifier()=b0ca3408-4b09-47e2-8174-f7aa66cb35c0]: fetchResults() > 2015-08-25 08:47:40,679 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:flush(498)) - writing data > length: 96 > 2015-08-25 08:47:40,679 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(654)) - > AUTH ID ======>hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,679 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(691)) - > Set remoteUser :hive, from endUser > :hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,679 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:readFrame(459)) - SERVER: > reading data length: 96 > 2015-08-25 08:47:40,679 INFO [HiveServer2-Handler-Pool: Thread-1038]: > log.PerfLogger (PerfLogger.java:PerfLogBegin(121)) - <PERFLOG > method=releaseLocks from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,679 INFO [HiveServer2-Handler-Pool: Thread-1038]: > log.PerfLogger (PerfLogger.java:PerfLogEnd(148)) - </PERFLOG > method=releaseLocks start=1440506860679 end=1440506860679 duration=0 > from=org.apache.hadoop.hive.ql.Driver> > 2015-08-25 08:47:40,680 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > cli.CLIService (CLIService.java:closeOperation(423)) - OperationHandle > [opType=EXECUTE_STATEMENT, > getHandleIdentifier()=b0ca3408-4b09-47e2-8174-f7aa66cb35c0]: closeOperation > 2015-08-25 08:47:40,680 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > transport.TSaslTransport (TSaslTransport.java:flush(498)) - writing data > length: 42 > 2015-08-25 08:47:40,680 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(654)) - > AUTH ID ======>hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > 2015-08-25 08:47:40,680 DEBUG [HiveServer2-Handler-Pool: Thread-1038]: > thrift.HadoopThriftAuthBridge (HadoopThriftAuthBridge.java:process(691)) - > Set remoteUser :hive, from endUser > :hive/ip-10-87-39-41.eu-west-1.compute.internal@EC2.INTERNAL > {noformat} > The _operationText_ on the Sentry log doesn't mention the exact statement > being made on beeline console: > {noformat}"operationText":"GRANT SELECT ON TABLE smallairport TO ROLE > grp2_role"{noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)