[
https://issues.apache.org/jira/browse/HIVE-29753?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Indhumathi Muthumurugesh updated HIVE-29753:
--------------------------------------------
Description:
When StorageBasedAuthorizationProvider.checkPermissions() calls
FileUtils.getFileStatusOrNull() to resolve HDFS path permissions, the
underlying NameNode RPC (getFileInfo) can block for an extended duration.
During this time, Metastore Handler threads are silently stuck with no INFO or
WARN log emitted — the issue is only detectable via thread dumps or DEBUG-level
logging.
Example thread dump showing the silent block:
{code:java}
java.lang.Thread.State: WAITING (on object monitor)
at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1571)
at
org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getFileInfo(...)
at
org.apache.hadoop.hive.common.FileUtils.getFileStatusOrNull(FileUtils.java:1114)
at
org.apache.hadoop.hive.ql.security.authorization.StorageBasedAuthorizationProvider.checkPermissions(...)
at org.apache.hadoop.hive.metastore.HMSHandler.get_database(...){code}
In production this can manifest as Metastore thread pool exhaustion with no
actionable log evidence.
{code:java}
>From 35e6b60f7b08d91c5ff3a56d9832b6ccebe37bee Mon Sep 17 00:00:00 2001
From: anonymous
Date: Tue, 21 Jul 2026 12:16:33 +0530
Subject: [PATCH 1/2] Add WARN-level logging for slow
getFileInfo calls during storage-based authorizationAdd a configurable
WARN-level log to StorageBasedAuthorizationProvider.checkPermissions()
that fires when HDFS getFileInfo (via FileUtils.getFileStatusOrNull) takes
longer than a
threshold. This makes slow NameNode RPC calls visible in standard logs without
debug mode.Changes:
- HiveConf.java: Add METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS
conf var
(hive.metastore.authorization.fileinfo.slow.warn.threshold.ms, default 300ms,
-1 to disable)
- StorageBasedAuthorizationProvider.java: Instrument both getFileStatusOrNull
call sites
in checkPermissions() with System.currentTimeMillis() timing; emit LOG.warn
with path
and elapsed ms when threshold exceeded (primary path check + parent traversal
loop)---
.../org/apache/hadoop/hive/conf/HiveConf.java | 5 +++++
.../StorageBasedAuthorizationProvider.java | 15 +++++++++++++++
2 files changed, 20 insertions(+)diff --git
a/common/src/java/org/apache/hadoop/hive/conf/HiveConf.java
b/common/src/java/org/apache/hadoop/hive/conf/HiveConf.java
index deb0ced50a..5a1911b99c 100644
--- a/common/src/java/org/apache/hadoop/hive/conf/HiveConf.java
+++ b/common/src/java/org/apache/hadoop/hive/conf/HiveConf.java
@@ -1398,6 +1398,11 @@ public static enum ConfVars {
"StorageBasedAuthorization already does this check for managed table.
For external table however,\n" +
"anyone who has read permission of the directory could drop external
table, which is surprising.\n" +
"The flag is set to false by default to maintain backward
compatibility."),
+ METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS(
+ "hive.metastore.authorization.fileinfo.slow.warn.threshold.ms", 300L,
+ "Threshold in milliseconds above which a WARN log is emitted for slow
HDFS getFileInfo calls\n" +
+ "during storage-based authorization checks. A value of -1 disables the
warning entirely.\n" +
+ "Default is 300ms."),
/**
* @deprecated Use MetastoreConf.EVENT_CLEAN_FREQ
*/
diff --git
a/ql/src/java/org/apache/hadoop/hive/ql/security/authorization/StorageBasedAuthorizationProvider.java
b/ql/src/java/org/apache/hadoop/hive/ql/security/authorization/StorageBasedAuthorizationProvider.java
index 1058ce3b6d..c2460c2f7e 100644
---
a/ql/src/java/org/apache/hadoop/hive/ql/security/authorization/StorageBasedAuthorizationProvider.java
+++
b/ql/src/java/org/apache/hadoop/hive/ql/security/authorization/StorageBasedAuthorizationProvider.java
@@ -407,8 +407,17 @@ protected void checkPermissions(final Configuration conf,
final Path path,
} final FileSystem fs = path.getFileSystem(conf);
+ final long slowWarnThresholdMs = conf.getLong(
+
HiveConf.ConfVars.METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS.varname,
+
HiveConf.ConfVars.METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS.defaultLongVal);+
long t0 = System.currentTimeMillis();
FileStatus pathStatus = FileUtils.getFileStatusOrNull(fs, path);
+ long elapsed = System.currentTimeMillis() - t0;
+ if (slowWarnThresholdMs >= 0 && elapsed > slowWarnThresholdMs) {
+ LOG.warn("Slow getFileInfo during storage-based authorization check:
path={}, elapsed={}ms",
+ path, elapsed);
+ }
if (pathStatus != null) {
checkPermissions(fs, pathStatus, actions, authenticator.getUserName());
} else if (path.getParent() != null) {
@@ -416,7 +425,13 @@ protected void checkPermissions(final Configuration conf,
final Path path,
Path par = path.getParent();
FileStatus parStatus = null;
while (par != null) {
+ long t1 = System.currentTimeMillis();
parStatus = FileUtils.getFileStatusOrNull(fs, par);
+ long elapsedPar = System.currentTimeMillis() - t1;
+ if (slowWarnThresholdMs >= 0 && elapsedPar > slowWarnThresholdMs) {
+ LOG.warn("Slow getFileInfo during storage-based authorization check
(parent traversal): "
+ + "path={}, elapsed={}ms", par, elapsedPar);
+ }
if (parStatus != null) {
break;
}
--
2.50.1 (Apple Git-155)
>From f65806b93fc24f5d38ffabd753381f7ea623477d Mon Sep 17 00:00:00 2001
From: anonymous
Date: Tue, 21 Jul 2026 14:57:59 +0530
Subject: [PATCH 2/2] Add integration tests for slow
getFileInfo WARN loggingTwo integration tests in
TestStorageBasedAuthorizationSlowFileInfoLog exercise
the full production code path end-to-end:
msc.getDatabase() -> AuthorizationPreEventListener ->
StorageBasedAuthorizationProvider
-> checkPermissions() -> FileUtils.getFileStatusOrNull() ->
FileSystem.getFileStatus()- testNoSlowWarnWhenThresholdDisabled: threshold=-1
in metastore conf (set via
System.setProperty before startup) -> no WARN after real getDatabase() auth
check
- testSlowWarnEmittedWhenFileSystemIsSlow: threshold=10ms + SlowLocalFileSystem
(sleeps 30ms in getFileStatus, registered via fs.file.impl) -> WARN IS emitted
through real checkPermissions() code path---
...rageBasedAuthorizationSlowFileInfoLog.java | 206 ++++++++++++++++++
1 file changed, 206 insertions(+)
create mode 100644
itests/hive-unit/src/test/java/org/apache/hadoop/hive/ql/security/TestStorageBasedAuthorizationSlowFileInfoLog.javadiff
--git
a/itests/hive-unit/src/test/java/org/apache/hadoop/hive/ql/security/TestStorageBasedAuthorizationSlowFileInfoLog.java
b/itests/hive-unit/src/test/java/org/apache/hadoop/hive/ql/security/TestStorageBasedAuthorizationSlowFileInfoLog.java
new file mode 100644
index 0000000000..d07dcbb7c8
--- /dev/null
+++
b/itests/hive-unit/src/test/java/org/apache/hadoop/hive/ql/security/TestStorageBasedAuthorizationSlowFileInfoLog.java
@@ -0,0 +1,206 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.apache.hadoop.hive.ql.security;
+
+import static org.junit.Assert.assertFalse;
+import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.assertTrue;
+
+import java.io.IOException;
+
+import org.apache.hadoop.fs.FileStatus;
+import org.apache.hadoop.fs.LocalFileSystem;
+import org.apache.hadoop.fs.Path;
+import org.apache.hadoop.hive.conf.HiveConf;
+import org.apache.hadoop.hive.conf.HiveConfForTest;
+import org.apache.hadoop.hive.metastore.HiveMetaStoreClient;
+import org.apache.hadoop.hive.metastore.MetaStoreTestUtils;
+import org.apache.hadoop.hive.metastore.api.Database;
+import org.apache.hadoop.hive.ql.metadata.StringAppender;
+import
org.apache.hadoop.hive.ql.security.authorization.AuthorizationPreEventListener;
+import
org.apache.hadoop.hive.ql.security.authorization.StorageBasedAuthorizationProvider;
+import org.apache.logging.log4j.Level;
+import org.junit.After;
+import org.junit.Before;
+import org.junit.Test;
+
+/**
+ * Integration tests for the slow-getFileInfo WARN logging in
+ * StorageBasedAuthorizationProvider.checkPermissions().
+ *
+ * Exercises the real production code path end-to-end:
+ * msc.getDatabase() -> AuthorizationPreEventListener.authorizeReadDatabase()
+ * -> StorageBasedAuthorizationProvider.checkPermissions()
+ * -> FileUtils.getFileStatusOrNull() -> FileSystem.getFileStatus()
+ *
+ * Two scenarios are tested:
+ * 1. threshold=-1 (disabled): no WARN emitted regardless of elapsed time
+ * 2. threshold=10ms + SlowLocalFileSystem (sleeps 30ms): WARN IS emitted
+ * because elapsed(~30ms) > threshold(10ms) through the real code path
+ *
+ * Each test starts its own metastore instance so System.setProperty values
+ * (threshold, fs.file.impl) are picked up by the metastore's HiveConf at
startup.
+ */
+public class TestStorageBasedAuthorizationSlowFileInfoLog {
+
+ private static final String THRESHOLD_KEY =
+
HiveConf.ConfVars.METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS.varname;
+ private static final String LOGGER_NAME =
+ StorageBasedAuthorizationProvider.class.getName();
+
+ private HiveMetaStoreClient msc;
+ private StringAppender appender;
+
+ /**
+ * LocalFileSystem wrapper that sleeps 30ms in getFileStatus to simulate
+ * a slow HDFS NameNode RPC. Registered via fs.file.impl so it is used
+ * by the metastore's StorageBasedAuthorizationProvider when it calls
+ * FileUtils.getFileStatusOrNull(fs, path).
+ */
+ public static class SlowLocalFileSystem extends LocalFileSystem {
+ @Override
+ public FileStatus getFileStatus(Path f) throws IOException {
+ try {
+ Thread.sleep(30); // 30ms > 10ms threshold used in the WARN test
+ } catch (InterruptedException e) {
+ Thread.currentThread().interrupt();
+ }
+ return super.getFileStatus(f);
+ }
+ }
+
+ @Before
+ public void setUpAppender() {
+ appender = StringAppender.createStringAppender("%m");
+ appender.addToLogger(LOGGER_NAME, Level.WARN);
+ appender.start();
+ }
+
+ @After
+ public void tearDown() throws Exception {
+ if (appender != null) {
+ appender.removeFromLogger(LOGGER_NAME);
+ }
+ if (msc != null) {
+ msc.close();
+ }
+ InjectableDummyAuthenticator.injectMode(false);
+
System.clearProperty(HiveConf.ConfVars.METASTORE_PRE_EVENT_LISTENERS.varname);
+
System.clearProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHORIZATION_MANAGER.varname);
+
System.clearProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHENTICATOR_MANAGER.varname);
+
System.clearProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHORIZATION_AUTH_READS.varname);
+ System.clearProperty(THRESHOLD_KEY);
+ System.clearProperty("fs.file.impl");
+ System.clearProperty("fs.file.impl.disable.cache");
+ }
+
+ /**
+ * Starts a fresh metastore with all required System properties already set
so
+ * the metastore-side HiveConf picks them up at construction time.
+ *
+ * @param thresholdMs value for
hive.metastore.authorization.fileinfo.slow.warn.threshold.ms
+ * @param slowFs if true, registers SlowLocalFileSystem as fs.file.impl
+ */
+ private void startMetaStore(long thresholdMs, boolean slowFs) throws
Exception {
+ System.setProperty(HiveConf.ConfVars.METASTORE_PRE_EVENT_LISTENERS.varname,
+ AuthorizationPreEventListener.class.getName());
+
System.setProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHORIZATION_MANAGER.varname,
+ StorageBasedAuthorizationProvider.class.getName());
+
System.setProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHENTICATOR_MANAGER.varname,
+ InjectableDummyAuthenticator.class.getName());
+
System.setProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHORIZATION_AUTH_READS.varname,
"true");
+ System.setProperty(THRESHOLD_KEY, String.valueOf(thresholdMs));
+ if (slowFs) {
+ System.setProperty("fs.file.impl", SlowLocalFileSystem.class.getName());
+ System.setProperty("fs.file.impl.disable.cache", "true");
+ }
+
+ int port = MetaStoreTestUtils.startMetaStoreWithRetry();
+
+ HiveConf clientConf = new HiveConfForTest(getClass());
+ clientConf.setVar(HiveConf.ConfVars.METASTORE_URIS, "thrift://localhost:"
+ port);
+
clientConf.setIntVar(HiveConf.ConfVars.METASTORE_THRIFT_CONNECTION_RETRIES, 3);
+ clientConf.setBoolVar(HiveConf.ConfVars.HIVE_AUTHORIZATION_ENABLED, false);
+
+ msc = new HiveMetaStoreClient(clientConf);
+ InjectableDummyAuthenticator.injectMode(false);
+ }
+
+ /**
+ * threshold=-1 (disabled): no WARN emitted after a real getDatabase() auth
check.
+ * Fully deterministic — threshold=-1 suppresses the WARN unconditionally.
+ */
+ @Test
+ public void testNoSlowWarnWhenThresholdDisabled() throws Exception {
+ startMetaStore(-1, false);
+
+ Database db = new Database("slow_log_disabled_db", null, null, null);
+ msc.createDatabase(db);
+ assertNotNull(msc.getDatabase("slow_log_disabled_db"));
+
+ appender.reset();
+ InjectableDummyAuthenticator.injectMode(true);
+ try {
+ msc.getDatabase("slow_log_disabled_db");
+ } catch (Exception ignored) {
+ } finally {
+ InjectableDummyAuthenticator.injectMode(false);
+ }
+
+ String output = appender.getOutput();
+ assertFalse(
+ "No 'Slow getFileInfo' WARN expected when threshold=-1, got: " +
output,
+ output.contains("Slow getFileInfo"));
+
+ msc.dropDatabase("slow_log_disabled_db");
+ }
+
+ /**
+ * threshold=10ms + SlowLocalFileSystem (sleeps 30ms): WARN IS emitted.
+ *
+ * SlowLocalFileSystem is registered as fs.file.impl so the metastore's
+ * StorageBasedAuthorizationProvider uses it when calling
getFileStatusOrNull().
+ * The 30ms sleep ensures elapsed(~30ms) > threshold(10ms), triggering the
real
+ * LOG.warn inside checkPermissions() in the production code.
+ */
+ @Test
+ public void testSlowWarnEmittedWhenFileSystemIsSlow() throws Exception {
+ startMetaStore(10, true); // 10ms threshold, SlowLocalFileSystem enabled
+
+ Database db = new Database("slow_log_slow_db", null, null, null);
+ msc.createDatabase(db);
+ assertNotNull(msc.getDatabase("slow_log_slow_db"));
+
+ appender.reset();
+ InjectableDummyAuthenticator.injectMode(true);
+ try {
+ msc.getDatabase("slow_log_slow_db");
+ } catch (Exception ignored) {
+ } finally {
+ InjectableDummyAuthenticator.injectMode(false);
+ }
+
+ String output = appender.getOutput();
+ assertTrue(
+ "Expected 'Slow getFileInfo' WARN when elapsed(~30ms) >
threshold(10ms), got: " + output,
+ output.contains("Slow getFileInfo"));
+
+ msc.dropDatabase("slow_log_slow_db");
+ }
+}
--
2.50.1 (Apple Git-155) {code}
was:
When StorageBasedAuthorizationProvider.checkPermissions() calls
FileUtils.getFileStatusOrNull() to resolve HDFS path permissions, the
underlying NameNode RPC (getFileInfo) can block for an extended duration.
During this time, Metastore Handler threads are silently stuck with no INFO or
WARN log emitted — the issue is only detectable via thread dumps or DEBUG-level
logging.
Example thread dump showing the silent block:
{code:java}
java.lang.Thread.State: WAITING (on object monitor)
at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1571)
at
org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getFileInfo(...)
at
org.apache.hadoop.hive.common.FileUtils.getFileStatusOrNull(FileUtils.java:1114)
at
org.apache.hadoop.hive.ql.security.authorization.StorageBasedAuthorizationProvider.checkPermissions(...)
at org.apache.hadoop.hive.metastore.HMSHandler.get_database(...){code}
In production this can manifest as Metastore thread pool exhaustion with no
actionable log evidence.
> StorageBasedAuthorizationProvider silently blocks on slow HDFS getFileInfo
> calls with no observable logging
> -----------------------------------------------------------------------------------------------------------
>
> Key: HIVE-29753
> URL: https://issues.apache.org/jira/browse/HIVE-29753
> Project: Hive
> Issue Type: Improvement
> Components: Authorization, Metastore
> Reporter: Indhumathi Muthumurugesh
> Assignee: Indhumathi Muthumurugesh
> Priority: Minor
>
> When StorageBasedAuthorizationProvider.checkPermissions() calls
> FileUtils.getFileStatusOrNull() to resolve HDFS path permissions, the
> underlying NameNode RPC (getFileInfo) can block for an extended duration.
> During this time, Metastore Handler threads are silently stuck with no INFO
> or WARN log emitted — the issue is only detectable via thread dumps or
> DEBUG-level logging.
> Example thread dump showing the silent block:
> {code:java}
> java.lang.Thread.State: WAITING (on object monitor)
> at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1571)
> at
> org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getFileInfo(...)
> at
> org.apache.hadoop.hive.common.FileUtils.getFileStatusOrNull(FileUtils.java:1114)
> at
> org.apache.hadoop.hive.ql.security.authorization.StorageBasedAuthorizationProvider.checkPermissions(...)
> at org.apache.hadoop.hive.metastore.HMSHandler.get_database(...){code}
>
> In production this can manifest as Metastore thread pool exhaustion with no
> actionable log evidence.
> {code:java}
> From 35e6b60f7b08d91c5ff3a56d9832b6ccebe37bee Mon Sep 17 00:00:00 2001
> From: anonymous
> Date: Tue, 21 Jul 2026 12:16:33 +0530
> Subject: [PATCH 1/2] Add WARN-level logging for slow
> getFileInfo calls during storage-based authorizationAdd a configurable
> WARN-level log to StorageBasedAuthorizationProvider.checkPermissions()
> that fires when HDFS getFileInfo (via FileUtils.getFileStatusOrNull) takes
> longer than a
> threshold. This makes slow NameNode RPC calls visible in standard logs
> without debug mode.Changes:
> - HiveConf.java: Add METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS
> conf var
> (hive.metastore.authorization.fileinfo.slow.warn.threshold.ms, default
> 300ms, -1 to disable)
> - StorageBasedAuthorizationProvider.java: Instrument both getFileStatusOrNull
> call sites
> in checkPermissions() with System.currentTimeMillis() timing; emit LOG.warn
> with path
> and elapsed ms when threshold exceeded (primary path check + parent
> traversal loop)---
> .../org/apache/hadoop/hive/conf/HiveConf.java | 5 +++++
> .../StorageBasedAuthorizationProvider.java | 15 +++++++++++++++
> 2 files changed, 20 insertions(+)diff --git
> a/common/src/java/org/apache/hadoop/hive/conf/HiveConf.java
> b/common/src/java/org/apache/hadoop/hive/conf/HiveConf.java
> index deb0ced50a..5a1911b99c 100644
> --- a/common/src/java/org/apache/hadoop/hive/conf/HiveConf.java
> +++ b/common/src/java/org/apache/hadoop/hive/conf/HiveConf.java
> @@ -1398,6 +1398,11 @@ public static enum ConfVars {
> "StorageBasedAuthorization already does this check for managed
> table. For external table however,\n" +
> "anyone who has read permission of the directory could drop external
> table, which is surprising.\n" +
> "The flag is set to false by default to maintain backward
> compatibility."),
> + METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS(
> + "hive.metastore.authorization.fileinfo.slow.warn.threshold.ms", 300L,
> + "Threshold in milliseconds above which a WARN log is emitted for
> slow HDFS getFileInfo calls\n" +
> + "during storage-based authorization checks. A value of -1 disables
> the warning entirely.\n" +
> + "Default is 300ms."),
> /**
> * @deprecated Use MetastoreConf.EVENT_CLEAN_FREQ
> */
> diff --git
> a/ql/src/java/org/apache/hadoop/hive/ql/security/authorization/StorageBasedAuthorizationProvider.java
>
> b/ql/src/java/org/apache/hadoop/hive/ql/security/authorization/StorageBasedAuthorizationProvider.java
> index 1058ce3b6d..c2460c2f7e 100644
> ---
> a/ql/src/java/org/apache/hadoop/hive/ql/security/authorization/StorageBasedAuthorizationProvider.java
> +++
> b/ql/src/java/org/apache/hadoop/hive/ql/security/authorization/StorageBasedAuthorizationProvider.java
> @@ -407,8 +407,17 @@ protected void checkPermissions(final Configuration
> conf, final Path path,
> } final FileSystem fs = path.getFileSystem(conf);
> + final long slowWarnThresholdMs = conf.getLong(
> +
> HiveConf.ConfVars.METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS.varname,
> +
> HiveConf.ConfVars.METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS.defaultLongVal);+
> long t0 = System.currentTimeMillis();
> FileStatus pathStatus = FileUtils.getFileStatusOrNull(fs, path);
> + long elapsed = System.currentTimeMillis() - t0;
> + if (slowWarnThresholdMs >= 0 && elapsed > slowWarnThresholdMs) {
> + LOG.warn("Slow getFileInfo during storage-based authorization check:
> path={}, elapsed={}ms",
> + path, elapsed);
> + }
> if (pathStatus != null) {
> checkPermissions(fs, pathStatus, actions, authenticator.getUserName());
> } else if (path.getParent() != null) {
> @@ -416,7 +425,13 @@ protected void checkPermissions(final Configuration
> conf, final Path path,
> Path par = path.getParent();
> FileStatus parStatus = null;
> while (par != null) {
> + long t1 = System.currentTimeMillis();
> parStatus = FileUtils.getFileStatusOrNull(fs, par);
> + long elapsedPar = System.currentTimeMillis() - t1;
> + if (slowWarnThresholdMs >= 0 && elapsedPar > slowWarnThresholdMs) {
> + LOG.warn("Slow getFileInfo during storage-based authorization
> check (parent traversal): "
> + + "path={}, elapsed={}ms", par, elapsedPar);
> + }
> if (parStatus != null) {
> break;
> }
> --
> 2.50.1 (Apple Git-155)
> From f65806b93fc24f5d38ffabd753381f7ea623477d Mon Sep 17 00:00:00 2001
> From: anonymous
> Date: Tue, 21 Jul 2026 14:57:59 +0530
> Subject: [PATCH 2/2] Add integration tests for slow
> getFileInfo WARN loggingTwo integration tests in
> TestStorageBasedAuthorizationSlowFileInfoLog exercise
> the full production code path end-to-end:
> msc.getDatabase() -> AuthorizationPreEventListener ->
> StorageBasedAuthorizationProvider
> -> checkPermissions() -> FileUtils.getFileStatusOrNull() ->
> FileSystem.getFileStatus()- testNoSlowWarnWhenThresholdDisabled: threshold=-1
> in metastore conf (set via
> System.setProperty before startup) -> no WARN after real getDatabase() auth
> check
> - testSlowWarnEmittedWhenFileSystemIsSlow: threshold=10ms +
> SlowLocalFileSystem
> (sleeps 30ms in getFileStatus, registered via fs.file.impl) -> WARN IS
> emitted
> through real checkPermissions() code path---
> ...rageBasedAuthorizationSlowFileInfoLog.java | 206 ++++++++++++++++++
> 1 file changed, 206 insertions(+)
> create mode 100644
> itests/hive-unit/src/test/java/org/apache/hadoop/hive/ql/security/TestStorageBasedAuthorizationSlowFileInfoLog.javadiff
> --git
> a/itests/hive-unit/src/test/java/org/apache/hadoop/hive/ql/security/TestStorageBasedAuthorizationSlowFileInfoLog.java
>
> b/itests/hive-unit/src/test/java/org/apache/hadoop/hive/ql/security/TestStorageBasedAuthorizationSlowFileInfoLog.java
> new file mode 100644
> index 0000000000..d07dcbb7c8
> --- /dev/null
> +++
> b/itests/hive-unit/src/test/java/org/apache/hadoop/hive/ql/security/TestStorageBasedAuthorizationSlowFileInfoLog.java
> @@ -0,0 +1,206 @@
> +/*
> + * Licensed to the Apache Software Foundation (ASF) under one
> + * or more contributor license agreements. See the NOTICE file
> + * distributed with this work for additional information
> + * regarding copyright ownership. The ASF licenses this file
> + * to you under the Apache License, Version 2.0 (the
> + * "License"); you may not use this file except in compliance
> + * with the License. You may obtain a copy of the License at
> + *
> + * http://www.apache.org/licenses/LICENSE-2.0
> + *
> + * Unless required by applicable law or agreed to in writing, software
> + * distributed under the License is distributed on an "AS IS" BASIS,
> + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
> + * See the License for the specific language governing permissions and
> + * limitations under the License.
> + */
> +
> +package org.apache.hadoop.hive.ql.security;
> +
> +import static org.junit.Assert.assertFalse;
> +import static org.junit.Assert.assertNotNull;
> +import static org.junit.Assert.assertTrue;
> +
> +import java.io.IOException;
> +
> +import org.apache.hadoop.fs.FileStatus;
> +import org.apache.hadoop.fs.LocalFileSystem;
> +import org.apache.hadoop.fs.Path;
> +import org.apache.hadoop.hive.conf.HiveConf;
> +import org.apache.hadoop.hive.conf.HiveConfForTest;
> +import org.apache.hadoop.hive.metastore.HiveMetaStoreClient;
> +import org.apache.hadoop.hive.metastore.MetaStoreTestUtils;
> +import org.apache.hadoop.hive.metastore.api.Database;
> +import org.apache.hadoop.hive.ql.metadata.StringAppender;
> +import
> org.apache.hadoop.hive.ql.security.authorization.AuthorizationPreEventListener;
> +import
> org.apache.hadoop.hive.ql.security.authorization.StorageBasedAuthorizationProvider;
> +import org.apache.logging.log4j.Level;
> +import org.junit.After;
> +import org.junit.Before;
> +import org.junit.Test;
> +
> +/**
> + * Integration tests for the slow-getFileInfo WARN logging in
> + * StorageBasedAuthorizationProvider.checkPermissions().
> + *
> + * Exercises the real production code path end-to-end:
> + * msc.getDatabase() ->
> AuthorizationPreEventListener.authorizeReadDatabase()
> + * -> StorageBasedAuthorizationProvider.checkPermissions()
> + * -> FileUtils.getFileStatusOrNull() -> FileSystem.getFileStatus()
> + *
> + * Two scenarios are tested:
> + * 1. threshold=-1 (disabled): no WARN emitted regardless of elapsed time
> + * 2. threshold=10ms + SlowLocalFileSystem (sleeps 30ms): WARN IS emitted
> + * because elapsed(~30ms) > threshold(10ms) through the real code path
> + *
> + * Each test starts its own metastore instance so System.setProperty values
> + * (threshold, fs.file.impl) are picked up by the metastore's HiveConf at
> startup.
> + */
> +public class TestStorageBasedAuthorizationSlowFileInfoLog {
> +
> + private static final String THRESHOLD_KEY =
> +
> HiveConf.ConfVars.METASTORE_AUTHORIZATION_FILEINFO_SLOW_WARN_THRESHOLD_MS.varname;
> + private static final String LOGGER_NAME =
> + StorageBasedAuthorizationProvider.class.getName();
> +
> + private HiveMetaStoreClient msc;
> + private StringAppender appender;
> +
> + /**
> + * LocalFileSystem wrapper that sleeps 30ms in getFileStatus to simulate
> + * a slow HDFS NameNode RPC. Registered via fs.file.impl so it is used
> + * by the metastore's StorageBasedAuthorizationProvider when it calls
> + * FileUtils.getFileStatusOrNull(fs, path).
> + */
> + public static class SlowLocalFileSystem extends LocalFileSystem {
> + @Override
> + public FileStatus getFileStatus(Path f) throws IOException {
> + try {
> + Thread.sleep(30); // 30ms > 10ms threshold used in the WARN test
> + } catch (InterruptedException e) {
> + Thread.currentThread().interrupt();
> + }
> + return super.getFileStatus(f);
> + }
> + }
> +
> + @Before
> + public void setUpAppender() {
> + appender = StringAppender.createStringAppender("%m");
> + appender.addToLogger(LOGGER_NAME, Level.WARN);
> + appender.start();
> + }
> +
> + @After
> + public void tearDown() throws Exception {
> + if (appender != null) {
> + appender.removeFromLogger(LOGGER_NAME);
> + }
> + if (msc != null) {
> + msc.close();
> + }
> + InjectableDummyAuthenticator.injectMode(false);
> +
> System.clearProperty(HiveConf.ConfVars.METASTORE_PRE_EVENT_LISTENERS.varname);
> +
> System.clearProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHORIZATION_MANAGER.varname);
> +
> System.clearProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHENTICATOR_MANAGER.varname);
> +
> System.clearProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHORIZATION_AUTH_READS.varname);
> + System.clearProperty(THRESHOLD_KEY);
> + System.clearProperty("fs.file.impl");
> + System.clearProperty("fs.file.impl.disable.cache");
> + }
> +
> + /**
> + * Starts a fresh metastore with all required System properties already
> set so
> + * the metastore-side HiveConf picks them up at construction time.
> + *
> + * @param thresholdMs value for
> hive.metastore.authorization.fileinfo.slow.warn.threshold.ms
> + * @param slowFs if true, registers SlowLocalFileSystem as
> fs.file.impl
> + */
> + private void startMetaStore(long thresholdMs, boolean slowFs) throws
> Exception {
> +
> System.setProperty(HiveConf.ConfVars.METASTORE_PRE_EVENT_LISTENERS.varname,
> + AuthorizationPreEventListener.class.getName());
> +
> System.setProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHORIZATION_MANAGER.varname,
> + StorageBasedAuthorizationProvider.class.getName());
> +
> System.setProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHENTICATOR_MANAGER.varname,
> + InjectableDummyAuthenticator.class.getName());
> +
> System.setProperty(HiveConf.ConfVars.HIVE_METASTORE_AUTHORIZATION_AUTH_READS.varname,
> "true");
> + System.setProperty(THRESHOLD_KEY, String.valueOf(thresholdMs));
> + if (slowFs) {
> + System.setProperty("fs.file.impl",
> SlowLocalFileSystem.class.getName());
> + System.setProperty("fs.file.impl.disable.cache", "true");
> + }
> +
> + int port = MetaStoreTestUtils.startMetaStoreWithRetry();
> +
> + HiveConf clientConf = new HiveConfForTest(getClass());
> + clientConf.setVar(HiveConf.ConfVars.METASTORE_URIS,
> "thrift://localhost:" + port);
> +
> clientConf.setIntVar(HiveConf.ConfVars.METASTORE_THRIFT_CONNECTION_RETRIES,
> 3);
> + clientConf.setBoolVar(HiveConf.ConfVars.HIVE_AUTHORIZATION_ENABLED,
> false);
> +
> + msc = new HiveMetaStoreClient(clientConf);
> + InjectableDummyAuthenticator.injectMode(false);
> + }
> +
> + /**
> + * threshold=-1 (disabled): no WARN emitted after a real getDatabase()
> auth check.
> + * Fully deterministic — threshold=-1 suppresses the WARN unconditionally.
> + */
> + @Test
> + public void testNoSlowWarnWhenThresholdDisabled() throws Exception {
> + startMetaStore(-1, false);
> +
> + Database db = new Database("slow_log_disabled_db", null, null, null);
> + msc.createDatabase(db);
> + assertNotNull(msc.getDatabase("slow_log_disabled_db"));
> +
> + appender.reset();
> + InjectableDummyAuthenticator.injectMode(true);
> + try {
> + msc.getDatabase("slow_log_disabled_db");
> + } catch (Exception ignored) {
> + } finally {
> + InjectableDummyAuthenticator.injectMode(false);
> + }
> +
> + String output = appender.getOutput();
> + assertFalse(
> + "No 'Slow getFileInfo' WARN expected when threshold=-1, got: " +
> output,
> + output.contains("Slow getFileInfo"));
> +
> + msc.dropDatabase("slow_log_disabled_db");
> + }
> +
> + /**
> + * threshold=10ms + SlowLocalFileSystem (sleeps 30ms): WARN IS emitted.
> + *
> + * SlowLocalFileSystem is registered as fs.file.impl so the metastore's
> + * StorageBasedAuthorizationProvider uses it when calling
> getFileStatusOrNull().
> + * The 30ms sleep ensures elapsed(~30ms) > threshold(10ms), triggering the
> real
> + * LOG.warn inside checkPermissions() in the production code.
> + */
> + @Test
> + public void testSlowWarnEmittedWhenFileSystemIsSlow() throws Exception {
> + startMetaStore(10, true); // 10ms threshold, SlowLocalFileSystem enabled
> +
> + Database db = new Database("slow_log_slow_db", null, null, null);
> + msc.createDatabase(db);
> + assertNotNull(msc.getDatabase("slow_log_slow_db"));
> +
> + appender.reset();
> + InjectableDummyAuthenticator.injectMode(true);
> + try {
> + msc.getDatabase("slow_log_slow_db");
> + } catch (Exception ignored) {
> + } finally {
> + InjectableDummyAuthenticator.injectMode(false);
> + }
> +
> + String output = appender.getOutput();
> + assertTrue(
> + "Expected 'Slow getFileInfo' WARN when elapsed(~30ms) >
> threshold(10ms), got: " + output,
> + output.contains("Slow getFileInfo"));
> +
> + msc.dropDatabase("slow_log_slow_db");
> + }
> +}
> --
> 2.50.1 (Apple Git-155) {code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
