prometheus/promql/query_logger.go
Tobias Klausmann b998636893
Improve error logging for missing config and QL dir (#10260)
* Improve error logging for missing config and QL dir

Currently, when Prometheus can't open its config file or the query
logging dir under the data dir, it only logs what it has been given
default or commandline/config. Depending on the environment this can be
less than helpful, since the working directory may be unclear to the
user. I have specifically kept the existing error messages as intact as
possible to a) still log the parameter as given and b) cause as little
disruption for log-parsers/-analyzers as possible.

So in case of the config file or the data dir being non-absolute paths,
I use os.GetWd to find the working dir and assemble an absolute path for
error logging purposes. If GetWd fails, we just log "unknown", as
recovering from an error there would be very complex measure, likely not
worth the code/effort.

Example errors:

```
$ ./prometheus
ts=2022-02-06T16:00:53.034Z caller=main.go:445 level=error msg="Error loading config (--config.file=prometheus.yml)" fullpath=/home/klausman/src/prometheus/prometheus.yml err="open prometheus.yml: no such file or directory"
$ touch prometheus.yml
$ ./prometheus
[...]
ts=2022-02-06T16:01:00.992Z caller=query_logger.go:99 level=error component=activeQueryTracker msg="Error opening query log file" file=data/queries.active fullpath=/home/klausman/src/prometheus/data/queries.active err="open data/queries.active: permission denied"
panic: Unable to create mmap-ed active query log
[...]
$
```

Signed-off-by: Tobias Klausmann <klausman@schwarzvogel.de>

* Replace our own logic with just using filepath.Abs()

Signed-off-by: Tobias Klausmann <klausman@schwarzvogel.de>

* Further simplification

Signed-off-by: Tobias Klausmann <klausman@schwarzvogel.de>

* Review edits

Signed-off-by: Tobias Klausmann <klausman@schwarzvogel.de>

* Review edits

Signed-off-by: Tobias Klausmann <klausman@schwarzvogel.de>

* Review edits

Signed-off-by: Tobias Klausmann <klausman@schwarzvogel.de>
2022-02-16 17:43:15 +01:00

200 lines
5.2 KiB
Go

// Copyright 2019 The Prometheus Authors
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package promql
import (
"context"
"encoding/json"
"os"
"path/filepath"
"strings"
"time"
"unicode/utf8"
"github.com/edsrzf/mmap-go"
"github.com/go-kit/log"
"github.com/go-kit/log/level"
)
type ActiveQueryTracker struct {
mmapedFile []byte
getNextIndex chan int
logger log.Logger
maxConcurrent int
}
type Entry struct {
Query string `json:"query"`
Timestamp int64 `json:"timestamp_sec"`
}
const (
entrySize int = 1000
)
func parseBrokenJSON(brokenJSON []byte) (string, bool) {
queries := strings.ReplaceAll(string(brokenJSON), "\x00", "")
if len(queries) > 0 {
queries = queries[:len(queries)-1] + "]"
}
// Conditional because of implementation detail: len() = 1 implies file consisted of a single char: '['.
if len(queries) <= 1 {
return "[]", false
}
return queries, true
}
func logUnfinishedQueries(filename string, filesize int, logger log.Logger) {
if _, err := os.Stat(filename); err == nil {
fd, err := os.Open(filename)
if err != nil {
level.Error(logger).Log("msg", "Failed to open query log file", "err", err)
return
}
brokenJSON := make([]byte, filesize)
_, err = fd.Read(brokenJSON)
if err != nil {
level.Error(logger).Log("msg", "Failed to read query log file", "err", err)
return
}
queries, queriesExist := parseBrokenJSON(brokenJSON)
if !queriesExist {
return
}
level.Info(logger).Log("msg", "These queries didn't finish in prometheus' last run:", "queries", queries)
}
}
func getMMapedFile(filename string, filesize int, logger log.Logger) ([]byte, error) {
file, err := os.OpenFile(filename, os.O_CREATE|os.O_RDWR|os.O_TRUNC, 0o666)
if err != nil {
absPath, pathErr := filepath.Abs(filename)
if pathErr != nil {
absPath = filename
}
level.Error(logger).Log("msg", "Error opening query log file", "file", absPath, "err", err)
return nil, err
}
err = file.Truncate(int64(filesize))
if err != nil {
level.Error(logger).Log("msg", "Error setting filesize.", "filesize", filesize, "err", err)
return nil, err
}
fileAsBytes, err := mmap.Map(file, mmap.RDWR, 0)
if err != nil {
level.Error(logger).Log("msg", "Failed to mmap", "file", filename, "Attempted size", filesize, "err", err)
return nil, err
}
return fileAsBytes, err
}
func NewActiveQueryTracker(localStoragePath string, maxConcurrent int, logger log.Logger) *ActiveQueryTracker {
err := os.MkdirAll(localStoragePath, 0o777)
if err != nil {
level.Error(logger).Log("msg", "Failed to create directory for logging active queries")
}
filename, filesize := filepath.Join(localStoragePath, "queries.active"), 1+maxConcurrent*entrySize
logUnfinishedQueries(filename, filesize, logger)
fileAsBytes, err := getMMapedFile(filename, filesize, logger)
if err != nil {
panic("Unable to create mmap-ed active query log")
}
copy(fileAsBytes, "[")
activeQueryTracker := ActiveQueryTracker{
mmapedFile: fileAsBytes,
getNextIndex: make(chan int, maxConcurrent),
logger: logger,
maxConcurrent: maxConcurrent,
}
activeQueryTracker.generateIndices(maxConcurrent)
return &activeQueryTracker
}
func trimStringByBytes(str string, size int) string {
bytesStr := []byte(str)
trimIndex := len(bytesStr)
if size < len(bytesStr) {
for !utf8.RuneStart(bytesStr[size]) {
size--
}
trimIndex = size
}
return string(bytesStr[:trimIndex])
}
func _newJSONEntry(query string, timestamp int64, logger log.Logger) []byte {
entry := Entry{query, timestamp}
jsonEntry, err := json.Marshal(entry)
if err != nil {
level.Error(logger).Log("msg", "Cannot create json of query", "query", query)
return []byte{}
}
return jsonEntry
}
func newJSONEntry(query string, logger log.Logger) []byte {
timestamp := time.Now().Unix()
minEntryJSON := _newJSONEntry("", timestamp, logger)
query = trimStringByBytes(query, entrySize-(len(minEntryJSON)+1))
jsonEntry := _newJSONEntry(query, timestamp, logger)
return jsonEntry
}
func (tracker ActiveQueryTracker) generateIndices(maxConcurrent int) {
for i := 0; i < maxConcurrent; i++ {
tracker.getNextIndex <- 1 + (i * entrySize)
}
}
func (tracker ActiveQueryTracker) GetMaxConcurrent() int {
return tracker.maxConcurrent
}
func (tracker ActiveQueryTracker) Delete(insertIndex int) {
copy(tracker.mmapedFile[insertIndex:], strings.Repeat("\x00", entrySize))
tracker.getNextIndex <- insertIndex
}
func (tracker ActiveQueryTracker) Insert(ctx context.Context, query string) (int, error) {
select {
case i := <-tracker.getNextIndex:
fileBytes := tracker.mmapedFile
entry := newJSONEntry(query, tracker.logger)
start, end := i, i+entrySize
copy(fileBytes[start:], entry)
copy(fileBytes[end-1:], ",")
return i, nil
case <-ctx.Done():
return 0, ctx.Err()
}
}