Add store & cache download statistics (#7982)

docs/sources/upgrading/_index.md

@@ -80,6 +80,20 @@ If you are not using Query Scheduler, then to avoid any issues on the Read path
 * Rollout changes to `queriers`.
 * Roll out the rest of the changes.
 
+### General
+
+#### Store & Cache Statistics
+
+Statistics are now logged in `metrics.go` lines about how long it takes to download chunks from the store, as well as how long it takes to download chunks, index query, and result cache responses from cache.
+
+Example (note the `*_download_time` fields):
+
+```
+level=info ts=2022-12-20T15:27:54.858554127Z caller=metrics.go:147 component=frontend org_id=docker latency=fast query="sum(count_over_time({job=\"generated-logs\"}[1h]))" query_type=metric range_type=range length=6h17m48.865587821s start_delta=6h17m54.858533178s end_delta=5.99294552s step=1m30s duration=5.990829396s status=200 limit=30 returned_lines=0 throughput=123MB total_bytes=738MB total_entries=1 store_chunks_download_time=2.319297059s queue_time=2m21.476090991s subqueries=8 cache_chunk_req=81143 cache_chunk_hit=32390 cache_chunk_bytes_stored=1874098 cache_chunk_bytes_fetched=94289610 cache_chunk_download_time=56.96914ms cache_index_req=994 cache_index_hit=710 cache_index_download_time=1.587842ms cache_result_req=7 cache_result_hit=0 cache_result_download_time=380.555µs
+```
+
+These statistics are also displayed when using `--stats` with LogCLI.
+
 ## 2.7.0
 
 ### Loki

pkg/logql/metrics.go

@@ -126,16 +126,20 @@ func RecordRangeAndInstantQueryMetrics(
 		"throughput", strings.Replace(humanize.Bytes(uint64(stats.Summary.BytesProcessedPerSecond)), " ", "", 1),
 		"total_bytes", strings.Replace(humanize.Bytes(uint64(stats.Summary.TotalBytesProcessed)), " ", "", 1),
 		"total_entries", stats.Summary.TotalEntriesReturned,
+		"store_chunks_download_time", stats.ChunksDownloadTime(),
 		"queue_time", logql_stats.ConvertSecondsToNanoseconds(stats.Summary.QueueTime),
 		"subqueries", stats.Summary.Subqueries,
 		"cache_chunk_req", stats.Caches.Chunk.EntriesRequested,
 		"cache_chunk_hit", stats.Caches.Chunk.EntriesFound,
 		"cache_chunk_bytes_stored", stats.Caches.Chunk.BytesSent,
 		"cache_chunk_bytes_fetched", stats.Caches.Chunk.BytesReceived,
+		"cache_chunk_download_time", stats.Caches.Chunk.CacheDownloadTime(),
 		"cache_index_req", stats.Caches.Index.EntriesRequested,
 		"cache_index_hit", stats.Caches.Index.EntriesFound,
+		"cache_index_download_time", stats.Caches.Index.CacheDownloadTime(),
 		"cache_result_req", stats.Caches.Result.EntriesRequested,
 		"cache_result_hit", stats.Caches.Result.EntriesFound,
+		"cache_result_download_time", stats.Caches.Result.CacheDownloadTime(),
 	}...)
 
 	logValues = append(logValues, tagsToKeyValues(queryTags)...)

pkg/logql/metrics_test.go

@@ -85,7 +85,7 @@ func TestLogSlowQuery(t *testing.T) {
 	}, logqlmodel.Streams{logproto.Stream{Entries: make([]logproto.Entry, 10)}})
 	require.Regexp(t,
 		regexp.MustCompile(fmt.Sprintf(
-			`level=info org_id=foo traceID=%s latency=slow query=".*" query_type=filter range_type=range length=1h0m0s start_delta=.* end_delta=.* step=1m0s duration=25.25s status=200 limit=1000 returned_lines=10 throughput=100kB total_bytes=100kB total_entries=10 queue_time=2ns subqueries=0 cache_chunk_req=0 cache_chunk_hit=0 cache_chunk_bytes_stored=0 cache_chunk_bytes_fetched=0 cache_index_req=0 cache_index_hit=0 cache_result_req=0 cache_result_hit=0 source=logvolhist feature=beta\n`,
+			`level=info org_id=foo traceID=%s latency=slow query=".*" query_type=filter range_type=range length=1h0m0s .*\n`,
 			sp.Context().(jaeger.SpanContext).SpanID().String(),
 		)),
 		buf.String())

pkg/logqlmodel/stats/context.go

@@ -201,6 +201,11 @@ func (c *Cache) Merge(m Cache) {
 	c.Requests += m.Requests
 	c.BytesSent += m.BytesSent
 	c.BytesReceived += m.BytesReceived
+	c.DownloadTime += m.DownloadTime
+}
+
+func (c *Cache) CacheDownloadTime() time.Duration {
+	return time.Duration(c.DownloadTime)
 }
 
 // Merge merges two results of statistics.
@@ -347,6 +352,16 @@ func (c *Context) AddCacheBytesSent(t CacheType, i int) {
 	atomic.AddInt64(&stats.BytesSent, int64(i))
 }
 
