RAM cache stats and logs updates

doc/admin-guide/monitoring/statistics/core/cache-volume.en.rst

@@ -125,9 +125,28 @@ a configuration with only one cache volume: :literal:`0`.
 .. ts:stat:: global proxy.process.cache.volume_0.ram_cache.hits integer
    :type: counter
 
+   Accumulates the number of hits to the LRU RAM cache for this volume.
+
 .. ts:stat:: global proxy.process.cache.volume_0.ram_cache.misses integer
    :type: counter
 
+   Accumulates the number of misses to the LRU RAM cache for this volume.  Note that this count includes hits to the other memory caches, including the last open read and aggregation buffer caches, so it may not represent the total number of cache accesses that go to disk.
+
+.. ts:stat:: global proxy.process.cache.volume_0.last_open_read.hits integer
+   :type: counter
+
+   Accumulates the number of hits to the last open read cache for this volume.  This cache stores the most recent read operation for each open cache volume.
+
+.. ts:stat:: global proxy.process.cache.volume_0.aggregation_buffer.hits integer
+   :type: counter
+
+   Accumulates the number of hits to the aggregation buffer for this volume.  This buffer stores data fragments that are on their way to be written to disk for write aggregation.
+
+.. ts:stat:: global proxy.process.cache.volume_0.all_memory_caches.misses integer
+   :type: counter
+
+   Accumulates the number of misses to all memory caches (LRU RAM cache, last open read cache, and aggregation buffer) for this volume.  This represents the total number of cache accesses that go to disk for this volume.
+
 .. ts:stat:: global proxy.process.cache.volume_0.ram_cache.total_bytes integer
    :type: gauge
    :units: bytes

doc/admin-guide/monitoring/statistics/core/cache.en.rst

@@ -86,7 +86,30 @@ Cache
 
 .. ts:stat:: global proxy.process.cache.ram_cache.bytes_used integer
 .. ts:stat:: global proxy.process.cache.ram_cache.hits integer
+   :type: counter
+
+   Accumulates the number of hits to the LRU RAM cache for all volumes.
+
 .. ts:stat:: global proxy.process.cache.ram_cache.misses integer
+   :type: counter
+
+   Accumulates the number of misses to the LRU RAM cache for all volumes.  Note that this includes hits to the other memory caches, including the last open read and aggregation buffer caches, so it may not represent the total number of cache accesses that go to disk.
+
+.. ts:stat:: global proxy.process.cache.last_open_read.hits integer
+   :type: counter
+
+   Accumulates the number of hits to the last open read cache for all volumes.  This cache stores the most recent read operation for each open cache volume.
+
+.. ts:stat:: global proxy.process.cache.aggregation_buffer.hits integer
+   :type: counter
+
+   Accumulates the number of hits to the aggregation buffer for all volumes.  This buffer stores data fragments that are on their way to be written to disk for write aggregation.
+
+.. ts:stat:: global proxy.process.cache.all_memory_caches.misses integer
+   :type: counter
+
+   Accumulates the number of misses to all memory caches (LRU RAM cache, last open read cache, and aggregation buffer) for all volumes.  This represents the total number of cache accesses that go to disk.
+
 .. ts:stat:: global proxy.process.cache.ram_cache.total_bytes integer
 .. ts:stat:: global proxy.process.cache.read.active integer
 .. ts:stat:: global proxy.process.cache.read_busy.failure integer

src/iocore/cache/CacheProcessor.cc

@@ -1126,7 +1126,10 @@ register_cache_stats(CacheStatsBlock *rsb, const std::string &prefix)
   rsb->ram_cache_bytes_total = ts::Metrics::Gauge::createPtr(prefix + ".ram_cache.total_bytes");
   rsb->ram_cache_bytes       = ts::Metrics::Gauge::createPtr(prefix + ".ram_cache.bytes_used");
   rsb->ram_cache_hits        = ts::Metrics::Counter::createPtr(prefix + ".ram_cache.hits");
+  rsb->last_open_read_hits   = ts::Metrics::Counter::createPtr(prefix + ".last_open_read.hits");
+  rsb->agg_buffer_hits       = ts::Metrics::Counter::createPtr(prefix + ".aggregation_buffer.hits");
   rsb->ram_cache_misses      = ts::Metrics::Counter::createPtr(prefix + ".ram_cache.misses");
