Store repository and cache perf stats in tasks

This is a preliminary implementation.

Also changed default repository performance monitoring level
to LEVEL_LOCAL_STATISTICS.

infra/schema/src/main/java/com/evolveum/midpoint/schema/util/CachePerformanceInformationUtil.java

@@ -0,0 +1,76 @@
+/*
+ * Copyright (c) 2010-2019 Evolveum
+ *
+ * Licensed 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 com.evolveum.midpoint.schema.util;
+
+import com.evolveum.midpoint.util.caching.CachePerformanceCollector;
+import com.evolveum.midpoint.xml.ns._public.common.common_3.CachesPerformanceInformationType;
+import com.evolveum.midpoint.xml.ns._public.common.common_3.SingleCachePerformanceInformationType;
+import org.jetbrains.annotations.NotNull;
+
+import java.util.Map;
+import java.util.Objects;
+
+/**
+ *
+ */
+public class CachePerformanceInformationUtil {
+	public static CachesPerformanceInformationType toCachesPerformanceInformationType(
+			@NotNull Map<String, CachePerformanceCollector.CacheData> performanceMap) {
+		CachesPerformanceInformationType rv = new CachesPerformanceInformationType();
+		performanceMap.forEach((cache, info) -> rv.getCache().add(toSingleCachePerformanceInformationType(cache, info)));
+		return rv;
+
+	}
+
+	private static SingleCachePerformanceInformationType toSingleCachePerformanceInformationType(String cache,
+			CachePerformanceCollector.CacheData info) {
+		SingleCachePerformanceInformationType rv = new SingleCachePerformanceInformationType();
+		rv.setName(cache);
+		rv.setHitCount(info.hits.intValue());
+		rv.setWeakHitCount(info.weakHits.intValue());
+		rv.setMissCount(info.misses.intValue());
+		rv.setPassCount(info.passes.intValue());
+		rv.setNotAvailableCount(info.notAvailable.intValue());
+		return rv;
+	}
+
+	public static void addTo(@NotNull CachesPerformanceInformationType aggregate, @NotNull CachesPerformanceInformationType part) {
+		for (SingleCachePerformanceInformationType partCacheInfo : part.getCache()) {
+			SingleCachePerformanceInformationType matchingAggregateCacheInfo = null;
+			for (SingleCachePerformanceInformationType aggregateCacheInfo : aggregate.getCache()) {
+				if (Objects.equals(partCacheInfo.getName(), aggregateCacheInfo.getName())) {
+					matchingAggregateCacheInfo = aggregateCacheInfo;
+					break;
+				}
+			}
+			if (matchingAggregateCacheInfo != null) {
+				addTo(matchingAggregateCacheInfo, partCacheInfo);
+			} else {
+				aggregate.getCache().add(partCacheInfo.clone());
+			}
+		}
+	}
+
+	private static void addTo(@NotNull SingleCachePerformanceInformationType aggregate,
+			@NotNull SingleCachePerformanceInformationType part) {
+		aggregate.setHitCount(aggregate.getHitCount() + part.getHitCount());
+		aggregate.setWeakHitCount(aggregate.getWeakHitCount() + part.getWeakHitCount());
+		aggregate.setMissCount(aggregate.getMissCount() + part.getMissCount());
+		aggregate.setPassCount(aggregate.getPassCount() + part.getPassCount());
+		aggregate.setNotAvailableCount(aggregate.getNotAvailableCount() + part.getNotAvailableCount());
+	}
+}

infra/util/src/main/java/com/evolveum/midpoint/util/caching/CachePerformanceCollector.java

@@ -22,9 +22,9 @@
 
 import java.util.ArrayList;
 import java.util.Map;
-import java.util.OptionalInt;
 import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.atomic.AtomicInteger;