+// AddCacheDownloadTime measures the time to download the data from cache
+func (c *Context) AddCacheDownloadTime(t CacheType, i time.Duration) {
+	stats := c.getCacheStatsByType(t)
+	if stats == nil {
+		return
+	}
+
+	atomic.AddInt64(&stats.DownloadTime, int64(i))
+}
+
 // AddCacheRequest counts the number of fetch/store requests to the cache
 func (c *Context) AddCacheRequest(t CacheType, i int) {
 	stats := c.getCacheStatsByType(t)
@@ -422,17 +437,20 @@ func (c Caches) Log(log log.Logger) {
 		"Cache.Chunk.EntriesStored", c.Chunk.EntriesStored,
 		"Cache.Chunk.BytesSent", humanize.Bytes(uint64(c.Chunk.BytesSent)),
 		"Cache.Chunk.BytesReceived", humanize.Bytes(uint64(c.Chunk.BytesReceived)),
+		"Cache.Chunk.DownloadTime", c.Chunk.CacheDownloadTime(),
 		"Cache.Index.Requests", c.Index.Requests,
 		"Cache.Index.EntriesRequested", c.Index.EntriesRequested,
 		"Cache.Index.EntriesFound", c.Index.EntriesFound,
 		"Cache.Index.EntriesStored", c.Index.EntriesStored,
 		"Cache.Index.BytesSent", humanize.Bytes(uint64(c.Index.BytesSent)),
 		"Cache.Index.BytesReceived", humanize.Bytes(uint64(c.Index.BytesReceived)),
+		"Cache.Index.DownloadTime", c.Index.CacheDownloadTime(),
 		"Cache.Result.Requests", c.Result.Requests,
 		"Cache.Result.EntriesRequested", c.Result.EntriesRequested,
 		"Cache.Result.EntriesFound", c.Result.EntriesFound,
 		"Cache.Result.EntriesStored", c.Result.EntriesStored,
 		"Cache.Result.BytesSent", humanize.Bytes(uint64(c.Result.BytesSent)),
 		"Cache.Result.BytesReceived", humanize.Bytes(uint64(c.Result.BytesReceived)),
+		"Cache.Result.DownloadTime", c.Result.CacheDownloadTime(),
 	)
 }

pkg/logqlmodel/stats/stats.pb.go

@@ -553,6 +553,7 @@ type Cache struct {
 	BytesReceived    int64 `protobuf:"varint,4,opt,name=bytesReceived,proto3" json:"bytesReceived"`
 	BytesSent        int64 `protobuf:"varint,5,opt,name=bytesSent,proto3" json:"bytesSent"`
 	Requests         int32 `protobuf:"varint,6,opt,name=requests,proto3" json:"requests"`
+	DownloadTime     int64 `protobuf:"varint,7,opt,name=downloadTime,proto3" json:"downloadTime"`
 }
 
 func (m *Cache) Reset()      { *m = Cache{} }
@@ -629,6 +630,13 @@ func (m *Cache) GetRequests() int32 {
 	return 0
 }
 
