github.com/siglens/siglens@v0.0.0-20240328180423-f7ce9ae441ed/pkg/segment/query/summary/querysummary.go (about)

     1  /*
     2  Copyright 2023.
     3  
     4  Licensed under the Apache License, Version 2.0 (the "License");
     5  you may not use this file except in compliance with the License.
     6  You may obtain a copy of the License at
     7  
     8      http://www.apache.org/licenses/LICENSE-2.0
     9  
    10  Unless required by applicable law or agreed to in writing, software
    11  distributed under the License is distributed on an "AS IS" BASIS,
    12  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    13  See the License for the specific language governing permissions and
    14  limitations under the License.
    15  */
    16  
    17  package summary
    18  
    19  import (
    20  	"fmt"
    21  	"math"
    22  	"sort"
    23  	"sync"
    24  	"sync/atomic"
    25  	"time"
    26  
    27  	"github.com/siglens/siglens/pkg/config"
    28  	"github.com/siglens/siglens/pkg/hooks"
    29  	"github.com/siglens/siglens/pkg/instrumentation"
    30  	"github.com/siglens/siglens/pkg/segment/structs"
    31  	uStats "github.com/siglens/siglens/pkg/usageStats"
    32  	log "github.com/sirupsen/logrus"
    33  )
    34  
    35  type SearchTypeEnum int
    36  
    37  const (
    38  	RAW SearchTypeEnum = iota
    39  	PQS
    40  	STREE
    41  	GRPC_ROTATED
    42  	GRPC_UNROTATED
    43  )
    44  
    45  type QueryType int
    46  
    47  const (
    48  	LOGS QueryType = iota
    49  	METRICS
    50  )
    51  
    52  type searchTypeSummary struct {
    53  	numFilesSearched  uint64
    54  	numMatched        uint64
    55  	minPerSegment     uint64
    56  	seenOneVal        bool
    57  	maxPerSegment     uint64
    58  	searchTimeHistory []time.Duration
    59  	totalTime         time.Duration
    60  }
    61  
    62  type MetadataSummary struct {
    63  	numCMIBlocksChecked uint64
    64  	numCMIBlocksPassed  uint64
    65  	allTimes            []time.Duration
    66  	totalTime           time.Duration
    67  }
    68  
    69  type metricsQueryTypeSummary struct {
    70  	timeGettingRotatedSearchRequests   time.Duration
    71  	timeGettingUnrotatedSearchRequests time.Duration
    72  	timeSearchingTagsTrees             []time.Duration
    73  	timeLoadingTSOFiles                []time.Duration
    74  	timeLoadingTSGFiles                []time.Duration
    75  }
    76  
    77  type QuerySummary struct {
    78  	queryType                   QueryType
    79  	updateLock                  *sync.Mutex
    80  	qid                         uint64
    81  	ticker                      *time.Ticker
    82  	tickerStopChan              chan bool
    83  	startTime                   time.Time
    84  	rawSearchTime               time.Duration
    85  	queryTotalTime              time.Duration
    86  	totalNumFiles               uint64
    87  	numRecordsSearched          uint64
    88  	numRecordsMatched           uint64
    89  	remoteRecordsSearched       uint64
    90  	remoteRecordsMatched        uint64
    91  	numMetricsSegmentsSearched  uint64
    92  	numTSIDsMatched             uint64
    93  	numTagsTreesSearched        uint64
    94  	numTSOFilesLoaded           uint64
    95  	numTSGFilesLoaded           uint64
    96  	numSeriesSearched           uint64
    97  	numResultSeries             uint64
    98  	allQuerySummaries           map[SearchTypeEnum]*searchTypeSummary
    99  	metricsQuerySummary         *metricsQueryTypeSummary
   100  	metadataSummary             MetadataSummary
   101  	numBuckets                  int
   102  	remainingDistributedQueries uint64
   103  	totalDistributedQueries     uint64
   104  }
   105  
   106  // InitQuerySummary returns a struct to store query level search stats.
   107  // This function starts a ticker to log info about long running queries.
   108  // Caller is responsible for calling LogSummary() function to stop the ticker.
   109  func InitQuerySummary(queryType QueryType, qid uint64) *QuerySummary {
   110  	lock := &sync.Mutex{}
   111  	rawSearchTypeSummary := &searchTypeSummary{}
   112  	pqsSearchTypeSummary := &searchTypeSummary{}
   113  	agileTreeSearchTypeSummary := &searchTypeSummary{}
   114  	allQuerySummaries := make(map[SearchTypeEnum]*searchTypeSummary)
   115  	allQuerySummaries[RAW] = rawSearchTypeSummary
   116  	allQuerySummaries[PQS] = pqsSearchTypeSummary
   117  	allQuerySummaries[STREE] = agileTreeSearchTypeSummary
   118  	allQuerySummaries[GRPC_ROTATED] = &searchTypeSummary{}
   119  	allQuerySummaries[GRPC_UNROTATED] = &searchTypeSummary{}
   120  
   121  	qs := &QuerySummary{
   122  		queryType:           queryType,
   123  		updateLock:          lock,
   124  		qid:                 qid,
   125  		startTime:           time.Now(),
   126  		queryTotalTime:      time.Duration(0),
   127  		allQuerySummaries:   allQuerySummaries,
   128  		metricsQuerySummary: &metricsQueryTypeSummary{},
   129  		metadataSummary: MetadataSummary{
   130  			allTimes: make([]time.Duration, 0),
   131  		},
   132  		remainingDistributedQueries: 0,
   133  	}
   134  	qs.startTicker()
   135  	return qs
   136  }
   137  
   138  func (qs *QuerySummary) startTicker() {
   139  	qs.ticker = time.NewTicker(10 * time.Second)
   140  	qs.tickerStopChan = make(chan bool)
   141  	go qs.tickWatcher()
   142  }
   143  
   144  func (qs *QuerySummary) stopTicker() {
   145  	if qs.ticker != nil {
   146  		qs.ticker.Stop()
   147  		close(qs.tickerStopChan)
   148  	}
   149  }
   150  
   151  func (qs *QuerySummary) tickWatcher() {
   152  	defer func() {
   153  		qs.ticker.Stop()
   154  		qs.ticker = nil
   155  		qs.tickerStopChan = nil
   156  	}()
   157  	for {
   158  		select {
   159  		case <-qs.tickerStopChan:
   160  			return
   161  		case <-qs.ticker.C:
   162  			if qs.queryType == LOGS {
   163  				remainingDQsString := ""
   164  				var addDistributedInfo bool
   165  				if hook := hooks.GlobalHooks.ShouldAddDistributedInfoHook; hook != nil {
   166  					addDistributedInfo = hook()
   167  				}
   168  
   169  				if addDistributedInfo {
   170  					remainingDQsString = fmt.Sprintf(", remaining distributed queries: %v", qs.remainingDistributedQueries)
   171  				}
   172  
   173  				log.Infof("qid=%d, still executing. Time Elapsed (%v), files so far: PQS: %v, RAW: %v, STREE: %v%v", qs.qid, time.Since(qs.startTime),
   174  					len(qs.allQuerySummaries[PQS].searchTimeHistory),
   175  					len(qs.allQuerySummaries[RAW].searchTimeHistory),
   176  					len(qs.allQuerySummaries[STREE].searchTimeHistory),
   177  					remainingDQsString)
   178  			} else if qs.queryType == METRICS {
   179  				log.Infof("qid=%d, still executing. Time Elapsed (%v). So far, number of metrics segments searched=%+v, number of TSIDs searched=%+v across %+v tags trees, number of TSO files loaded=%+v, number of TSG files loaded=%+v", qs.qid, time.Since(qs.startTime), qs.getNumMetricsSegmentsSearched(), qs.getNumTSIDsMatched(), qs.getNumTagsTreesSearched(), qs.getNumTSOFilesLoaded(), qs.getNumTSGFilesLoaded())
   180  			}
   181  		}
   182  	}
   183  }
   184  
   185  func (qs *QuerySummary) UpdateCMIResults(numBlocksChecked, passedBlocks uint64) {
   186  	qs.metadataSummary.numCMIBlocksChecked += numBlocksChecked
   187  	qs.metadataSummary.numCMIBlocksPassed += passedBlocks
   188  }
   189  
   190  func (qs *QuerySummary) IncrementNumTagsTreesSearched(record uint64) {
   191  	qs.updateLock.Lock()
   192  	qs.numTagsTreesSearched += record
   193  	qs.updateLock.Unlock()
   194  }
   195  
   196  func (qs *QuerySummary) IncrementNumTSIDsMatched(record uint64) {
   197  	qs.updateLock.Lock()
   198  	qs.numTSIDsMatched += record
   199  	qs.updateLock.Unlock()
   200  }
   201  
   202  func (qs *QuerySummary) IncrementNumResultSeries(record uint64) {
   203  	qs.updateLock.Lock()
   204  	qs.numResultSeries += record
   205  	qs.updateLock.Unlock()
   206  }
   207  
   208  func (qs *QuerySummary) UpdateExtractSSRTime(t time.Duration) {
   209  	qs.metadataSummary.allTimes = append(qs.metadataSummary.allTimes, t)
   210  	qs.metadataSummary.totalTime += t
   211  }
   212  
   213  func (qs *QuerySummary) SetRRCFinishTime() {
   214  	qs.rawSearchTime = time.Since(qs.startTime)
   215  }
   216  
   217  func (qs *QuerySummary) UpdateSummary(searchType SearchTypeEnum, ttime time.Duration, queryMetrics *structs.QueryProcessingMetrics) {
   218  	qs.updateLock.Lock()
   219  	qs.numRecordsSearched += queryMetrics.NumRecordsToRawSearch
   220  	qs.numRecordsMatched += queryMetrics.NumRecordsMatched
   221  	qs.totalNumFiles += 1
   222  	qs.updateLock.Unlock()
   223  	qs.updateSearchTime(ttime, qs.allQuerySummaries[searchType])
   224  	qs.updateNumFilesSearched(qs.allQuerySummaries[searchType])
   225  	qs.updateNumMatched(queryMetrics.NumRecordsMatched, qs.allQuerySummaries[searchType])
   226  	qs.updateTotalTime(ttime, qs.allQuerySummaries[searchType])
   227  }
   228  
   229  func (qs *QuerySummary) UpdateRemoteSummary(searchType SearchTypeEnum, ttime time.Duration, numSearched uint64, numMatched uint64) {
   230  	qs.updateLock.Lock()
   231  	qs.numRecordsSearched += numSearched
   232  	qs.numRecordsMatched += numMatched
   233  	qs.remoteRecordsMatched += numMatched
   234  	qs.remoteRecordsSearched += numSearched
   235  	qs.updateLock.Unlock()
   236  	qs.updateSearchTime(ttime, qs.allQuerySummaries[searchType])
   237  	qs.updateNumFilesSearched(qs.allQuerySummaries[searchType])
   238  	qs.updateTotalTime(ttime, qs.allQuerySummaries[searchType])
   239  }
   240  
   241  func (qs *QuerySummary) IncrementNumberDistributedQuery() {
   242  	atomic.AddUint64(&qs.totalDistributedQueries, 1)
   243  }
   244  
   245  func (qs *QuerySummary) UpdateMetricsSummary(queryMetrics *structs.MetricsQueryProcessingMetrics) {
   246  	qs.updateLock.Lock()
   247  	qs.numTSOFilesLoaded += queryMetrics.NumTSOFilesLoaded
   248  	qs.numTSGFilesLoaded += queryMetrics.NumTSGFilesLoaded
   249  	qs.numSeriesSearched += queryMetrics.NumSeriesSearched
   250  	qs.numMetricsSegmentsSearched += queryMetrics.NumMetricsSegmentsSearched
   251  	qs.updateLock.Unlock()
   252  }
   253  
   254  func (qs *QuerySummary) updateSearchTime(ttime time.Duration, searchTypeSummary *searchTypeSummary) {
   255  	qs.updateLock.Lock()
   256  	defer qs.updateLock.Unlock()
   257  	i := sort.Search(len(searchTypeSummary.searchTimeHistory), func(i int) bool { return searchTypeSummary.searchTimeHistory[i] >= ttime })
   258  	searchTypeSummary.searchTimeHistory = append(searchTypeSummary.searchTimeHistory, time.Duration(0))
   259  	copy(searchTypeSummary.searchTimeHistory[i+1:], searchTypeSummary.searchTimeHistory[i:])
   260  	searchTypeSummary.searchTimeHistory[i] = ttime
   261  }
   262  
   263  func (qs *QuerySummary) updateTotalTime(ttime time.Duration, searchTypeSummary *searchTypeSummary) {
   264  	qs.updateLock.Lock()
   265  	defer qs.updateLock.Unlock()
   266  	searchTypeSummary.totalTime += ttime
   267  }
   268  
   269  func (qs *QuerySummary) updateNumFilesSearched(searchTypeSummary *searchTypeSummary) {
   270  	qs.updateLock.Lock()
   271  	defer qs.updateLock.Unlock()
   272  	searchTypeSummary.numFilesSearched += 1
   273  }
   274  
   275  func (qs *QuerySummary) updateNumMatched(numRecs uint64, searchTypeSummary *searchTypeSummary) {
   276  	qs.updateLock.Lock()
   277  	defer qs.updateLock.Unlock()
   278  	searchTypeSummary.numMatched += numRecs
   279  	if !searchTypeSummary.seenOneVal || searchTypeSummary.minPerSegment > numRecs {
   280  		searchTypeSummary.minPerSegment = numRecs
   281  	}
   282  	if !searchTypeSummary.seenOneVal || searchTypeSummary.maxPerSegment < numRecs {
   283  		searchTypeSummary.maxPerSegment = numRecs
   284  	}
   285  	searchTypeSummary.seenOneVal = true
   286  }
   287  
   288  func (qs *QuerySummary) UpdateQueryTotalTime(ttime time.Duration, nBuckets int) {
   289  	qs.updateLock.Lock()
   290  	defer qs.updateLock.Unlock()
   291  	qs.queryTotalTime = ttime
   292  	qs.numBuckets = nBuckets
   293  }
   294  
   295  func (qs *QuerySummary) UpdateTimeGettingRotatedSearchRequests(ttime time.Duration) {
   296  	qs.updateLock.Lock()
   297  	qs.metricsQuerySummary.timeGettingRotatedSearchRequests += ttime
   298  	qs.updateLock.Unlock()
   299  }
   300  
   301  func (qs *QuerySummary) UpdateTimeGettingUnrotatedSearchRequests(ttime time.Duration) {
   302  	qs.updateLock.Lock()
   303  	qs.metricsQuerySummary.timeGettingUnrotatedSearchRequests += ttime
   304  	qs.updateLock.Unlock()
   305  }
   306  
   307  func (qs *QuerySummary) UpdateTimeSearchingTagsTrees(ttime time.Duration) {
   308  	qs.updateLock.Lock()
   309  	defer qs.updateLock.Unlock()
   310  	i := sort.Search(len(qs.metricsQuerySummary.timeSearchingTagsTrees), func(i int) bool { return qs.metricsQuerySummary.timeSearchingTagsTrees[i] >= ttime })
   311  	qs.metricsQuerySummary.timeSearchingTagsTrees = append(qs.metricsQuerySummary.timeSearchingTagsTrees, time.Duration(0))
   312  	copy(qs.metricsQuerySummary.timeSearchingTagsTrees[i+1:], qs.metricsQuerySummary.timeSearchingTagsTrees[i:])
   313  	qs.metricsQuerySummary.timeSearchingTagsTrees[i] = ttime
   314  }
   315  
   316  func (qs *QuerySummary) UpdateTimeLoadingTSOFiles(ttime time.Duration) {
   317  	qs.updateLock.Lock()
   318  	defer qs.updateLock.Unlock()
   319  	i := sort.Search(len(qs.metricsQuerySummary.timeLoadingTSOFiles), func(i int) bool { return qs.metricsQuerySummary.timeLoadingTSOFiles[i] >= ttime })
   320  	qs.metricsQuerySummary.timeLoadingTSOFiles = append(qs.metricsQuerySummary.timeLoadingTSOFiles, time.Duration(0))
   321  	copy(qs.metricsQuerySummary.timeLoadingTSOFiles[i+1:], qs.metricsQuerySummary.timeLoadingTSOFiles[i:])
   322  	qs.metricsQuerySummary.timeLoadingTSOFiles[i] = ttime
   323  }
   324  
   325  func (qs *QuerySummary) UpdateTimeLoadingTSGFiles(ttime time.Duration) {
   326  	qs.updateLock.Lock()
   327  	defer qs.updateLock.Unlock()
   328  	i := sort.Search(len(qs.metricsQuerySummary.timeLoadingTSGFiles), func(i int) bool { return qs.metricsQuerySummary.timeLoadingTSGFiles[i] >= ttime })
   329  	qs.metricsQuerySummary.timeLoadingTSGFiles = append(qs.metricsQuerySummary.timeLoadingTSGFiles, time.Duration(0))
   330  	copy(qs.metricsQuerySummary.timeLoadingTSGFiles[i+1:], qs.metricsQuerySummary.timeLoadingTSGFiles[i:])
   331  	qs.metricsQuerySummary.timeLoadingTSGFiles[i] = ttime
   332  }
   333  
   334  func (qs *QuerySummary) getTotalTime(searchType SearchTypeEnum) time.Duration {
   335  	qs.updateLock.Lock()
   336  	defer qs.updateLock.Unlock()
   337  	return qs.allQuerySummaries[searchType].totalTime
   338  }
   339  
   340  func (qs *QuerySummary) getQueryTotalTime() time.Duration {
   341  	qs.updateLock.Lock()
   342  	defer qs.updateLock.Unlock()
   343  	return qs.queryTotalTime
   344  }
   345  
   346  func (qs *QuerySummary) getMinSearchTime(searchType SearchTypeEnum) float64 {
   347  	qs.updateLock.Lock()
   348  	defer qs.updateLock.Unlock()
   349  	return getMinSearchTimeFromArr(qs.allQuerySummaries[searchType].searchTimeHistory)
   350  }
   351  
   352  func getMinSearchTimeFromArr(arr []time.Duration) float64 {
   353  	if len(arr) > 0 {
   354  		ret := float64(arr[0] / time.Nanosecond)
   355  		return ret / 1000_000
   356  	}
   357  	return 0
   358  }
   359  
   360  func (qs *QuerySummary) getMaxSearchTime(searchType SearchTypeEnum) float64 {
   361  	qs.updateLock.Lock()
   362  	defer qs.updateLock.Unlock()
   363  	return getMaxSearchTimeFromArr(qs.allQuerySummaries[searchType].searchTimeHistory)
   364  }
   365  
   366  func getMaxSearchTimeFromArr(arr []time.Duration) float64 {
   367  	if len(arr) > 0 {
   368  		ret := float64(arr[len(arr)-1]) / float64(time.Nanosecond)
   369  		return ret / 1000_000
   370  	}
   371  	return 0
   372  }
   373  
   374  func getSumSearchTimeFromArr(arr []time.Duration) float64 {
   375  	sum := float64(0)
   376  	for _, num := range arr {
   377  		sum += float64(num) / float64(time.Nanosecond)
   378  	}
   379  	return sum / 1000_000
   380  }
   381  
   382  func (qs *QuerySummary) getSearchTimeHistory(searchType SearchTypeEnum) []float64 {
   383  	qs.updateLock.Lock()
   384  	defer qs.updateLock.Unlock()
   385  	retval := make([]float64, len(qs.allQuerySummaries[searchType].searchTimeHistory))
   386  	for i, val := range qs.allQuerySummaries[searchType].searchTimeHistory {
   387  		val := float64(val.Nanoseconds()) / 1000_000 // convert nano to ms
   388  		ratio := math.Pow(10, float64(3))            // round up to 3 decimal places
   389  		retval[i] = math.Round(val*ratio) / ratio
   390  	}
   391  	return retval
   392  }
   393  
   394  func (qs *QuerySummary) getPercentileTime(percent float64, searchType SearchTypeEnum) float64 {
   395  	qs.updateLock.Lock()
   396  	defer qs.updateLock.Unlock()
   397  	return getPercentileTimeFromArr(percent, qs.allQuerySummaries[searchType].searchTimeHistory)
   398  }
   399  
   400  func getPercentileTimeFromArr(percent float64, arr []time.Duration) float64 {
   401  	ret := float64(percentile(arr, percent)) / float64(time.Nanosecond)
   402  	return ret / 1000_000
   403  }
   404  
   405  func (qs *QuerySummary) getNumFilesSearched(searchType SearchTypeEnum) uint64 {
   406  	qs.updateLock.Lock()
   407  	numFilesSearched := qs.allQuerySummaries[searchType].numFilesSearched
   408  	qs.updateLock.Unlock()
   409  	return numFilesSearched
   410  }
   411  
   412  func (qs *QuerySummary) getTotNumFilesSearched() uint64 {
   413  	qs.updateLock.Lock()
   414  	totalNumFiles := qs.totalNumFiles
   415  	qs.updateLock.Unlock()
   416  	return totalNumFiles
   417  }
   418  
   419  func (qs *QuerySummary) getNumBuckets() int {
   420  	qs.updateLock.Lock()
   421  	numBuckets := qs.numBuckets
   422  	qs.updateLock.Unlock()
   423  	return numBuckets
   424  }
   425  
   426  func (qs *QuerySummary) getNumRecordsMatched(searchType SearchTypeEnum) uint64 {
   427  	qs.updateLock.Lock()
   428  	numMatched := qs.allQuerySummaries[searchType].numMatched
   429  	qs.updateLock.Unlock()
   430  	return numMatched
   431  }
   432  
   433  func (qs *QuerySummary) getTotNumRecordsMatched() uint64 {
   434  	qs.updateLock.Lock()
   435  	numRecordsMatched := qs.numRecordsMatched
   436  	qs.updateLock.Unlock()
   437  	return numRecordsMatched
   438  }
   439  
   440  func (qs *QuerySummary) getTotNumRecordsSearched() uint64 {
   441  	qs.updateLock.Lock()
   442  	numRecordsSearched := qs.numRecordsSearched
   443  	qs.updateLock.Unlock()
   444  	return numRecordsSearched
   445  }
   446  
   447  func (qs *QuerySummary) getNumMetricsSegmentsSearched() uint64 {
   448  	qs.updateLock.Lock()
   449  	numMetricsSegmentsSearched := qs.numMetricsSegmentsSearched
   450  	qs.updateLock.Unlock()
   451  	return numMetricsSegmentsSearched
   452  }
   453  
   454  func (qs *QuerySummary) getNumTSIDsMatched() uint64 {
   455  	qs.updateLock.Lock()
   456  	numTSIDsMatched := qs.numTSIDsMatched
   457  	qs.updateLock.Unlock()
   458  	return numTSIDsMatched
   459  }
   460  
   461  func (qs *QuerySummary) getNumTagsTreesSearched() uint64 {
   462  	qs.updateLock.Lock()
   463  	numTagsTreesSearched := qs.numTagsTreesSearched
   464  	qs.updateLock.Unlock()
   465  	return numTagsTreesSearched
   466  }
   467  
   468  func (qs *QuerySummary) getNumTSOFilesLoaded() uint64 {
   469  	qs.updateLock.Lock()
   470  	numTSOFilesLoaded := qs.numTSOFilesLoaded
   471  	qs.updateLock.Unlock()
   472  	return numTSOFilesLoaded
   473  }
   474  
   475  func (qs *QuerySummary) getNumTSGFilesLoaded() uint64 {
   476  	qs.updateLock.Lock()
   477  	numTSGFilesLoaded := qs.numTSGFilesLoaded
   478  	qs.updateLock.Unlock()
   479  	return numTSGFilesLoaded
   480  }
   481  
   482  func (qs *QuerySummary) getNumSeriesSearched() uint64 {
   483  	qs.updateLock.Lock()
   484  	numSeriesSearched := qs.numSeriesSearched
   485  	qs.updateLock.Unlock()
   486  	return numSeriesSearched
   487  }
   488  
   489  func (qs *QuerySummary) getNumResultSeries() uint64 {
   490  	qs.updateLock.Lock()
   491  	numResultSeries := qs.numResultSeries
   492  	qs.updateLock.Unlock()
   493  	return numResultSeries
   494  }
   495  
   496  func (qs *QuerySummary) getNumRecordsMatchedMinMax(searchType SearchTypeEnum) (uint64, uint64) {
   497  	qs.updateLock.Lock()
   498  	minPerSegment, maxPerSegment := qs.allQuerySummaries[searchType].minPerSegment, qs.allQuerySummaries[searchType].maxPerSegment
   499  	qs.updateLock.Unlock()
   500  	return minPerSegment, maxPerSegment
   501  }
   502  
   503  func (qs *QuerySummary) LogSummaryAndEmitMetrics(qid uint64, pqid string, containsKibana bool, orgid uint64) {
   504  
   505  	sort.Slice(qs.metadataSummary.allTimes, func(i, j int) bool {
   506  		return qs.metadataSummary.allTimes[i] < qs.metadataSummary.allTimes[j]
   507  	})
   508  
   509  	log.Warnf("qid=%d, pqid %v, QuerySummary: Finished in  %+vms time. Total number of records searched %+v. Total number of records matched=%+v. Total number of files searched=%+v. Total number of buckets created=%+v",
   510  		qs.qid, pqid, qs.getQueryTotalTime().Milliseconds(), qs.getTotNumRecordsSearched(), qs.getTotNumRecordsMatched(), qs.getTotNumFilesSearched(), qs.getNumBuckets())
   511  
   512  	avgCmiTime := float64(qs.metadataSummary.totalTime.Milliseconds()) / float64(len(qs.metadataSummary.allTimes))
   513  
   514  	log.Warnf("qid=%d, pqid %v, QuerySummary: CMI layer checked %+v total blocks, and %+v blocks passed. Total time: %+vms. min (%+vms) max (%+vms) avg (%vms) p95 (%+vms)", qs.qid, pqid,
   515  		qs.metadataSummary.numCMIBlocksChecked,
   516  		qs.metadataSummary.numCMIBlocksPassed,
   517  		float64(qs.metadataSummary.totalTime)/float64(time.Millisecond),
   518  		getMinSearchTimeFromArr(qs.metadataSummary.allTimes),
   519  		getMaxSearchTimeFromArr(qs.metadataSummary.allTimes),
   520  		avgCmiTime,
   521  		getPercentileTimeFromArr(95, qs.metadataSummary.allTimes))
   522  
   523  	log.Warnf("qid=%d, pqid %v, QuerySummary: RawSearch: Took %+vms time, after searching %+v files. RRCs were generated in %+vms", qs.qid,
   524  		pqid, qs.getTotalTime(RAW).Milliseconds(), qs.getNumFilesSearched(RAW), qs.rawSearchTime.Milliseconds())
   525  
   526  	if !containsKibana {
   527  		instrumentation.SetQueryLatencyMs(int64(qs.getQueryTotalTime()/1_000_000), "pqid", pqid)
   528  		instrumentation.SetEventsSearchedGauge(int64(qs.getTotNumRecordsSearched()))
   529  		instrumentation.SetEventsMatchedGauge(int64(qs.getTotNumRecordsMatched()))
   530  	}
   531  
   532  	if len(qs.allQuerySummaries[RAW].searchTimeHistory) <= 25 {
   533  		log.Warnf("qid=%d, pqid %v, QuerySummary: RawSearch: Search Time History across all files %vms",
   534  			qs.qid, pqid, qs.getSearchTimeHistory(RAW))
   535  	}
   536  
   537  	if qs.getTotNumFilesSearched() > 0 {
   538  		avgTime := uint64((qs.getTotalTime(RAW)).Milliseconds() / int64(qs.getTotNumFilesSearched()))
   539  		log.Warnf("qid=%d, pqid %v, QuerySummary: RawSearch: File raw search time: min (%+vms) max (%+vms) avg (%vms) p95 (%+vms)",
   540  			qs.qid, pqid, qs.getMinSearchTime(RAW), qs.getMaxSearchTime(RAW), avgTime,
   541  			qs.getPercentileTime(95, RAW))
   542  
   543  		if !containsKibana {
   544  			instrumentation.SetSegmentLatencyMinMs(int64(qs.getMinSearchTime(RAW)), "pqid", pqid)
   545  			instrumentation.SetSegmentLatencyMaxMs(int64(qs.getMaxSearchTime(RAW)), "pqid", pqid)
   546  			instrumentation.SetSegmentLatencyAvgMs(int64(int64(avgTime)), "pqid", pqid)
   547  			instrumentation.SetSegmentLatencyP95Ms(int64(qs.getPercentileTime(95, RAW)), "pqid", pqid)
   548  		}
   549  
   550  	}
   551  	min, max := qs.getNumRecordsMatchedMinMax(RAW)
   552  	log.Warnf("qid=%d, pqid %v, QuerySummary: RawSearch: Number of records matched %d, min/segment (%v) max/segment (%v)", qs.qid, pqid, qs.getNumRecordsMatched(RAW), min, max)
   553  
   554  	if config.IsPQSEnabled() {
   555  		log.Warnf("qid=%d, pqid %v, QuerySummary: PQS: Finished in %+vms time, after searching %+v files",
   556  			qs.qid, pqid, qs.getTotalTime(PQS).Milliseconds(), qs.getNumFilesSearched(PQS))
   557  
   558  		if len(qs.allQuerySummaries[PQS].searchTimeHistory) <= 25 {
   559  			log.Warnf("qid=%d, pqid %v, QuerySummary: PQS: Search Time History across all files %vms",
   560  				qs.qid, pqid, qs.getSearchTimeHistory(PQS))
   561  		}
   562  		if qs.getTotNumFilesSearched() > 0 {
   563  			avgTime := float64((qs.getTotalTime(PQS)).Milliseconds() / int64(qs.getTotNumFilesSearched()))
   564  			log.Warnf("qid=%d, pqid %v, QuerySummary: PQS: File raw search time: min (%+v) max (%+v) avg (%vms) p95 (%+v)",
   565  				qs.qid, pqid, qs.getMinSearchTime(PQS),
   566  				qs.getMaxSearchTime(PQS), avgTime, qs.getPercentileTime(95, PQS))
   567  		}
   568  		min, max = qs.getNumRecordsMatchedMinMax(PQS)
   569  		log.Warnf("qid=%d, pqid %v, QuerySummary: PQS: Number of records matched %d, min/segment (%v) max/segment (%v) ",
   570  			qs.qid, pqid, qs.getNumRecordsMatched(PQS), min, max)
   571  	}
   572  
   573  	if len(qs.allQuerySummaries[STREE].searchTimeHistory) > 0 {
   574  
   575  		if len(qs.allQuerySummaries[STREE].searchTimeHistory) <= 25 {
   576  			log.Warnf("qid=%d, pqid %v, QuerySummary: STREE: Search Time History for files %vms",
   577  				qs.qid, pqid, qs.getSearchTimeHistory(STREE))
   578  		}
   579  		avgNs := qs.getTotalTime(STREE).Nanoseconds() / int64(qs.getTotNumFilesSearched())
   580  		avgTime := float64(avgNs) / 1000_000 // nano to millis
   581  		log.Warnf("qid=%d, pqid %v, QuerySummary: STREE: File search times: min (%+vms) max (%+vms) avg (%vms) p95 (%+vms), numFiles: %v, numRecsMatched: %v",
   582  			qs.qid, pqid, qs.getMinSearchTime(STREE), qs.getMaxSearchTime(STREE), avgTime,
   583  			qs.getPercentileTime(95, STREE), qs.getNumFilesSearched(STREE),
   584  			qs.getNumRecordsMatched(STREE))
   585  	}
   586  
   587  	if qs.totalDistributedQueries > 0 {
   588  		log.Warnf("qid=%d, pqid %v, QuerySummary: Distributed: Sent %d requests numRemoteMatched: %v, numRecsSearced: %v",
   589  			qs.qid, pqid, qs.totalDistributedQueries, qs.remoteRecordsMatched, qs.remoteRecordsSearched)
   590  		log.Warnf("qid=%d, pqid %v, QuerySummary: Unrotated.GRPC Search times: min (%+vms) max (%+vms) p95 (%+vms), numGRPCs: %v",
   591  			qs.qid, pqid, qs.getMinSearchTime(GRPC_UNROTATED), qs.getMaxSearchTime(GRPC_UNROTATED),
   592  			qs.getPercentileTime(95, GRPC_UNROTATED), qs.getNumFilesSearched(GRPC_UNROTATED))
   593  		log.Warnf("qid=%d, pqid %v, QuerySummary: Rotated.GRPC Search times: min (%+vms) max (%+vms) p95 (%+vms), numGRPCs: %v",
   594  			qs.qid, pqid, qs.getMinSearchTime(GRPC_ROTATED), qs.getMaxSearchTime(GRPC_ROTATED),
   595  			qs.getPercentileTime(95, GRPC_ROTATED), qs.getNumFilesSearched(GRPC_ROTATED))
   596  	}
   597  
   598  	uStats.UpdateQueryStats(1, float64(qs.getQueryTotalTime().Milliseconds()), orgid)
   599  	qs.stopTicker()
   600  }
   601  
   602  func (qs *QuerySummary) LogMetricsQuerySummary(orgid uint64) {
   603  	log.Warnf("qid=%d, MetricsQuerySummary: Finished in %+vms time. Searched a total of %+v TSIDs. Total number of series searched=%+v. Returned number of series=%+v",
   604  		qs.qid, time.Since(qs.startTime).Milliseconds(), qs.getNumTSIDsMatched(), qs.getNumSeriesSearched(), qs.getNumResultSeries())
   605  	log.Warnf("qid=%d, MetricsQuerySummary: Time taken to get rotated search requests=%+vms. Time taken to get unrotated search requests=%+vms. Total number of metrics segments searched=%+v.",
   606  		qs.qid, qs.metricsQuerySummary.timeGettingRotatedSearchRequests.Microseconds(),
   607  		qs.metricsQuerySummary.timeGettingUnrotatedSearchRequests.Microseconds(), qs.getNumMetricsSegmentsSearched())
   608  
   609  	avgTimeSearchingTagsTrees := getSumSearchTimeFromArr(qs.metricsQuerySummary.timeSearchingTagsTrees) / float64(qs.numTagsTreesSearched)
   610  	avgTimeLoadingTSOFiles := getSumSearchTimeFromArr(qs.metricsQuerySummary.timeLoadingTSOFiles) / float64(qs.numTSOFilesLoaded)
   611  	avgTimeLoadingTSGFiles := getSumSearchTimeFromArr(qs.metricsQuerySummary.timeLoadingTSGFiles) / float64(qs.numTSGFilesLoaded)
   612  
   613  	log.Warnf("qid=%d, MetricsQuerySummary: Across %d TagsTree Files: min (%.3fms) max (%.3fms) avg (%.3fms) p95(%.3fms)", qs.qid, qs.getNumTagsTreesSearched(), getMinSearchTimeFromArr(qs.metricsQuerySummary.timeSearchingTagsTrees), getMaxSearchTimeFromArr(qs.metricsQuerySummary.timeSearchingTagsTrees), avgTimeSearchingTagsTrees, getPercentileTimeFromArr(95, qs.metricsQuerySummary.timeSearchingTagsTrees))
   614  	log.Warnf("qid=%d, MetricsQuerySummary: Across %d TSO Files: min (%.3fms) max (%.3fms) avg (%.3fms) p95(%.3fms)", qs.qid, qs.getNumTSOFilesLoaded(), getMinSearchTimeFromArr(qs.metricsQuerySummary.timeLoadingTSOFiles), getMaxSearchTimeFromArr(qs.metricsQuerySummary.timeLoadingTSOFiles), avgTimeLoadingTSOFiles, getPercentileTimeFromArr(95, qs.metricsQuerySummary.timeLoadingTSOFiles))
   615  	log.Warnf("qid=%d, MetricsQuerySummary: Across %d TSG Files: min (%.3fms) max (%.3fms) avg (%.3fms) p95(%.3fms)", qs.qid, qs.getNumTSGFilesLoaded(), getMinSearchTimeFromArr(qs.metricsQuerySummary.timeLoadingTSGFiles), getMaxSearchTimeFromArr(qs.metricsQuerySummary.timeLoadingTSGFiles), avgTimeLoadingTSGFiles, getPercentileTimeFromArr(95, qs.metricsQuerySummary.timeLoadingTSGFiles))
   616  
   617  	uStats.UpdateQueryStats(1, float64(qs.getQueryTotalTime().Milliseconds()), orgid)
   618  	qs.stopTicker()
   619  }
   620  
   621  func (qs *QuerySummary) UpdateRemainingDistributedQueries(remainingDistributedQueries uint64) {
   622  	qs.updateLock.Lock()
   623  	qs.remainingDistributedQueries = remainingDistributedQueries
   624  	qs.updateLock.Unlock()
   625  }
   626  
   627  func percentile(input []time.Duration, percent float64) (percentile time.Duration) {
   628  	length := len(input)
   629  	if length == 0 {
   630  		return time.Duration(0)
   631  	}
   632  	if length == 1 {
   633  		return input[0]
   634  	}
   635  	if percent <= 0 || percent > 100 {
   636  		return time.Duration(0)
   637  	}
   638  	// Multiply percent by length of input
   639  	index := (percent / 100) * float64(len(input))
   640  	// Check if the index is a whole number
   641  	if index == float64(int64(index)) {
   642  		// Convert float to int
   643  		i := int(index)
   644  		// Find the value at the index
   645  		percentile = input[i-1]
   646  	} else if index > 1 {
   647  		// Convert float to int via truncation
   648  		i := int(index)
   649  		// Find the average of the index and following values
   650  		percentile = (input[i-1] + input[i]) / 2
   651  	} else {
   652  		return time.Duration(0)
   653  	}
   654  	return percentile
   655  }