+  rsb->all_mem_misses        = ts::Metrics::Counter::createPtr(prefix + ".all_memory_caches.misses");
   rsb->pread_count           = ts::Metrics::Counter::createPtr(prefix + ".pread_count");
   rsb->percent_full          = ts::Metrics::Gauge::createPtr(prefix + ".percent_full");
   rsb->read_seek_fail        = ts::Metrics::Counter::createPtr(prefix + ".read.seek.failure");

src/iocore/cache/CacheVC.cc

@@ -459,11 +459,15 @@ CacheVC::handleRead(int /* event ATS_UNUSED */, Event * /* e ATS_UNUSED */)
   } else if (load_from_last_open_read_call()) {
     goto LmemHit;
   } else if (load_from_aggregation_buffer()) {
-    io.aio_result = io.aiocb.aio_nbytes;
+    f.doc_from_ram_cache = true;
+    io.aio_result        = io.aiocb.aio_nbytes;
     SET_HANDLER(&CacheVC::handleReadDone);
     return EVENT_RETURN;
   }
 
+  ts::Metrics::Counter::increment(cache_rsb.all_mem_misses);
+  ts::Metrics::Counter::increment(stripe->cache_vol->vol_rsb.all_mem_misses);
+
   io.aiocb.aio_fildes = stripe->fd;
   io.aiocb.aio_offset = stripe->vol_offset(&dir);
   if (static_cast<off_t>(io.aiocb.aio_offset + io.aiocb.aio_nbytes) > static_cast<off_t>(stripe->skip + stripe->len)) {
@@ -514,6 +518,8 @@ CacheVC::load_from_last_open_read_call()
 {
   if (*this->read_key == this->stripe->first_fragment_key && dir_offset(&this->dir) == this->stripe->first_fragment_offset) {
     this->buf = this->stripe->first_fragment_data;
+    ts::Metrics::Counter::increment(cache_rsb.last_open_read_hits);
+    ts::Metrics::Counter::increment(stripe->cache_vol->vol_rsb.last_open_read_hits);
     return true;
   }
   return false;
@@ -531,6 +537,8 @@ CacheVC::load_from_aggregation_buffer()
   [[maybe_unused]] bool success = this->stripe->copy_from_aggregate_write_buffer(doc, dir, this->io.aiocb.aio_nbytes);
   // We already confirmed that the copy was valid, so it should not fail.
   ink_assert(success);
+  ts::Metrics::Counter::increment(cache_rsb.agg_buffer_hits);
+  ts::Metrics::Counter::increment(stripe->cache_vol->vol_rsb.agg_buffer_hits);
   return true;
 }
 

src/iocore/cache/P_CacheStats.h

@@ -45,7 +45,10 @@ struct CacheStatsBlock {
   ts::Metrics::Gauge::AtomicType   *direntries_total      = nullptr;
   ts::Metrics::Gauge::AtomicType   *direntries_used       = nullptr;
   ts::Metrics::Counter::AtomicType *ram_cache_hits        = nullptr;
+  ts::Metrics::Counter::AtomicType *last_open_read_hits   = nullptr;
+  ts::Metrics::Counter::AtomicType *agg_buffer_hits       = nullptr;
   ts::Metrics::Counter::AtomicType *ram_cache_misses      = nullptr;
+  ts::Metrics::Counter::AtomicType *all_mem_misses        = nullptr;
   ts::Metrics::Counter::AtomicType *pread_count           = nullptr;
   ts::Metrics::Gauge::AtomicType   *percent_full          = nullptr;
   ts::Metrics::Counter::AtomicType *read_seek_fail        = nullptr;

tests/gold_tests/headers/gold/accept_webp_cache.gold

@@ -11,6 +11,6 @@
 < Date: ``
 < Age: ``
 < Connection: keep-alive
-< Via: http/1.1 `` (ApacheTrafficServer/`` [uScHs f p eN:t cCHp s ])
+< Via: http/1.1 `` (ApacheTrafficServer/`` [uScRs f p eN:t cCHp s ])
 < Server: ATS/``
 ``

tests/gold_tests/pluginTest/prefetch/prefetch_cmcd0.gold

@@ -1,9 +1,9 @@
 /tests/request.txt 200 TCP_MISS FIN 33 -
-/tests/request.txt 200 TCP_HIT - 33 -
+/tests/request.txt 200 ``_HIT - 33 -
 /tests/prefetch.txt 200 TCP_MISS - 16 tests/request.txt
 /tests/prefetch.txt 200 TCP_MISS FIN 34 -
 /tests/request.txt 200 ``_HIT - 33 -
-/tests/prefetch.txt 208 TCP_HIT - 20 tests/request.txt
+/tests/prefetch.txt 208 ``_HIT - 20 tests/request.txt
 /tests/prefetch.txt 200 ``_HIT - 34 -
 /tests/query?this=foo&that 200 TCP_MISS FIN 41 -
 /tests/query?bar=baz 200 TCP_MISS - 16 tests/query

tests/gold_tests/pluginTest/prefetch/prefetch_cmcd1.gold

@@ -1,11 +1,11 @@
 /tests/request.txt 200 TCP_MISS FIN 33 -
 /tests/prefetch.txt 200 TCP_MISS - 16 tests/request.txt
 /tests/prefetch.txt 200 TCP_MISS FIN 34 -
-/tests/prefetch.txt 200 TCP_HIT - 34 -
+/tests/prefetch.txt 200 TCP_``HIT - 34 -
 /tests/query?this=foo&that 200 TCP_MISS FIN 41 -
 /tests/query?bar=baz 200 TCP_MISS - 16 tests/query
 /tests/query?bar=baz 200 TCP_MISS FIN 35 -
-/tests/query?bar=baz 200 TCP_HIT - 35 -
+/tests/query?bar=baz 200 TCP_``HIT - 35 -
 /root.txt 200 TCP_MISS FIN 30 -
 /rooted 200 TCP_MISS - 16 root.txt
 /rooted 200 TCP_MISS FIN 28 -

tests/gold_tests/pluginTest/slice/gold/slice_crr_ident.gold

@@ -2,12 +2,12 @@ cpuup=/plain sssc=200 pssc=206 phr=DIRECT range=::bytes=0-2:: x-crr-ident=::-::
 cpuup=/plain sssc=200 pssc=206 phr=DIRECT range=::bytes=3-5:: x-crr-ident=::Etag "plain":: uid=::plain 1:: crc=TCP_MISS
 cpuup=/plain sssc=200 pssc=200 phr=DIRECT range=::-:: x-crr-ident=::-:: uid=::plain:: crc=TCP_MISS
 cpuup=/plain sssc=200 pssc=206 phr=DIRECT range=::bytes=0-2:: x-crr-ident=::-:: uid=::plain 0:: crc=TCP_REFRESH_MISS
-cpuup=/plain sssc=000 pssc=206 phr=NONE range=::bytes=3-5:: x-crr-ident=::Etag "plain":: uid=::-:: crc=TCP_HIT
+cpuup=/plain sssc=000 pssc=206 phr=NONE range=::bytes=3-5:: x-crr-ident=::Etag "plain":: uid=::-:: crc=TCP_MEM_HIT
 cpuup=/plain sssc=200 pssc=200 phr=DIRECT range=::-:: x-crr-ident=::-:: uid=::plain:: crc=TCP_MISS
 cpuup=/plain sssc=200 pssc=206 phr=DIRECT range=::bytes=0-2:: x-crr-ident=::-:: uid=::chg 0:: crc=TCP_REFRESH_MISS
 cpuup=/plain sssc=200 pssc=206 phr=DIRECT range=::bytes=3-5:: x-crr-ident=::Etag "chg":: uid=::chg 1:: crc=TCP_REFRESH_MISS
 cpuup=/plain sssc=200 pssc=200 phr=DIRECT range=::-:: x-crr-ident=::-:: uid=::chg:: crc=TCP_MISS
-cpuup=/plain sssc=000 pssc=206 phr=NONE range=::bytes=0-2:: x-crr-ident=::-:: uid=::-:: crc=TCP_HIT
-cpuup=/plain sssc=000 pssc=206 phr=NONE range=::bytes=3-5:: x-crr-ident=::Etag "chg":: uid=::-:: crc=TCP_HIT
+cpuup=/plain sssc=000 pssc=206 phr=NONE range=::bytes=0-2:: x-crr-ident=::-:: uid=::-:: crc=TCP_MEM_HIT
+cpuup=/plain sssc=000 pssc=206 phr=NONE range=::bytes=3-5:: x-crr-ident=::Etag "chg":: uid=::-:: crc=TCP_MEM_HIT
 cpuup=/plain sssc=200 pssc=200 phr=DIRECT range=::-:: x-crr-ident=::-:: uid=::chg:: crc=TCP_MISS
 cpuup=/404.txt sssc=404 pssc=404 phr=DIRECT range=::-:: x-crr-ident=::-:: uid=::-:: crc=TCP_MISS