WIP. Fix concurrent start timings.

modules/core/src/main/java/org/apache/ignite/internal/processors/cache/GridCacheContext.java

@@ -289,6 +289,9 @@ public class GridCacheContext<K, V> implements Externalizable {
     /** Last remove all job future. */
     private AtomicReference<IgniteInternalFuture<Boolean>> lastRmvAllJobFut = new AtomicReference<>();
 
+    /** Start time. */
+    private volatile long startTime;
+
     /**
      * Empty constructor required for {@link Externalizable}.
      */
@@ -531,6 +534,8 @@ public boolean started() {
      *
      */
     public void onStarted() {
+        startTime = U.currentTimeMillis();
+
         startLatch.countDown();
     }
 
@@ -2357,6 +2362,11 @@ public AtomicReference<IgniteInternalFuture<Boolean>> lastRemoveAllJobFut() {
         return lastRmvAllJobFut;
     }
 
+    /** @return Start time. */
+    public long startTime() {
+        return startTime;
+    }
+
     /** {@inheritDoc} */
     @Override public void writeExternal(ObjectOutput out) throws IOException {
         U.writeString(out, igniteInstanceName());

modules/core/src/main/java/org/apache/ignite/internal/processors/cache/query/GridCacheDistributedQueryManager.java

@@ -201,7 +201,9 @@ protected void removeQueryFuture(long reqId) {
         assert req.mvccSnapshot() != null || !cctx.mvccEnabled() || req.cancel() ||
             (req.type() == null && !req.fields()) : req; // Last assertion means next page request.
 
-        if (cctx.kernalContext().metric().profilingEnabled())
+        boolean profilingEnabled = cctx.kernalContext().metric().profilingEnabled();
+
+        if (profilingEnabled)
             IoStatisticsQueryHelper.startGatheringQueryStatistics();
 
         try {
@@ -255,7 +257,7 @@ protected void removeQueryFuture(long reqId) {
                 }
             }
         } finally {
-            if (cctx.kernalContext().metric().profilingEnabled()) {
+            if (profilingEnabled) {
                 IoStatisticsHolderQuery stat = IoStatisticsQueryHelper.finishGatheringQueryStatistics();
 
                 if (stat.logicalReads() > 0 || stat.physicalReads() > 0) {
@@ -615,8 +617,10 @@ else if (!cancelled.contains(res.requestId()))
         assert qry.type() == GridCacheQueryType.SCAN : qry;
         assert qry.mvccSnapshot() != null || !cctx.mvccEnabled();
 
-        long startTime = cctx.kernalContext().metric().profilingEnabled() ? System.currentTimeMillis() : 0;
-        long startTimeNanos = cctx.kernalContext().metric().profilingEnabled() ? System.nanoTime() : 0;
+        boolean profilingEnabled = cctx.kernalContext().metric().profilingEnabled();
+
+        long startTime = profilingEnabled ? System.currentTimeMillis() : 0;
+        long startTimeNanos = profilingEnabled ? System.nanoTime() : 0;
 
         GridCloseableIterator locIter0 = null;
 
@@ -691,7 +695,7 @@ private Object convert(Object obj) {
                 if (fut != null)
                     fut.cancel();
 
-                if (cctx.kernalContext().metric().profilingEnabled()) {
+                if (profilingEnabled) {
                     cctx.kernalContext().metric().profiling().query(
                         SCAN,
                         cctx.name(),

modules/core/src/main/java/org/apache/ignite/internal/processors/cache/transactions/IgniteTxManager.java

@@ -2984,7 +2984,7 @@ private void broadcastToNodesSupportingFeature(IgniteRunnable job, IgniteFeature
      * @param commit {@code True} if transaction commited.
      */
     private void profile(IgniteInternalTx tx, boolean commit) {
-        if (!cctx.kernalContext().metric().profilingEnabled())
+        if (!cctx.kernalContext().metric().profilingEnabled() || tx.startTimeNanos() == 0)
             return;
 
         cctx.kernalContext().metric().profiling().transaction(

modules/core/src/main/java/org/apache/ignite/internal/processors/query/RunningQueryManager.java

@@ -198,7 +198,7 @@ public void unregister(Long qryId, @Nullable Throwable failReason) {
             }
         }
 
-        if (ctx.metric().profilingEnabled()) {
+        if (ctx.metric().profilingEnabled() && qry.startTimeNanos() > 0) {
             ctx.metric().profiling().query(
                 qry.queryType(),
                 qry.query(),

modules/core/src/main/java/org/apache/ignite/internal/profiling/LogFileProfiling.java

@@ -31,6 +31,7 @@
 import org.apache.ignite.internal.IgniteInternalFuture;
 import org.apache.ignite.internal.IgniteInterruptedCheckedException;
 import org.apache.ignite.internal.IgniteVersionUtils;
+import org.apache.ignite.internal.processors.cache.GridCacheContext;
 import org.apache.ignite.internal.processors.cache.persistence.file.FileIO;
 import org.apache.ignite.internal.processors.cache.persistence.file.FileIOFactory;
 import org.apache.ignite.internal.processors.cache.persistence.file.RandomAccessFileIOFactory;
@@ -152,6 +153,9 @@ public synchronized void startProfiling(long maxFileSize, int bufferSize, int fl
         }
 
         profilingStart(ctx.localNodeId(), ctx.igniteInstanceName(), IgniteVersionUtils.VER_STR, U.currentTimeMillis());
+
+        for (GridCacheContext cctx : ctx.cache().context().cacheContexts())
+            cacheStart(cctx.cacheId(), cctx.startTime(), cctx.name(), cctx.config().getGroupName(), cctx.userCache());
     }
 
     /** Stops profiling. */

modules/indexing/src/main/java/org/apache/ignite/internal/processors/query/h2/twostep/GridMapQueryExecutor.java

@@ -301,7 +301,9 @@ private void onQueryRequest0(
         @Nullable final MvccSnapshot mvccSnapshot,
         Boolean dataPageScanEnabled
     ) {
-        if (ctx.metric().profilingEnabled())
+        boolean profilingEnabled = ctx.metric().profilingEnabled();
+
+        if (profilingEnabled)
             IoStatisticsQueryHelper.startGatheringQueryStatistics();
 
         // Prepare to run queries.
@@ -527,7 +529,7 @@ private void onQueryRequest0(
             if (reserved != null)
                 reserved.release();
 
-            if (ctx.metric().profilingEnabled()) {
+            if (profilingEnabled) {
                 IoStatisticsHolderQuery stat = IoStatisticsQueryHelper.finishGatheringQueryStatistics();
 
                 if (stat.logicalReads() > 0 || stat.physicalReads() > 0) {

modules/profiling/src/main/java/org/apache/ignite/internal/profiling/ProfilingFilesParser.java

@@ -359,6 +359,8 @@ public static void jsonToJsVar(String fileName, String varName) throws IOExcepti
     private static void copyReportSources(String resDir) throws Exception {
         try (InputStream in = ProfilingFilesParser.class.getClassLoader().getResourceAsStream(REPORT_RESOURCE_NAME)) {
             if (in == null) {
+                U.delete(new File(resDir));
+
                 throw new RuntimeException("Run from IDE require custom maven assembly (try to package " +
                     "'ignite-profiling' module). The report sources will not be copied to the result directory.");
             }

modules/profiling/src/main/java/org/apache/ignite/internal/profiling/handlers/TopologyInfoHandler.java

@@ -46,7 +46,7 @@ public class TopologyInfoHandler implements IgniteProfilingHandler {
 
     /** */
     public TopologyInfoHandler() {
-        res.put("profilingStartTime", 0);
+        res.put("profilingStartTime", Long.MAX_VALUE);
         res.set("nodesInfo", nodesInfo);
     }