+import java.util.function.Function;
 
 /**
  * Temporary implementation.
@@ -33,13 +33,37 @@ public class CachePerformanceCollector implements DebugDumpable {
 
 	public static final CachePerformanceCollector INSTANCE = new CachePerformanceCollector();
 
+	private final Map<String, CacheData> performanceMap = new ConcurrentHashMap<>();
+
+	private final ThreadLocal<Map<String, CacheData>> threadLocalPerformanceMap = new ThreadLocal<>();
+
 	public static class CacheData implements ShortDumpable {
 		public final AtomicInteger hits = new AtomicInteger(0);
 		public final AtomicInteger weakHits = new AtomicInteger(0);             // e.g. hit but with getVersion call
 		public final AtomicInteger misses = new AtomicInteger(0);
 		public final AtomicInteger passes = new AtomicInteger(0);
 		public final AtomicInteger notAvailable = new AtomicInteger(0);
 
+		public AtomicInteger getHits() {
+			return hits;
+		}
+
+		public AtomicInteger getWeakHits() {
+			return weakHits;
+		}
+
+		public AtomicInteger getMisses() {
+			return misses;
+		}
+
+		public AtomicInteger getPasses() {
+			return passes;
+		}
+
+		public AtomicInteger getNotAvailable() {
+			return notAvailable;
+		}
+
 		public void add(AbstractCache cache) {
 			hits.addAndGet(cache.getHits());
 			misses.addAndGet(cache.getMisses());
@@ -70,40 +94,54 @@ public void shortDump(StringBuilder sb) {
 		}
 	}
 
-	private final Map<String, CacheData> performanceMap = new ConcurrentHashMap<>();
-
 	public void onCacheDestroy(AbstractCache cache) {
-		getOrCreate(cache.getClass()).add(cache);
+		getOrCreate(performanceMap, cache.getClass()).add(cache);
+		Map<String, CacheData> localMap = threadLocalPerformanceMap.get();
+		if (localMap != null) {
+			getOrCreate(localMap, cache.getClass()).add(cache);
+		}
+	}
+
+	private void increment(Class<?> cacheClass, Function<CacheData, AtomicInteger> selector) {
+		selector.apply(getOrCreate(performanceMap, cacheClass)).incrementAndGet();
+		Map<String, CacheData> localMap = threadLocalPerformanceMap.get();
+		if (localMap != null) {
+			selector.apply(getOrCreate(localMap, cacheClass)).incrementAndGet();
+		}
 	}
 
 	public void registerHit(Class<?> cacheClass) {
-		getOrCreate(cacheClass).hits.incrementAndGet();
+		increment(cacheClass, CacheData::getHits);
 	}
 
 	public void registerWeakHit(Class<?> cacheClass) {
-		getOrCreate(cacheClass).weakHits.incrementAndGet();
+		increment(cacheClass, CacheData::getWeakHits);
 	}
 
 	public void registerMiss(Class<?> cacheClass) {
-		getOrCreate(cacheClass).misses.incrementAndGet();
+		increment(cacheClass, CacheData::getMisses);
 	}
 
 	public void registerPass(Class<?> cacheClass) {
-		getOrCreate(cacheClass).passes.incrementAndGet();
+		increment(cacheClass, CacheData::getPasses);
 	}
 
 	public void registerNotAvailable(Class<?> cacheClass) {
-		getOrCreate(cacheClass).notAvailable.incrementAndGet();
+		increment(cacheClass, CacheData::getNotAvailable);
 	}
 
-	private CacheData getOrCreate(Class<?> cacheClass) {
-		CacheData existingData = performanceMap.get(cacheClass.getName());
-		if (existingData != null) {
-			return existingData;
+	private CacheData getOrCreate(Map<String, CacheData> performanceMap, Class<?> cacheClass) {
+		if (performanceMap != null) {
+			CacheData existingData = performanceMap.get(cacheClass.getName());
+			if (existingData != null) {
+				return existingData;
+			} else {
+				CacheData newData = new CacheData();
+				performanceMap.put(cacheClass.getName(), newData);
+				return newData;
+			}
 		} else {
-			CacheData newData = new CacheData();
-			performanceMap.put(cacheClass.getName(), newData);
-			return newData;
+			return null;
 		}
 	}
 
@@ -123,4 +161,26 @@ public String debugDump(int indent) {
 		}
 		return sb.toString();
 	}
+
+	public Map<String, CacheData> getGlobalPerformanceMap() {
+		return performanceMap;
+	}
+
+	public Map<String, CacheData> getThreadLocalPerformanceMap() {
+		return threadLocalPerformanceMap.get();
+	}
+
+	/**
+	 * Starts gathering thread-local performance information, clearing existing (if any).
+	 */
+	public void startThreadLocalPerformanceInformationCollection() {
+		threadLocalPerformanceMap.set(new ConcurrentHashMap<>());
+	}
+
+	/**
+	 * Stops gathering thread-local performance information, clearing existing (if any).
+	 */
+	public void stopThreadLocalPerformanceInformationCollection() {
+		threadLocalPerformanceMap.remove();
+	}
 }

repo/repo-api/src/main/java/com/evolveum/midpoint/repo/api/perf/PerformanceInformationUtil.java

