remove timing changes

Author: szybia

modules/ingest-geoip/src/main/java/org/elasticsearch/ingest/geoip/GeoIpCache.java

@@ -62,24 +62,27 @@ public String toString() {
 
     @SuppressWarnings("unchecked")
     <RESPONSE> RESPONSE putIfAbsent(ProjectId projectId, String ip, String databasePath, Function<String, RESPONSE> retrieveFunction) {
-        long cacheStart = relativeNanoTimeProvider.getAsLong();
         // can't use cache.computeIfAbsent due to the elevated permissions for the jackson (run via the cache loader)
         CacheKey cacheKey = new CacheKey(projectId, ip, databasePath);
+        long cacheStart = relativeNanoTimeProvider.getAsLong();
         // intentionally non-locking for simplicity...it's OK if we re-put the same key/value in the cache during a race condition.
         Object response = cache.get(cacheKey);
+        long cacheRequestTime = relativeNanoTimeProvider.getAsLong() - cacheStart;
 
         // populate the cache for this key, if necessary
         if (response == null) {
+            long retrieveStart = relativeNanoTimeProvider.getAsLong();
             response = retrieveFunction.apply(ip);
             // if the response from the database was null, then use the no-result sentinel value
             if (response == null) {
                 response = NO_RESULT;
             }
             // store the result or no-result in the cache
             cache.put(cacheKey, response);
-            missesTimeInNanos.add(relativeNanoTimeProvider.getAsLong() - cacheStart);
+            long databaseRequestAndCachePutTime = relativeNanoTimeProvider.getAsLong() - retrieveStart;
+            missesTimeInNanos.add(cacheRequestTime + databaseRequestAndCachePutTime);
         } else {
-            hitsTimeInNanos.add(relativeNanoTimeProvider.getAsLong() - cacheStart);
+            hitsTimeInNanos.add(cacheRequestTime);
         }
 
         if (response == NO_RESULT) {

modules/ingest-geoip/src/test/java/org/elasticsearch/ingest/geoip/GeoIpCacheTests.java

@@ -133,8 +133,8 @@ public void testGetCacheStats() {
         assertThat(cacheStats.evictions(), equalTo(2L));
         // There are 3 hits, each taking 1ms:
         assertThat(cacheStats.hitsTimeInMillis(), equalTo(3L));
-        // There are 4 misses. each taking 1ms:
-        assertThat(cacheStats.missesTimeInMillis(), equalTo(4L));
+        // There are 4 misses. Each is made up of a cache query, and a database query, each being 1ms:
+        assertThat(cacheStats.missesTimeInMillis(), equalTo(8L));
     }
 
     public void testPurgeCacheEntriesForDatabase() {

x-pack/plugin/enrich/src/main/java/org/elasticsearch/xpack/enrich/EnrichCache.java

@@ -103,15 +103,18 @@ public void computeIfAbsent(
         long cacheStart = relativeNanoTimeProvider.getAsLong();
         var cacheKey = new CacheKey(projectId, enrichIndex, lookupValue, maxMatches);
         List<Map<?, ?>> response = get(cacheKey);
+        long cacheRequestTime = relativeNanoTimeProvider.getAsLong() - cacheStart;
         if (response != null) {
-            hitsTimeInNanos.add(relativeNanoTimeProvider.getAsLong() - cacheStart);
+            hitsTimeInNanos.add(cacheRequestTime);
             listener.onResponse(response);
         } else {
+            final long retrieveStart = relativeNanoTimeProvider.getAsLong();
             searchResponseFetcher.accept(ActionListener.wrap(resp -> {
                 CacheValue cacheValue = toCacheValue(resp);
                 put(cacheKey, cacheValue);
                 List<Map<?, ?>> copy = deepCopy(cacheValue.hits, false);
-                missesTimeInNanos.add(relativeNanoTimeProvider.getAsLong() - cacheStart);
+                long databaseQueryAndCachePutTime = relativeNanoTimeProvider.getAsLong() - retrieveStart;
+                missesTimeInNanos.add(cacheRequestTime + databaseQueryAndCachePutTime);
                 listener.onResponse(copy);
             }, listener::onFailure));
         }

x-pack/plugin/enrich/src/test/java/org/elasticsearch/xpack/enrich/EnrichCacheTests.java

@@ -140,7 +140,7 @@ public void testComputeIfAbsent() throws InterruptedException {
             assertThat(cacheStats.misses(), equalTo(++expectedMisses));
             assertThat(cacheStats.evictions(), equalTo(0L));
             assertThat(cacheStats.hitsTimeInMillis(), equalTo(0L));
-            assertThat(cacheStats.missesTimeInMillis(), equalTo(1L));
+            assertThat(cacheStats.missesTimeInMillis(), equalTo(2L)); // cache query and enrich query + cache put
         }
 
         {
@@ -156,7 +156,7 @@ public void testComputeIfAbsent() throws InterruptedException {
             assertThat(cacheStats.misses(), equalTo(expectedMisses));
             assertThat(cacheStats.evictions(), equalTo(0L));
             assertThat(cacheStats.hitsTimeInMillis(), equalTo(1L));
-            assertThat(cacheStats.missesTimeInMillis(), equalTo(1L));
+            assertThat(cacheStats.missesTimeInMillis(), equalTo(2L));
         }
 
         {