+func (m *Cache) GetDownloadTime() int64 {
+	if m != nil {
+		return m.DownloadTime
+	}
+	return 0
+}
+
 func init() {
 	proto.RegisterType((*Result)(nil), "stats.Result")
 	proto.RegisterType((*Caches)(nil), "stats.Caches")
@@ -643,65 +651,66 @@ func init() {
 func init() { proto.RegisterFile("pkg/logqlmodel/stats/stats.proto", fileDescriptor_6cdfe5d2aea33ebb) }
 
 var fileDescriptor_6cdfe5d2aea33ebb = []byte{
-	// 925 bytes of a gzipped FileDescriptorProto
-	0x1f, 0x8b, 0x08, 0x00, 0x00, 0x00, 0x00, 0x00, 0x02, 0xff, 0x8c, 0x56, 0x4b, 0x6f, 0xe4, 0x44,
-	0x10, 0x1e, 0xcf, 0xc4, 0x33, 0xd9, 0x26, 0xaf, 0xed, 0xcd, 0xb2, 0x06, 0x24, 0x3b, 0x9a, 0x53,
-	0x24, 0x50, 0x46, 0x3c, 0x24, 0x04, 0x62, 0x25, 0xe4, 0x2c, 0x2b, 0x45, 0x5a, 0xc4, 0x52, 0x81,
-	0x0b, 0x37, 0x8f, 0xdd, 0x3b, 0xb1, 0xe2, 0x71, 0x67, 0xfc, 0x80, 0xdd, 0x1b, 0x37, 0x8e, 0xf0,
-	0x1b, 0x10, 0x07, 0x2e, 0xfc, 0x8f, 0x1c, 0x73, 0xdc, 0x93, 0x45, 0x26, 0x17, 0xe4, 0xd3, 0x4a,
-	0xfc, 0x01, 0xd4, 0xd5, 0x3d, 0xb6, 0xdb, 0xe3, 0x91, 0xb8, 0x4c, 0x57, 0x7d, 0x5f, 0x7d, 0xfd,
-	0xac, 0xaa, 0x31, 0x39, 0xba, 0xba, 0x9c, 0x4d, 0x22, 0x3e, 0x5b, 0x44, 0x73, 0x1e, 0xb0, 0x68,
-	0x92, 0x66, 0x5e, 0x96, 0xca, 0xdf, 0x93, 0xab, 0x84, 0x67, 0x9c, 0x9a, 0xe8, 0xbc, 0x7b, 0x38,
-	0xe3, 0x33, 0x8e, 0xc8, 0x44, 0x58, 0x92, 0x1c, 0xff, 0x6b, 0x90, 0x21, 0xb0, 0x34, 0x8f, 0x32,
-	0xfa, 0x19, 0x19, 0xa5, 0xf9, 0x7c, 0xee, 0x25, 0xaf, 0x2c, 0xe3, 0xc8, 0x38, 0x7e, 0xeb, 0xa3,
-	0xbd, 0x13, 0x39, 0xcd, 0xb9, 0x44, 0xdd, 0xfd, 0xeb, 0xc2, 0xe9, 0x95, 0x85, 0xb3, 0x0a, 0x83,
-	0x95, 0x21, 0xa4, 0x8b, 0x9c, 0x25, 0x21, 0x4b, 0xac, 0xbe, 0x26, 0xfd, 0x56, 0xa2, 0xb5, 0x54,
-	0x85, 0xc1, 0xca, 0xa0, 0x8f, 0xc9, 0x76, 0x18, 0xcf, 0x58, 0x9a, 0xb1, 0xc4, 0x1a, 0xa0, 0x76,
-	0x5f, 0x69, 0xcf, 0x14, 0xec, 0x1e, 0x28, 0x71, 0x15, 0x08, 0x95, 0x45, 0x3f, 0x21, 0x43, 0xdf,
-	0xf3, 0x2f, 0x58, 0x6a, 0x6d, 0xa1, 0x78, 0x57, 0x89, 0x4f, 0x11, 0x74, 0x77, 0x95, 0xd4, 0xc4,
-	0x20, 0x50, 0xb1, 0xe3, 0x3f, 0x0c, 0x32, 0x94, 0x11, 0xf4, 0x43, 0x62, 0xfa, 0x17, 0x79, 0x7c,
-	0xa9, 0xce, 0xbc, 0xd3, 0xd4, 0x37, 0xe4, 0x22, 0x04, 0xe4, 0x20, 0x24, 0x61, 0x1c, 0xb0, 0x97,
-	0xea, 0xac, 0x1b, 0x24, 0x18, 0x02, 0x72, 0x10, 0xdb, 0x4c, 0xf0, 0x96, 0xd5, 0x19, 0x75, 0xcd,
-	0x9e, 0xd2, 0xa8, 0x18, 0x50, 0xe3, 0xf8, 0xf7, 0x2d, 0x32, 0x52, 0x97, 0x4f, 0xbf, 0x27, 0x8f,
-	0xa6, 0xaf, 0x32, 0x96, 0x3e, 0x4f, 0xb8, 0xcf, 0xd2, 0x94, 0x05, 0xcf, 0x59, 0x72, 0xce, 0x7c,
-	0x1e, 0x07, 0xb8, 0xf3, 0x81, 0xfb, 0x5e, 0x59, 0x38, 0x9b, 0x42, 0x60, 0x13, 0x21, 0xa6, 0x8d,
-	0xc2, 0xb8, 0x73, 0xda, 0x7e, 0x3d, 0xed, 0x86, 0x10, 0xd8, 0x44, 0xd0, 0x33, 0xf2, 0x20, 0xe3,
-	0x99, 0x17, 0xb9, 0xda, 0xb2, 0x78, 0xf8, 0x81, 0xfb, 0xa8, 0x2c, 0x9c, 0x2e, 0x1a, 0xba, 0xc0,
-	0x6a, 0xaa, 0x67, 0xda, 0x52, 0xf8, 0xdc, 0xcd, 0xa9, 0x74, 0x1a, 0xba, 0x40, 0x7a, 0x4c, 0xb6,
-	0xd9, 0x4b, 0xe6, 0x7f, 0x17, 0xce, 0x99, 0x65, 0x1e, 0x19, 0xc7, 0x86, 0xbb, 0x23, 0xd2, 0x6a,
-	0x85, 0x41, 0x65, 0xd1, 0xf7, 0xc9, 0xbd, 0x45, 0xce, 0x72, 0x86, 0xa1, 0x43, 0x0c, 0xdd, 0x2d,
-	0x0b, 0xa7, 0x06, 0xa1, 0x36, 0xe9, 0x09, 0x21, 0x69, 0x3e, 0x95, 0x09, 0x9d, 0x5a, 0x23, 0xdc,
-	0xd8, 0x5e, 0x59, 0x38, 0x0d, 0x14, 0x1a, 0x36, 0x7d, 0x46, 0x0e, 0x71, 0x77, 0x5f, 0xc5, 0x19,
-	0x72, 0x2c, 0xcb, 0x93, 0x98, 0x05, 0xd6, 0x36, 0x2a, 0xad, 0xb2, 0x70, 0x3a, 0x79, 0xe8, 0x44,
-	0xc7, 0x5f, 0x90, 0x91, 0xaa, 0x32, 0x91, 0x98, 0x69, 0xc6, 0x13, 0xd6, 0xca, 0xe5, 0x73, 0x81,
-	0xd5, 0x89, 0x89, 0x21, 0x20, 0x87, 0xf1, 0x5f, 0x7d, 0xb2, 0x7d, 0x56, 0x17, 0xd3, 0x0e, 0x2e,
-	0x01, 0x4c, 0xa4, 0xa5, 0x4c, 0x2c, 0xd3, 0x3d, 0x28, 0x0b, 0x47, 0xc3, 0x41, 0xf3, 0xe8, 0x53,
-	0x42, 0xd1, 0x3f, 0x15, 0xc5, 0x91, 0x7e, 0xed, 0x65, 0xa8, 0x95, 0xd9, 0xf3, 0x76, 0x59, 0x38,
-	0x1d, 0x2c, 0x74, 0x60, 0xd5, 0xea, 0x2e, 0xfa, 0xa9, 0x4a, 0x96, 0x7a, 0x75, 0x85, 0x83, 0xe6,
-	0xd1, 0xcf, 0xc9, 0x5e, 0xfd, 0xd4, 0xe7, 0x2c, 0xce, 0x54, 0x66, 0xd0, 0xb2, 0x70, 0x5a, 0x0c,
-	0xb4, 0xfc, 0xfa, 0xbe, 0xcc, 0xff, 0x7d, 0x5f, 0xbf, 0xf6, 0x89, 0x89, 0x7c, 0xb5, 0xb0, 0x3c,
-	0x04, 0xb0, 0x17, 0xaa, 0x0e, 0xeb, 0x85, 0x2b, 0x06, 0x5a, 0x3e, 0xfd, 0x86, 0x3c, 0x6c, 0x20,
-	0x4f, 0xf8, 0x4f, 0x71, 0xc4, 0xbd, 0xa0, 0xba, 0xb5, 0x77, 0xca, 0xc2, 0xe9, 0x0e, 0x80, 0x6e,
-	0x58, 0xbc, 0x81, 0xaf, 0x61, 0x98, 0xb8, 0x83, 0xfa, 0x0d, 0xd6, 0x59, 0xe8, 0xc0, 0xea, 0x6e,
-	0xb8, 0xa5, 0xb7, 0x29, 0x81, 0x75, 0x77, 0xc3, 0xf1, 0x2f, 0x03, 0x62, 0x22, 0x2f, 0x6e, 0xe4,
-	0x82, 0x79, 0x81, 0x0c, 0x16, 0x45, 0xdc, 0x7c, 0x0a, 0x9d, 0x81, 0x96, 0xaf, 0x69, 0xf1, 0x81,
-	0xf0, 0x4d, 0xda, 0x5a, 0x64, 0xa0, 0xe5, 0xd3, 0x53, 0x72, 0x3f, 0x60, 0x3e, 0x9f, 0x5f, 0x25,
-	0x58, 0xe6, 0x72, 0xe9, 0x21, 0xca, 0x1f, 0x96, 0x85, 0xb3, 0x4e, 0xc2, 0x3a, 0xd4, 0x9e, 0x44,
-	0xee, 0x61, 0xd4, 0x3d, 0x89, 0xdc, 0xc6, 0x3a, 0x44, 0x1f, 0x93, 0xfd, 0xf6, 0x3e, 0x64, 0x51,
-	0x3f, 0x28, 0x0b, 0xa7, 0x4d, 0x41, 0x1b, 0x10, 0x72, 0x7c, 0xde, 0x27, 0xf9, 0x55, 0x14, 0xfa,
-	0x9e, 0x90, 0xdf, 0xab, 0xe5, 0x2d, 0x0a, 0xda, 0xc0, 0xf8, 0xba, 0x4f, 0x4c, 0xfc, 0x43, 0x11,
-	0xa5, 0xc4, 0x64, 0x9b, 0x78, 0xca, 0xf3, 0x58, 0x2b, 0xe4, 0x26, 0x0e, 0x9a, 0x47, 0xbf, 0x24,
-	0x07, 0x6c, 0xd5, 0x5c, 0x16, 0xb9, 0x68, 0x09, 0x32, 0x21, 0x4d, 0xf7, 0xb0, 0x2c, 0x9c, 0x35,
-	0x0e, 0xd6, 0x10, 0xfa, 0x29, 0xd9, 0x55, 0x18, 0xd6, 0x88, 0x6c, 0xf8, 0xa6, 0x7b, 0xbf, 0x2c,
-	0x1c, 0x9d, 0x00, 0xdd, 0x15, 0x42, 0xfc, 0x87, 0x02, 0xe6, 0xb3, 0xf0, 0xc7, 0xaa, 0xbd, 0xa3,
-	0x50, 0x23, 0x40, 0x77, 0x45, 0xa3, 0x46, 0x00, 0x2b, 0x5f, 0xa6, 0x0c, 0x36, 0xea, 0x0a, 0x84,
-	0xda, 0x14, 0xfd, 0x3f, 0x91, 0x7b, 0x95, 0xf9, 0x61, 0xca, 0xfe, 0xbf, 0xc2, 0xa0, 0xb2, 0xdc,
-	0xe9, 0xcd, 0xad, 0xdd, 0x7b, 0x7d, 0x6b, 0xf7, 0xde, 0xdc, 0xda, 0xc6, 0xcf, 0x4b, 0xdb, 0xf8,
-	0x73, 0x69, 0x1b, 0xd7, 0x4b, 0xdb, 0xb8, 0x59, 0xda, 0xc6, 0xdf, 0x4b, 0xdb, 0xf8, 0x67, 0x69,
-	0xf7, 0xde, 0x2c, 0x6d, 0xe3, 0xb7, 0x3b, 0xbb, 0x77, 0x73, 0x67, 0xf7, 0x5e, 0xdf, 0xd9, 0xbd,
-	0x1f, 0x3e, 0x98, 0x85, 0xd9, 0x45, 0x3e, 0x3d, 0xf1, 0xf9, 0x7c, 0x32, 0x4b, 0xbc, 0x17, 0x5e,
-	0xec, 0x4d, 0x22, 0x7e, 0x19, 0x4e, 0xba, 0xbe, 0xd1, 0xa6, 0x43, 0xfc, 0x02, 0xfb, 0xf8, 0xbf,
-	0x00, 0x00, 0x00, 0xff, 0xff, 0x8e, 0x12, 0x05, 0xf0, 0xc2, 0x09, 0x00, 0x00,
+	// 937 bytes of a gzipped FileDescriptorProto
+	0x1f, 0x8b, 0x08, 0x00, 0x00, 0x00, 0x00, 0x00, 0x02, 0xff, 0x8c, 0x56, 0xcd, 0x8f, 0xdb, 0x44,
+	0x14, 0x8f, 0x93, 0x75, 0xb2, 0x1d, 0xf6, 0xab, 0xd3, 0x2d, 0x35, 0x20, 0xd9, 0xab, 0x9c, 0x56,
+	0x02, 0x6d, 0xc4, 0x87, 0x84, 0x40, 0x54, 0x42, 0xde, 0x52, 0x69, 0xa5, 0x22, 0xca, 0x5b, 0xb8,
+	0x70, 0x73, 0xec, 0x69, 0xd6, 0x5a, 0xc7, 0xb3, 0xf1, 0x07, 0xb4, 0x37, 0x6e, 0x1c, 0xe1, 0x6f,
+	0x40, 0x1c, 0xb8, 0xf0, 0x7f, 0xf4, 0xb8, 0xc7, 0x9e, 0x2c, 0x36, 0x7b, 0x41, 0x3e, 0x55, 0xe2,
+	0x8e, 0xd0, 0xbc, 0x99, 0xd8, 0x1e, 0xc7, 0x91, 0x7a, 0xc9, 0xbc, 0xf7, 0xfb, 0xbd, 0xdf, 0x7c,
+	0xbe, 0xf7, 0x62, 0x72, 0x74, 0x75, 0x39, 0x9b, 0x44, 0x7c, 0xb6, 0x88, 0xe6, 0x3c, 0x60, 0xd1,
+	0x24, 0xcd, 0xbc, 0x2c, 0x95, 0xbf, 0x27, 0x57, 0x09, 0xcf, 0x38, 0x35, 0xd1, 0x79, 0xf7, 0x70,
+	0xc6, 0x67, 0x1c, 0x91, 0x89, 0xb0, 0x24, 0x39, 0xfe, 0xd7, 0x20, 0x43, 0x60, 0x69, 0x1e, 0x65,
+	0xf4, 0x33, 0x32, 0x4a, 0xf3, 0xf9, 0xdc, 0x4b, 0x5e, 0x58, 0xc6, 0x91, 0x71, 0xfc, 0xd6, 0x47,
+	0x7b, 0x27, 0x72, 0x9a, 0x73, 0x89, 0xba, 0xfb, 0x2f, 0x0b, 0xa7, 0x57, 0x16, 0xce, 0x2a, 0x0c,
+	0x56, 0x86, 0x90, 0x2e, 0x72, 0x96, 0x84, 0x2c, 0xb1, 0xfa, 0x9a, 0xf4, 0x5b, 0x89, 0xd6, 0x52,
+	0x15, 0x06, 0x2b, 0x83, 0x3e, 0x24, 0xdb, 0x61, 0x3c, 0x63, 0x69, 0xc6, 0x12, 0x6b, 0x80, 0xda,
+	0x7d, 0xa5, 0x3d, 0x53, 0xb0, 0x7b, 0xa0, 0xc4, 0x55, 0x20, 0x54, 0x16, 0xfd, 0x84, 0x0c, 0x7d,
+	0xcf, 0xbf, 0x60, 0xa9, 0xb5, 0x85, 0xe2, 0x5d, 0x25, 0x3e, 0x45, 0xd0, 0xdd, 0x55, 0x52, 0x13,
+	0x83, 0x40, 0xc5, 0x8e, 0xff, 0x30, 0xc8, 0x50, 0x46, 0xd0, 0x0f, 0x89, 0xe9, 0x5f, 0xe4, 0xf1,
+	0xa5, 0x3a, 0xf3, 0x4e, 0x53, 0xdf, 0x90, 0x8b, 0x10, 0x90, 0x83, 0x90, 0x84, 0x71, 0xc0, 0x9e,
+	0xab, 0xb3, 0x6e, 0x90, 0x60, 0x08, 0xc8, 0x41, 0x6c, 0x33, 0xc1, 0x5b, 0x56, 0x67, 0xd4, 0x35,
+	0x7b, 0x4a, 0xa3, 0x62, 0x40, 0x8d, 0xe3, 0xdf, 0xb7, 0xc8, 0x48, 0x5d, 0x3e, 0xfd, 0x9e, 0x3c,
+	0x98, 0xbe, 0xc8, 0x58, 0xfa, 0x34, 0xe1, 0x3e, 0x4b, 0x53, 0x16, 0x3c, 0x65, 0xc9, 0x39, 0xf3,
+	0x79, 0x1c, 0xe0, 0xce, 0x07, 0xee, 0x7b, 0x65, 0xe1, 0x6c, 0x0a, 0x81, 0x4d, 0x84, 0x98, 0x36,
+	0x0a, 0xe3, 0xce, 0x69, 0xfb, 0xf5, 0xb4, 0x1b, 0x42, 0x60, 0x13, 0x41, 0xcf, 0xc8, 0xbd, 0x8c,
+	0x67, 0x5e, 0xe4, 0x6a, 0xcb, 0xe2, 0xe1, 0x07, 0xee, 0x83, 0xb2, 0x70, 0xba, 0x68, 0xe8, 0x02,
+	0xab, 0xa9, 0x9e, 0x68, 0x4b, 0xe1, 0x73, 0x37, 0xa7, 0xd2, 0x69, 0xe8, 0x02, 0xe9, 0x31, 0xd9,
+	0x66, 0xcf, 0x99, 0xff, 0x5d, 0x38, 0x67, 0x96, 0x79, 0x64, 0x1c, 0x1b, 0xee, 0x8e, 0x48, 0xab,
+	0x15, 0x06, 0x95, 0x45, 0xdf, 0x27, 0x77, 0x16, 0x39, 0xcb, 0x19, 0x86, 0x0e, 0x31, 0x74, 0xb7,
+	0x2c, 0x9c, 0x1a, 0x84, 0xda, 0xa4, 0x27, 0x84, 0xa4, 0xf9, 0x54, 0x26, 0x74, 0x6a, 0x8d, 0x70,
+	0x63, 0x7b, 0x65, 0xe1, 0x34, 0x50, 0x68, 0xd8, 0xf4, 0x09, 0x39, 0xc4, 0xdd, 0x7d, 0x15, 0x67,
+	0xc8, 0xb1, 0x2c, 0x4f, 0x62, 0x16, 0x58, 0xdb, 0xa8, 0xb4, 0xca, 0xc2, 0xe9, 0xe4, 0xa1, 0x13,
+	0x1d, 0x7f, 0x41, 0x46, 0xaa, 0xca, 0x44, 0x62, 0xa6, 0x19, 0x4f, 0x58, 0x2b, 0x97, 0xcf, 0x05,
+	0x56, 0x27, 0x26, 0x86, 0x80, 0x1c, 0xc6, 0x7f, 0xf5, 0xc9, 0xf6, 0x59, 0x5d, 0x4c, 0x3b, 0xb8,
+	0x04, 0x30, 0x91, 0x96, 0x32, 0xb1, 0x4c, 0xf7, 0xa0, 0x2c, 0x1c, 0x0d, 0x07, 0xcd, 0xa3, 0x8f,
+	0x09, 0x45, 0xff, 0x54, 0x14, 0x47, 0xfa, 0xb5, 0x97, 0xa1, 0x56, 0x66, 0xcf, 0xdb, 0x65, 0xe1,
+	0x74, 0xb0, 0xd0, 0x81, 0x55, 0xab, 0xbb, 0xe8, 0xa7, 0x2a, 0x59, 0xea, 0xd5, 0x15, 0x0e, 0x9a,
+	0x47, 0x3f, 0x27, 0x7b, 0xf5, 0x53, 0x9f, 0xb3, 0x38, 0x53, 0x99, 0x41, 0xcb, 0xc2, 0x69, 0x31,
+	0xd0, 0xf2, 0xeb, 0xfb, 0x32, 0xdf, 0xf8, 0xbe, 0x7e, 0xed, 0x13, 0x13, 0xf9, 0x6a, 0x61, 0x79,
+	0x08, 0x60, 0xcf, 0x54, 0x1d, 0xd6, 0x0b, 0x57, 0x0c, 0xb4, 0x7c, 0xfa, 0x0d, 0xb9, 0xdf, 0x40,
+	0x1e, 0xf1, 0x9f, 0xe2, 0x88, 0x7b, 0x41, 0x75, 0x6b, 0xef, 0x94, 0x85, 0xd3, 0x1d, 0x00, 0xdd,
+	0xb0, 0x78, 0x03, 0x5f, 0xc3, 0x30, 0x71, 0x07, 0xf5, 0x1b, 0xac, 0xb3, 0xd0, 0x81, 0xd5, 0xdd,
+	0x70, 0x4b, 0x6f, 0x53, 0x02, 0xeb, 0xee, 0x86, 0xe3, 0x5f, 0x06, 0xc4, 0x44, 0x5e, 0xdc, 0xc8,
+	0x05, 0xf3, 0x02, 0x19, 0x2c, 0x8a, 0xb8, 0xf9, 0x14, 0x3a, 0x03, 0x2d, 0x5f, 0xd3, 0xe2, 0x03,
+	0xe1, 0x9b, 0xb4, 0xb5, 0xc8, 0x40, 0xcb, 0xa7, 0xa7, 0xe4, 0x6e, 0xc0, 0x7c, 0x3e, 0xbf, 0x4a,
+	0xb0, 0xcc, 0xe5, 0xd2, 0x43, 0x94, 0xdf, 0x2f, 0x0b, 0x67, 0x9d, 0x84, 0x75, 0xa8, 0x3d, 0x89,
+	0xdc, 0xc3, 0xa8, 0x7b, 0x12, 0xb9, 0x8d, 0x75, 0x88, 0x3e, 0x24, 0xfb, 0xed, 0x7d, 0xc8, 0xa2,
+	0xbe, 0x57, 0x16, 0x4e, 0x9b, 0x82, 0x36, 0x20, 0xe4, 0xf8, 0xbc, 0x8f, 0xf2, 0xab, 0x28, 0xf4,
+	0x3d, 0x21, 0xbf, 0x53, 0xcb, 0x5b, 0x14, 0xb4, 0x81, 0xf1, 0x7f, 0x7d, 0x62, 0xe2, 0x1f, 0x8a,
+	0x28, 0x25, 0x26, 0xdb, 0xc4, 0x63, 0x9e, 0xc7, 0x5a, 0x21, 0x37, 0x71, 0xd0, 0x3c, 0xfa, 0x25,
+	0x39, 0x60, 0xab, 0xe6, 0xb2, 0xc8, 0x45, 0x4b, 0x90, 0x09, 0x69, 0xba, 0x87, 0x65, 0xe1, 0xac,
+	0x71, 0xb0, 0x86, 0xd0, 0x4f, 0xc9, 0xae, 0xc2, 0xb0, 0x46, 0x64, 0xc3, 0x37, 0xdd, 0xbb, 0x65,
+	0xe1, 0xe8, 0x04, 0xe8, 0xae, 0x10, 0xe2, 0x3f, 0x14, 0x30, 0x9f, 0x85, 0x3f, 0x56, 0xed, 0x1d,
+	0x85, 0x1a, 0x01, 0xba, 0x2b, 0x1a, 0x35, 0x02, 0x58, 0xf9, 0x32, 0x65, 0xb0, 0x51, 0x57, 0x20,
+	0xd4, 0xa6, 0xe8, 0xff, 0x89, 0xdc, 0xab, 0xcc, 0x0f, 0x53, 0xf6, 0xff, 0x15, 0x06, 0x95, 0x25,
+	0x2e, 0x30, 0x68, 0x56, 0xd2, 0xa8, 0xee, 0x45, 0x4d, 0x1c, 0x34, 0xcf, 0x9d, 0x5e, 0xdf, 0xd8,
+	0xbd, 0x57, 0x37, 0x76, 0xef, 0xf5, 0x8d, 0x6d, 0xfc, 0xbc, 0xb4, 0x8d, 0x3f, 0x97, 0xb6, 0xf1,
+	0x72, 0x69, 0x1b, 0xd7, 0x4b, 0xdb, 0xf8, 0x7b, 0x69, 0x1b, 0xff, 0x2c, 0xed, 0xde, 0xeb, 0xa5,
+	0x6d, 0xfc, 0x76, 0x6b, 0xf7, 0xae, 0x6f, 0xed, 0xde, 0xab, 0x5b, 0xbb, 0xf7, 0xc3, 0x07, 0xb3,
+	0x30, 0xbb, 0xc8, 0xa7, 0x27, 0x3e, 0x9f, 0x4f, 0x66, 0x89, 0xf7, 0xcc, 0x8b, 0xbd, 0x49, 0xc4,
+	0x2f, 0xc3, 0x49, 0xd7, 0x97, 0xdd, 0x74, 0x88, 0xdf, 0x6d, 0x1f, 0xff, 0x1f, 0x00, 0x00, 0xff,
+	0xff, 0x33, 0x50, 0xe6, 0x64, 0xf8, 0x09, 0x00, 0x00,
 }
 
 func (this *Result) Equal(that interface{}) bool {
@@ -981,6 +990,9 @@ func (this *Cache) Equal(that interface{}) bool {
 	if this.Requests != that1.Requests {
 		return false
 	}
+	if this.DownloadTime != that1.DownloadTime {
+		return false
+	}
 	return true
 }
 func (this *Result) GoString() string {
@@ -1081,7 +1093,7 @@ func (this *Cache) GoString() string {
 	if this == nil {
 		return "nil"
 	}
-	s := make([]string, 0, 10)
+	s := make([]string, 0, 11)
 	s = append(s, "&stats.Cache{")
 	s = append(s, "EntriesFound: "+fmt.Sprintf("%#v", this.EntriesFound)+",\n")
 	s = append(s, "EntriesRequested: "+fmt.Sprintf("%#v", this.EntriesRequested)+",\n")
@@ -1089,6 +1101,7 @@ func (this *Cache) GoString() string {
 	s = append(s, "BytesReceived: "+fmt.Sprintf("%#v", this.BytesReceived)+",\n")
 	s = append(s, "BytesSent: "+fmt.Sprintf("%#v", this.BytesSent)+",\n")
 	s = append(s, "Requests: "+fmt.Sprintf("%#v", this.Requests)+",\n")
+	s = append(s, "DownloadTime: "+fmt.Sprintf("%#v", this.DownloadTime)+",\n")
 	s = append(s, "}")
 	return strings.Join(s, "")
 }
@@ -1488,6 +1501,11 @@ func (m *Cache) MarshalToSizedBuffer(dAtA []byte) (int, error) {
 	_ = i
 	var l int
 	_ = l
+	if m.DownloadTime != 0 {
+		i = encodeVarintStats(dAtA, i, uint64(m.DownloadTime))
+		i--
+		dAtA[i] = 0x38
+	}
 	if m.Requests != 0 {
 		i = encodeVarintStats(dAtA, i, uint64(m.Requests))
 		i--
@@ -1702,6 +1720,9 @@ func (m *Cache) Size() (n int) {
 	if m.Requests != 0 {
 		n += 1 + sovStats(uint64(m.Requests))
 	}
+	if m.DownloadTime != 0 {
+		n += 1 + sovStats(uint64(m.DownloadTime))
+	}
 	return n
 }
 
@@ -1816,6 +1837,7 @@ func (this *Cache) String() string {
 		`BytesReceived:` + fmt.Sprintf("%v", this.BytesReceived) + `,`,
 		`BytesSent:` + fmt.Sprintf("%v", this.BytesSent) + `,`,
 		`Requests:` + fmt.Sprintf("%v", this.Requests) + `,`,
+		`DownloadTime:` + fmt.Sprintf("%v", this.DownloadTime) + `,`,
 		`}`,
 	}, "")
 	return s
@@ -3055,6 +3077,25 @@ func (m *Cache) Unmarshal(dAtA []byte) error {
 					break
 				}
 			}
+		case 7:
+			if wireType != 0 {
+				return fmt.Errorf("proto: wrong wireType = %d for field DownloadTime", wireType)
+			}
+			m.DownloadTime = 0
+			for shift := uint(0); ; shift += 7 {
+				if shift >= 64 {
+					return ErrIntOverflowStats
+				}
+				if iNdEx >= l {
+					return io.ErrUnexpectedEOF
+				}
+				b := dAtA[iNdEx]
+				iNdEx++
+				m.DownloadTime |= int64(b&0x7F) << shift
+				if b < 0x80 {
+					break
+				}
+			}
 		default:
 			iNdEx = preIndex
 			skippy, err := skipStats(dAtA[iNdEx:])

pkg/logqlmodel/stats/stats.proto

@@ -126,4 +126,5 @@ message Cache {
   int64 bytesReceived = 4 [(gogoproto.jsontag) = "bytesReceived"];
   int64 bytesSent = 5 [(gogoproto.jsontag) = "bytesSent"];
   int32 requests = 6 [(gogoproto.jsontag) = "requests"];
+  int64 downloadTime = 7 [(gogoproto.jsontag) = "downloadTime"];
 }

pkg/querier/queryrange/codec_test.go

@@ -983,7 +983,8 @@ var (
 				"entriesStored": 0,
 				"bytesReceived": 0,
 				"bytesSent": 0,
-				"requests": 0
+				"requests": 0,
+				"downloadTime": 0
 			},
 			"index": {
 				"entriesFound": 0,
@@ -991,7 +992,8 @@ var (
 				"entriesStored": 0,
 				"bytesReceived": 0,
 				"bytesSent": 0,
-				"requests": 0
+				"requests": 0,
+				"downloadTime": 0
 			},
 			"result": {
 				"entriesFound": 0,
@@ -999,7 +1001,8 @@ var (
 				"entriesStored": 0,
 				"bytesReceived": 0,
 				"bytesSent": 0,
-				"requests": 0
+				"requests": 0,
+				"downloadTime": 0
 			}
 		},
 		"summary": {

pkg/querier/queryrange/prometheus_test.go

@@ -54,7 +54,8 @@ var emptyStats = `"stats": {
 			"entriesStored": 0,
 			"bytesReceived": 0,
 			"bytesSent": 0,
-			"requests": 0
+			"requests": 0,
+			"downloadTime": 0
 		},
 		"index": {
 			"entriesFound": 0,
@@ -62,7 +63,8 @@ var emptyStats = `"stats": {
 			"entriesStored": 0,
 			"bytesReceived": 0,
 			"bytesSent": 0,
-			"requests": 0
+			"requests": 0,
+			"downloadTime": 0
 		},
 		"result": {
 			"entriesFound": 0,
@@ -70,7 +72,8 @@ var emptyStats = `"stats": {
 			"entriesStored": 0,
 			"bytesReceived": 0,
 			"bytesSent": 0,
-			"requests": 0
+			"requests": 0,
+			"downloadTime": 0
 		}
 	},
 	"summary": {
@@ -80,7 +83,7 @@ var emptyStats = `"stats": {
 		"queueTime": 0,
 		"subqueries": 0,
 		"totalBytesProcessed":0,
-                "totalEntriesReturned":0,
+		"totalEntriesReturned":0,
 		"totalLinesProcessed":0
 	}
 }`

pkg/storage/chunk/cache/stats.go

@@ -2,6 +2,7 @@ package cache
 
 import (
 	"context"
+	"time"
 
 	"github.com/grafana/loki/pkg/logqlmodel/stats"
 )
@@ -32,8 +33,11 @@ func (s statsCollector) Fetch(ctx context.Context, keys []string) (found []strin
 	st := stats.FromContext(ctx)
 	st.AddCacheRequest(s.Cache.GetCacheType(), 1)
 
+	start := time.Now()
+
 	found, bufs, missing, err = s.Cache.Fetch(ctx, keys)
 
+	st.AddCacheDownloadTime(s.Cache.GetCacheType(), time.Since(start))
 	st.AddCacheEntriesFound(s.Cache.GetCacheType(), len(found))
 	st.AddCacheEntriesRequested(s.Cache.GetCacheType(), len(keys))
 

pkg/util/marshal/legacy/marshal_test.go

@@ -85,7 +85,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					},
 					"index": {
 						"entriesFound": 0,
@@ -93,7 +94,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					},
 					"result": {
 						"entriesFound": 0,
@@ -101,7 +103,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					}
 				},
 				"summary": {

pkg/util/marshal/marshal_test.go

@@ -94,7 +94,8 @@ var queryTests = []struct {
 							"entriesStored": 0,
 							"bytesReceived": 0,
 							"bytesSent": 0,
-							"requests": 0
+							"requests": 0,
+							"downloadTime": 0
 						},
 						"index": {
 							"entriesFound": 0,
@@ -102,7 +103,8 @@ var queryTests = []struct {
 							"entriesStored": 0,
 							"bytesReceived": 0,
 							"bytesSent": 0,
-							"requests": 0
+							"requests": 0,
+							"downloadTime": 0
 						},
 						"result": {
 							"entriesFound": 0,
@@ -110,7 +112,8 @@ var queryTests = []struct {
 							"entriesStored": 0,
 							"bytesReceived": 0,
 							"bytesSent": 0,
-							"requests": 0
+							"requests": 0,
+							"downloadTime": 0
 						}
 					},
 					"summary": {
@@ -230,7 +233,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					},
 					"index": {
 						"entriesFound": 0,
@@ -238,7 +242,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					},
 					"result": {
 						"entriesFound": 0,
@@ -246,7 +251,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					}
 				},
 				"summary": {
@@ -383,7 +389,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					},
 					"index": {
 						"entriesFound": 0,
@@ -391,7 +398,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					},
 					"result": {
 						"entriesFound": 0,
@@ -399,7 +407,8 @@ var queryTests = []struct {
 						"entriesStored": 0,
 						"bytesReceived": 0,
 						"bytesSent": 0,
-						"requests": 0
+						"requests": 0,
+						"downloadTime": 0
 					}
 				},
 				"summary": {