@@ -0,0 +1,78 @@
+/*
+ * Copyright (c) 2010-2019 Evolveum
+ *
+ * Licensed 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 com.evolveum.midpoint.repo.api.perf;
+
+import com.evolveum.midpoint.xml.ns._public.common.common_3.RepositoryOperationPerformanceInformationType;
+import com.evolveum.midpoint.xml.ns._public.common.common_3.RepositoryPerformanceInformationType;
+import org.jetbrains.annotations.NotNull;
+
+import java.util.Objects;
+
+/**
+ *
+ */
+public class PerformanceInformationUtil {
+
+	public static void addTo(@NotNull RepositoryPerformanceInformationType aggregate, @NotNull RepositoryPerformanceInformationType part) {
+		for (RepositoryOperationPerformanceInformationType partOperation : part.getOperation()) {
+			RepositoryOperationPerformanceInformationType matchingAggregateOperation = null;
+			for (RepositoryOperationPerformanceInformationType aggregateOperation : aggregate.getOperation()) {
+				if (Objects.equals(partOperation.getName(), aggregateOperation.getName())) {
+					matchingAggregateOperation = aggregateOperation;
+					break;
+				}
+			}
+			if (matchingAggregateOperation != null) {
+				addTo(matchingAggregateOperation, partOperation);
+			} else {
+				aggregate.getOperation().add(partOperation.clone());
+			}
+		}
+	}
+
+	private static void addTo(@NotNull RepositoryOperationPerformanceInformationType aggregate,
+			@NotNull RepositoryOperationPerformanceInformationType part) {
+		aggregate.setInvocationCount(aggregate.getInvocationCount() + part.getInvocationCount());
+		aggregate.setExecutionCount(aggregate.getExecutionCount() + part.getExecutionCount());
+		aggregate.setTotalTime(aggregate.getTotalTime() + part.getTotalTime());
+		aggregate.setMinTime(min(aggregate.getMinTime(), part.getMinTime()));
+		aggregate.setMaxTime(max(aggregate.getMaxTime(), part.getMaxTime()));
+		aggregate.setTotalWastedTime(aggregate.getTotalWastedTime() + part.getTotalWastedTime());
+		aggregate.setMinWastedTime(min(aggregate.getMinWastedTime(), part.getMinWastedTime()));
+		aggregate.setMaxWastedTime(max(aggregate.getMaxWastedTime(), part.getMaxWastedTime()));
+	}
+
+	private static Long min(Long a, Long b) {
+		if (a == null) {
+			return b;
+		} else if (b == null) {
+			return a;
+		} else {
+			return Math.min(a, b);
+		}
+	}
+
+	private static Long max(Long a, Long b) {
+		if (a == null) {
+			return b;
+		} else if (b == null) {
+			return a;
+		} else {
+			return Math.max(a, b);
+		}
+	}
+}

repo/repo-common/src/main/java/com/evolveum/midpoint/repo/common/task/AbstractSearchIterativeResultHandler.java

@@ -299,13 +299,15 @@ public void run(RunningTask workerTask) {
 			workerSpecificResult.addArbitraryObjectAsContext("subtaskName", workerTask.getName());
 
 			while (workerTask.canRun()) {
+				workerTask.refreshStoredThreadLocalPerformanceStats();
 				ProcessingRequest request;
 				try {
 					request = requestQueue.poll(WORKER_THREAD_WAIT_FOR_REQUEST, TimeUnit.MILLISECONDS);
 				} catch (InterruptedException e) {
 					LOGGER.trace("Interrupted when waiting for next request", e);
 					return;
 				}
+				workerTask.refreshStoredThreadLocalPerformanceStats();
 				if (request != null) {
 					processRequest(request, workerTask, workerSpecificResult);
 				} else {

repo/repo-sql-impl/src/main/java/com/evolveum/midpoint/repo/sql/SqlRepositoryConfiguration.java

@@ -18,6 +18,7 @@
 
 import com.evolveum.midpoint.repo.api.RepositoryServiceFactoryException;
 import com.evolveum.midpoint.repo.sql.helpers.OrgClosureManager;
+import com.evolveum.midpoint.repo.sql.perf.SqlPerformanceMonitorImpl;
 import com.evolveum.midpoint.repo.sql.util.*;
 import com.evolveum.midpoint.util.MiscUtil;
 import com.evolveum.midpoint.util.exception.SystemException;
@@ -478,7 +479,7 @@ public SqlRepositoryConfiguration(Configuration configuration) {
         useReadOnlyTransactions = configuration.getBoolean(PROPERTY_USE_READ_ONLY_TRANSACTIONS, defaultUseReadOnlyTransactions);
 
         performanceStatisticsFile = configuration.getString(PROPERTY_PERFORMANCE_STATISTICS_FILE);
-        performanceStatisticsLevel = configuration.getInt(PROPERTY_PERFORMANCE_STATISTICS_LEVEL, 0);
+        performanceStatisticsLevel = configuration.getInt(PROPERTY_PERFORMANCE_STATISTICS_LEVEL, SqlPerformanceMonitorImpl.LEVEL_LOCAL_STATISTICS);
 
         computeDefaultIterativeSearchParameters();
         iterativeSearchByPaging = configuration.getBoolean(PROPERTY_ITERATIVE_SEARCH_BY_PAGING, defaultIterativeSearchByPaging);

repo/task-api/src/main/java/com/evolveum/midpoint/task/api/RunningTask.java

@@ -85,6 +85,11 @@ public interface RunningTask extends Task {
 
 	void storeOperationStatsDeferred();
 
+	/**
+	 * Call from the thread that executes the task ONLY! Otherwise wrong data might be recorded.
+	 */
+	void refreshStoredThreadLocalPerformanceStats();
+
 	void storeOperationStats();
 
 	// stores operation statistics if the time has come