Examples with PerfLogger org.apache.hadoop.hive.metastore.metrics.PerfLogger used on opensource projects

Example 1 with PerfLogger

use of org.apache.hadoop.hive.metastore.metrics.PerfLogger in project hive by apache.

the class Cleaner method clean.

private void clean(CompactionInfo ci, long minOpenTxnGLB, boolean metricsEnabled) throws MetaException {
    LOG.info("Starting cleaning for " + ci);
    PerfLogger perfLogger = PerfLogger.getPerfLogger(false);
    String cleanerMetric = MetricsConstants.COMPACTION_CLEANER_CYCLE + "_" + (ci.type != null ? ci.type.toString().toLowerCase() : null);
    try {
        if (metricsEnabled) {
            perfLogger.perfLogBegin(CLASS_NAME, cleanerMetric);
        }
        Optional<String> location = Optional.ofNullable(ci.properties).map(StringableMap::new).map(config -> config.get("location"));
        Callable<Boolean> cleanUpTask;
        Table t = null;
        Partition p = resolvePartition(ci);
        if (!location.isPresent()) {
            t = resolveTable(ci);
            if (t == null) {
                // The table was dropped before we got around to cleaning it.
                LOG.info("Unable to find table " + ci.getFullTableName() + ", assuming it was dropped." + idWatermark(ci));
                txnHandler.markCleaned(ci);
                return;
            }
            if (MetaStoreUtils.isNoCleanUpSet(t.getParameters())) {
                // The table was marked no clean up true.
                LOG.info("Skipping table " + ci.getFullTableName() + " clean up, as NO_CLEANUP set to true");
                txnHandler.markCleaned(ci);
                return;
            }
            if (ci.partName != null) {
                if (p == null) {
                    // The partition was dropped before we got around to cleaning it.
                    LOG.info("Unable to find partition " + ci.getFullPartitionName() + ", assuming it was dropped." + idWatermark(ci));
                    txnHandler.markCleaned(ci);
                    return;
                }
                if (MetaStoreUtils.isNoCleanUpSet(p.getParameters())) {
                    // The partition was marked no clean up true.
                    LOG.info("Skipping partition " + ci.getFullPartitionName() + " clean up, as NO_CLEANUP set to true");
                    txnHandler.markCleaned(ci);
                    return;
                }
            }
        }
        txnHandler.markCleanerStart(ci);
        if (t != null) {
            StorageDescriptor sd = resolveStorageDescriptor(t, p);
            cleanUpTask = () -> removeFiles(location.orElse(sd.getLocation()), minOpenTxnGLB, ci, ci.partName != null && p == null);
        } else {
            cleanUpTask = () -> removeFiles(location.get(), ci);
        }
        Ref<Boolean> removedFiles = Ref.from(false);
        if (runJobAsSelf(ci.runAs)) {
            removedFiles.value = cleanUpTask.call();
        } else {
            LOG.info("Cleaning as user " + ci.runAs + " for " + ci.getFullPartitionName());
            UserGroupInformation ugi = UserGroupInformation.createProxyUser(ci.runAs, UserGroupInformation.getLoginUser());
            ugi.doAs((PrivilegedExceptionAction<Void>) () -> {
                removedFiles.value = cleanUpTask.call();
                return null;
            });
            try {
                FileSystem.closeAllForUGI(ugi);
            } catch (IOException exception) {
                LOG.error("Could not clean up file-system handles for UGI: " + ugi + " for " + ci.getFullPartitionName() + idWatermark(ci), exception);
            }
        }
        if (removedFiles.value || isDynPartAbort(t, ci)) {
            txnHandler.markCleaned(ci);
        } else {
            txnHandler.clearCleanerStart(ci);
            LOG.warn("No files were removed. Leaving queue entry " + ci + " in ready for cleaning state.");
        }
    } catch (Exception e) {
        LOG.error("Caught exception when cleaning, unable to complete cleaning of " + ci + " " + StringUtils.stringifyException(e));
        ci.errorMessage = e.getMessage();
        if (metricsEnabled) {
            Metrics.getOrCreateCounter(MetricsConstants.COMPACTION_CLEANER_FAILURE_COUNTER).inc();
        }
        txnHandler.markFailed(ci);
    } finally {
        if (metricsEnabled) {
            perfLogger.perfLogEnd(CLASS_NAME, cleanerMetric);
        }
    }
}

