dengzhhu653 commented on code in PR #6464: URL: https://github.com/apache/hive/pull/6464#discussion_r3592510515
########## standalone-metastore/metastore-server/src/main/java/org/apache/hadoop/hive/metastore/datasource/MetastoreStatement.java: ########## @@ -0,0 +1,261 @@ +/* + * 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.metastore.datasource; + +import com.codahale.metrics.Counter; +import com.codahale.metrics.Timer; + +import java.lang.reflect.InvocationHandler; +import java.lang.reflect.InvocationTargetException; +import java.lang.reflect.Method; +import java.lang.reflect.Proxy; +import java.lang.reflect.UndeclaredThrowableException; +import java.sql.Statement; +import java.util.Arrays; +import java.util.HashSet; +import java.util.Objects; +import java.util.Optional; +import java.util.Set; +import java.util.concurrent.TimeUnit; + +import org.apache.commons.lang3.ClassUtils; +import org.apache.commons.lang3.StringUtils; +import org.apache.hadoop.conf.Configuration; +import org.apache.hadoop.hive.metastore.HMSHandlerContext; +import org.apache.hadoop.hive.metastore.api.MetaException; +import org.apache.hadoop.hive.metastore.conf.MetastoreConf; +import org.apache.hadoop.hive.metastore.metrics.Metrics; +import org.apache.hadoop.hive.metastore.metrics.MetricsConstants; +import org.apache.hadoop.hive.metastore.utils.JavaUtils; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +@SuppressWarnings("unchecked") +public final class MetastoreStatement implements InvocationHandler { + private static final Logger LOG = LoggerFactory.getLogger(MetastoreStatement.class); + private static final ThreadLocal<HMSHandlerContext.CallCtx> CALL_CTX = new ThreadLocal<>(); + static final String EXEC_HOOK = "metastore.jdbc.execution.hook"; + + private final String rawSql; + private final Statement delegate; + private final Configuration configuration; + private final MetastoreStatementHook hook; + + private MetastoreStatement(Configuration conf, Statement statement, String rawSql) { + this.configuration = Objects.requireNonNull(conf); + this.rawSql = rawSql; + this.delegate = Objects.requireNonNull(statement); + this.hook = resolveHook(conf); + } + + private MetastoreStatementHook resolveHook(Configuration conf) { + String className = conf.get(EXEC_HOOK, ""); + if (StringUtils.isEmpty(className)) { + return new JdbcProfilerUtils(configuration); + } + try { + return JavaUtils.newInstance(JavaUtils.getClass(className.trim(), MetastoreStatementHook.class), + new Class[] {Configuration.class}, new Object[] {conf}); + } catch (MetaException e) { + throw new RuntimeException(e.getMessage(), e); + } + } + + public static <T extends Statement> T getProxyStatement(Configuration configuration, T delegate, String rawSql) { + MetastoreStatement handler = new MetastoreStatement(configuration, delegate, rawSql); + return (T) Proxy.newProxyInstance(JavaUtils.getClassLoader(), + ClassUtils.getAllInterfaces(delegate.getClass()).toArray(new Class[0]), handler); + } + + private void logSummary(boolean monitor) { + Optional<HMSHandlerContext.CallCtx> currentCall = HMSHandlerContext.getCallCtx(); + HMSHandlerContext.CallCtx previousCall = CALL_CTX.get(); + if (currentCall.isEmpty()) { + if (previousCall != null) { + logSummary(previousCall); + CALL_CTX.remove(); + } + return; + } + if (previousCall == null) { + if (monitor) { + CALL_CTX.set(currentCall.get()); + } + return; + } + if (!currentCall.get().equals(previousCall)) { + logSummary(previousCall); + if (monitor) { + CALL_CTX.set(currentCall.get()); + } else { + CALL_CTX.remove(); + } + } + } + + private void logSummary(HMSHandlerContext.CallCtx call) { + long totalSpent = call.totalTime().get(); + LOG.debug("{} took {} ms to complete all queries", call.methodName(), totalSpent); + if (isSlowExecution(configuration, totalSpent)) { + LOG.warn("{} took {} ms to complete all queries", call.methodName(), totalSpent); Review Comment: > whether the latency comes from JDBC or HDFS, which is indeed a pain point. Yeah, this is `totalSpent` trying to reveal. > In this HMSHandler level, timing the total JDBC or HDFS calls of each thrift call In HMSHandler, even though we have clear boundaries for the call, but we don't know the real time spent per jdbc query, and how many queries will be sent to satisfy the request, until the caller reaches to `MetastoreStatement`, and HMSHandler tells the boundary to `MetastoreStatement`, so it's difficult to time the total jdbc spent in HMSHandler level, or do you have any ideas? -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
