diff --git a/docs/sources/upgrading/_index.md b/docs/sources/upgrading/_index.md index 15e5769df4..ae9dcaedb6 100644 --- a/docs/sources/upgrading/_index.md +++ b/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 diff --git a/pkg/logql/metrics.go b/pkg/logql/metrics.go index 558600c542..4991419775 100644 --- a/pkg/logql/metrics.go +++ b/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)...) diff --git a/pkg/logql/metrics_test.go b/pkg/logql/metrics_test.go index 2e8d65177e..00fb47883b 100644 --- a/pkg/logql/metrics_test.go +++ b/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()) diff --git a/pkg/logqlmodel/stats/context.go b/pkg/logqlmodel/stats/context.go index 12628ae4b6..ad9f10cef9 100644 --- a/pkg/logqlmodel/stats/context.go +++ b/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(), ) } diff --git a/pkg/logqlmodel/stats/stats.pb.go b/pkg/logqlmodel/stats/stats.pb.go index 345a673b1e..26cf3ddbe1 100644 --- a/pkg/logqlmodel/stats/stats.pb.go +++ b/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:]) diff --git a/pkg/logqlmodel/stats/stats.proto b/pkg/logqlmodel/stats/stats.proto index 2ab22e7996..79d56280b3 100644 --- a/pkg/logqlmodel/stats/stats.proto +++ b/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"]; } diff --git a/pkg/querier/queryrange/codec_test.go b/pkg/querier/queryrange/codec_test.go index d4a3fe5134..a9a12466ef 100644 --- a/pkg/querier/queryrange/codec_test.go +++ b/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": { diff --git a/pkg/querier/queryrange/prometheus_test.go b/pkg/querier/queryrange/prometheus_test.go index 84bd2112b1..e679a98111 100644 --- a/pkg/querier/queryrange/prometheus_test.go +++ b/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 } }` diff --git a/pkg/storage/chunk/cache/stats.go b/pkg/storage/chunk/cache/stats.go index 9964532ad8..3bdf0b017e 100644 --- a/pkg/storage/chunk/cache/stats.go +++ b/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)) diff --git a/pkg/util/marshal/legacy/marshal_test.go b/pkg/util/marshal/legacy/marshal_test.go index cf8a18b7bb..8cf2ecc299 100644 --- a/pkg/util/marshal/legacy/marshal_test.go +++ b/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": { diff --git a/pkg/util/marshal/marshal_test.go b/pkg/util/marshal/marshal_test.go index efdfabc2ff..4650214ff6 100644 --- a/pkg/util/marshal/marshal_test.go +++ b/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": {