Example 2 with PerfLogger

use of org.apache.hadoop.hive.metastore.metrics.PerfLogger in project hive by apache.

the class Initiator method run.

@Override
public void run() {
    LOG.info("Starting Initiator thread");
    // so wrap it in a big catch Throwable statement.
    try {
        recoverFailedCompactions(false);
        int abortedThreshold = HiveConf.getIntVar(conf, HiveConf.ConfVars.HIVE_COMPACTOR_ABORTEDTXN_THRESHOLD);
        long abortedTimeThreshold = HiveConf.getTimeVar(conf, HiveConf.ConfVars.HIVE_COMPACTOR_ABORTEDTXN_TIME_THRESHOLD, TimeUnit.MILLISECONDS);
        // HiveMetaStore.
        do {
            PerfLogger perfLogger = PerfLogger.getPerfLogger(false);
            long startedAt = -1;
            long prevStart;
            TxnStore.MutexAPI.LockHandle handle = null;
            // don't doom the entire thread.
            try {
                handle = txnHandler.getMutexAPI().acquireLock(TxnStore.MUTEX_KEY.Initiator.name());
                startedAt = System.currentTimeMillis();
                prevStart = handle.getLastUpdateTime();
                long compactionInterval = (prevStart <= 0) ? prevStart : (startedAt - prevStart) / 1000;
                if (metricsEnabled) {
                    perfLogger.perfLogBegin(CLASS_NAME, MetricsConstants.COMPACTION_INITIATOR_CYCLE);
                    stopCycleUpdater();
                    startCycleUpdater(HiveConf.getTimeVar(conf, HiveConf.ConfVars.HIVE_COMPACTOR_INITIATOR_DURATION_UPDATE_INTERVAL, TimeUnit.MILLISECONDS), new InitiatorCycleUpdater(MetricsConstants.COMPACTION_INITIATOR_CYCLE_DURATION, startedAt, MetastoreConf.getTimeVar(conf, MetastoreConf.ConfVars.COMPACTOR_LONG_RUNNING_INITIATOR_THRESHOLD_WARNING, TimeUnit.MILLISECONDS), MetastoreConf.getTimeVar(conf, MetastoreConf.ConfVars.COMPACTOR_LONG_RUNNING_INITIATOR_THRESHOLD_ERROR, TimeUnit.MILLISECONDS)));
                }
                final ShowCompactResponse currentCompactions = txnHandler.showCompact(new ShowCompactRequest());
                // Currently we invalidate all entries after each cycle, because the bootstrap replication is marked via
                // table property hive.repl.first.inc.pending which would be cached.
                tableCache.ifPresent(c -> c.invalidateAll());
                Set<String> skipDBs = Sets.newConcurrentHashSet();
                Set<String> skipTables = Sets.newConcurrentHashSet();
                Set<CompactionInfo> potentials = compactionExecutor.submit(() -> txnHandler.findPotentialCompactions(abortedThreshold, abortedTimeThreshold, compactionInterval).parallelStream().filter(ci -> isEligibleForCompaction(ci, currentCompactions, skipDBs, skipTables)).collect(Collectors.toSet())).get();
                LOG.debug("Found " + potentials.size() + " potential compactions, " + "checking to see if we should compact any of them");
                Map<String, String> tblNameOwners = new HashMap<>();
                List<CompletableFuture<Void>> compactionList = new ArrayList<>();
                if (!potentials.isEmpty()) {
                    ValidTxnList validTxnList = TxnCommonUtils.createValidReadTxnList(txnHandler.getOpenTxns(), 0);
                    conf.set(ValidTxnList.VALID_TXNS_KEY, validTxnList.writeToString());
                }
                for (CompactionInfo ci : potentials) {
                    try {
                        Table t = resolveTableAndCache(ci);
                        Partition p = resolvePartition(ci);
                        if (p == null && ci.partName != null) {
                            LOG.info("Can't find partition " + ci.getFullPartitionName() + ", assuming it has been dropped and moving on.");
                            continue;
                        }
                        String runAs = resolveUserToRunAs(tblNameOwners, t, p);
                        /* checkForCompaction includes many file metadata checks and may be expensive.
               * Therefore, using a thread pool here and running checkForCompactions in parallel */
                        String tableName = ci.getFullTableName();
                        String partition = ci.getFullPartitionName();
                        CompletableFuture<Void> asyncJob = CompletableFuture.runAsync(CompactorUtil.ThrowingRunnable.unchecked(() -> scheduleCompactionIfRequired(ci, t, p, runAs, metricsEnabled)), compactionExecutor).exceptionally(exc -> {
                            LOG.error("Error while running scheduling the compaction on the table {} / partition {}.", tableName, partition, exc);
                            return null;
                        });
                        compactionList.add(asyncJob);
                    } catch (Throwable t) {
                        LOG.error("Caught exception while trying to determine if we should compact {}. " + "Marking failed to avoid repeated failures, {}", ci, t);
                        ci.errorMessage = t.getMessage();
                        txnHandler.markFailed(ci);
                    }
                }
                CompletableFuture.allOf(compactionList.toArray(new CompletableFuture[0])).join();
                // Check for timed out remote workers.
                recoverFailedCompactions(true);
            } catch (Throwable t) {
                LOG.error("Initiator loop caught unexpected exception this time through the loop: " + StringUtils.stringifyException(t));
            } finally {
                if (handle != null) {
                    handle.releaseLocks(startedAt);
                }
                if (metricsEnabled) {
                    perfLogger.perfLogEnd(CLASS_NAME, MetricsConstants.COMPACTION_INITIATOR_CYCLE);
                    updateCycleDurationMetric(MetricsConstants.COMPACTION_INITIATOR_CYCLE_DURATION, startedAt);
                }
                stopCycleUpdater();
            }
            long elapsedTime = System.currentTimeMillis() - startedAt;
            if (elapsedTime < checkInterval && !stop.get()) {
                Thread.sleep(checkInterval - elapsedTime);
            }
            LOG.info("Initiator thread finished one loop.");
        } while (!stop.get());
    } catch (Throwable t) {
        LOG.error("Caught an exception in the main loop of compactor initiator, exiting " + StringUtils.stringifyException(t));
    } finally {
        if (compactionExecutor != null) {
            this.compactionExecutor.shutdownNow();
        }
    }
}

Example 3 with PerfLogger

use of org.apache.hadoop.hive.metastore.metrics.PerfLogger in project hive by apache.

the class RetryingHMSHandler method invoke.

@Override
public Object invoke(final Object proxy, final Method method, final Object[] args) throws Throwable {
    int retryCount = -1;
    int threadId = baseHandler.getThreadId();
    boolean error = true;
    PerfLogger perfLogger = PerfLogger.getPerfLogger(false);
    perfLogger.perfLogBegin(CLASS_NAME, method.getName());
    try {
        Result result = invokeInternal(proxy, method, args);
        retryCount = result.numRetries;
        error = false;
        return result.result;
    } finally {
        StringBuilder additionalInfo = new StringBuilder();
        additionalInfo.append("threadId=").append(threadId).append(" retryCount=").append(retryCount).append(" error=").append(error);
        perfLogger.perfLogEnd(CLASS_NAME, method.getName(), additionalInfo.toString());
    }
}