Merge pull request #35 from grafana/add-query-frontend-parse

Adding logtool

Author: mattmendick

.gitignore

@@ -1,5 +1,6 @@
 cmd/cortextool/cortextool
 cmd/chunktool/chunktool
+cmd/logtool/logtool
 .uptodate
 .pkg
 .cache

Makefile

@@ -7,10 +7,11 @@ GIT_REVISION := $(shell git rev-parse --short HEAD)
 GIT_BRANCH := $(shell git rev-parse --abbrev-ref HEAD)
 GO_FLAGS := -mod=vendor -ldflags "-extldflags \"-static\" -s -w -X $(VPREFIX).Branch=$(GIT_BRANCH) -X $(VPREFIX).Version=$(IMAGE_TAG) -X $(VPREFIX).Revision=$(GIT_REVISION)" -tags netgo
 
-all: cortextool chunktool
-images: cortextool-image chunktool-image
+all: cortextool chunktool logtool
+images: cortextool-image chunktool-image logtool-image
 cortextool: cmd/cortextool/cortextool
 chunktool: cmd/chunktool/chunktool
+logtool: cmd/logtool/logtool
 
 cortextool-image:
 	$(SUDO) docker build -t $(IMAGE_PREFIX)/cortextool -f cmd/cortextool/Dockerfile .
@@ -20,22 +21,31 @@ chunktool-image:
 	$(SUDO) docker build -t $(IMAGE_PREFIX)/chunktool -f cmd/chunktool/Dockerfile .
 	$(SUDO) docker tag $(IMAGE_PREFIX)/chunktool $(IMAGE_PREFIX)/chunktool:$(IMAGE_TAG)
 
+logtool-image:
+	$(SUDO) docker build -t $(IMAGE_PREFIX)/logtool -f cmd/logtool/Dockerfile .
+	$(SUDO) docker tag $(IMAGE_PREFIX)/logtool $(IMAGE_PREFIX)/logtool:$(IMAGE_TAG)
+
 cmd/cortextool/cortextool: $(APP_GO_FILES) cmd/cortextool/main.go
 	CGO_ENABLED=0 go build $(GO_FLAGS) -o $@ ./$(@D)
 
 cmd/chunktool/chunktool: $(APP_GO_FILES) cmd/chunktool/main.go
 	CGO_ENABLED=0 go build $(GO_FLAGS) -o $@ ./$(@D)
 
+cmd/logtool/logtool: $(APP_GO_FILES) cmd/logtool/main.go
+	CGO_ENABLED=0 go build $(GO_FLAGS) -o $@ ./$(@D)
+
 lint:
 	golangci-lint run -v
 
 cross:
 	CGO_ENABLED=0 gox -output="dist/{{.Dir}}-{{.OS}}-{{.Arch}}" -ldflags=${LDFLAGS} -arch="amd64" -os="linux windows darwin" ./cmd/cortextool
 	CGO_ENABLED=0 gox -output="dist/{{.Dir}}-{{.OS}}-{{.Arch}}" -ldflags=${LDFLAGS} -arch="amd64" -os="linux windows darwin" ./cmd/chunktool
+	CGO_ENABLED=0 gox -output="dist/{{.Dir}}-{{.OS}}-{{.Arch}}" -ldflags=${LDFLAGS} -arch="amd64" -os="linux windows darwin" ./cmd/logtool
 
 test:
 	go test -mod=vendor -p=8 ./...
 
 clean:
 	rm -rf cmd/cortextool/cortextool
 	rm -rf cmd/chunktool/chunktool
+	rm -rf cmd/logtool/logtool

README.md

@@ -1,60 +1,68 @@
-# cortextool
+# Cortex Tools
 
-This tool is designed to interact with the various user facing APIs provided by Cortex, as well as, interact with various backend storage components containing Cortex data.
+This repo contains tools used for interacting with [Cortex](https://github.com/cortexproject/cortex).
 
-## Config Commands
+* [cortextool](#cortextool): Interacts with user-facing Cortex APIs and backend storage components
+* [chunktool](#chunktool): Interacts with chunks stored and indexed in Cortex storage backends.
+* [logtool](#logtool): Tool which parses Cortex query-frontend logs and formats them for easy analysis.
+
+## cortextool
+
+This tool is designed to interact with the various user-facing APIs provided by Cortex, as well as, interact with various backend storage components containing Cortex data.
+
+### Config Commands
 
 Config commands interact with the Cortex api and read/create/update/delete user configs from Cortex. Specifically a users alertmanager and rule configs can be composed and updated using these commands.
 
-### Configuration
+#### Configuration
 
 | Env Variables     | Flag      | Description                                                                                                   |
 | ----------------- | --------- | ------------------------------------------------------------------------------------------------------------- |
 | CORTEX_ADDRESS    | `address` | Addess of the API of the desired Cortex cluster.                                                              |
 | CORTEX_API_KEY    | `key`     | In cases where the Cortex API is set behind a basic auth gateway, an key can be set as a basic auth password. |
 | CORTEX_TENANT_ID | `id`      | The tenant ID of the Cortex instance to interact with.                                                        |
 
-### Alertmanager
+#### Alertmanager
 
 The following commands are used by users to interact with their Cortex alertmanager configuration, as well as their alert template files.
 
-#### Alertmanager Get
+##### Alertmanager Get
 
     cortextool alertmanager get
 
-#### Alertmanager Load
+##### Alertmanager Load
 
     cortextool alertmanager load ./example_alertmanager_config.yaml
 
-### Rules
+#### Rules
 
 The following commands are used by users to interact with their Cortex ruler configuration. They can load prometheus rule files, as well as interact with individual rule groups.
 
-#### Rules List
+##### Rules List
 
 This command will retrieve all of the rule groups stored in the specified Cortex instance and print each one by rule group name and namespace to the terminal.
 
     cortextool rules list
 
-#### Rules Print
+##### Rules Print
 
 This command will retrieve all of the rule groups stored in the specified Cortex instance and print them to the terminal.
 
     cortextool rules print
 
-#### Rules Get
+##### Rules Get
 
 This command will retrieve the specified rule group from Cortex and print it to the terminal.
 
     cortextool rules get example_namespace example_rule_group
 
-#### Rules Delete
+##### Rules Delete
 
 This command will retrieve the specified rule group from Cortex and print it to the terminal.
 
     cortextool rules delete example_namespace example_rule_group
 
-#### Rules Load
+##### Rules Load
 
 This command will load each rule group in the specified files and load them into Cortex. If a rule already exists in Cortex it will be overwritten if a diff is found.
 
@@ -82,21 +90,58 @@ At the end of the run, the command tells you whenever the operation was a succes
 
 It is important to note that a modification can be a PromQL expression lint or a label add to your aggregation.
 
-# chunktool
+## chunktool
 
 This repo also contains the `chunktool`. A client meant to interact with chunks stored and indexed in cortex backends.
 
-### Chunk Delete
+##### Chunk Delete
 
 The delete command currently cleans all index entries pointing to chunks in the specified index. Only bigtable and the v10 schema are currently fully supported. This will not delete the entire index entry, only the corresponding chunk entries within the index row.
 
-### Chunk Migrate
+##### Chunk Migrate
 
 The migrate command helps with migrating chunks across cortex clusters. It also takes care of setting right index in the new cluster as per the specified schema config.
 
 As of now it only supports `Bigtable` or `GCS` as a source to read chunks from for migration while for writing it supports all the storages that Cortex supports.
 More details about it [here](./pkg/chunk/migrate/README.md)
 
-## License
+## logtool
+
+A CLI tool to parse Cortex query-frontend logs and formats them for easy analysis.
+
+```
+Options:
+  -dur duration
+        only show queries which took longer than this duration, e.g. -dur 10s
+  -query
+        show the query
+  -utc
+        show timestamp in UTC time
+```
+
+Feed logs into it using [`logcli`](https://github.com/grafana/loki/blob/master/docs/getting-started/logcli.md) from Loki, [`kubectl`](https://kubernetes.io/docs/reference/kubectl/overview/) for Kubernetes, `cat` from a file, or any other way to get raw logs:
+
+Loki `logcli` example:
+```
+$ logcli query '{cluster="us-central1", name="query-frontend", namespace="dev"}' --limit=5000 --since=3h --forward -o raw | ./logtool -dur 5s
+https://logs-dev-ops-tools1.grafana.net/loki/api/v1/query_range?direction=FORWARD&end=1591119479093405000&limit=5000&query=%7Bcluster%3D%22us-central1%22%2C+name%3D%22query-frontend%22%2C+namespace%3D%22dev%22%7D&start=1591108679093405000
+Common labels: {cluster="us-central1", container_name="query-frontend", job="dev/query-frontend", level="debug", name="query-frontend", namespace="dev", pod_template_hash="7cd4bf469d", stream="stderr"}
+
+Timestamp                                TraceID           Length    Duration       Status  Path
+2020-06-02 10:38:40.34205349 -0400 EDT   1f2533b40f7711d3  12h0m0s   21.92465802s   (200)   /api/prom/api/v1/query_range
+2020-06-02 10:40:25.171649132 -0400 EDT  2ac59421db0000d8  168h0m0s  16.378698276s  (200)   /api/prom/api/v1/query_range
+2020-06-02 10:40:29.698167258 -0400 EDT  3fd088d900160ba8  168h0m0s  20.912864541s  (200)   /api/prom/api/v1/query_range
+```
+
+```
+$ cat query-frontend-logs.log | ./logtool -dur 5s
+Timestamp                                TraceID           Length    Duration       Status  Path
+2020-05-26 13:51:15.0577354 -0400 EDT    76b9939fd5c78b8f  6h0m0s    10.249149614s  (200)   /api/prom/api/v1/query_range
+2020-05-26 13:52:15.771988849 -0400 EDT  2e7473ab10160630  10h33m0s  7.472855362s   (200)   /api/prom/api/v1/query_range
+2020-05-26 13:53:46.712563497 -0400 EDT  761f3221dcdd85de  10h33m0s  11.874296689s  (200)   /api/prom/api/v1/query_range
+```
+
+
+### License
 
 Licensed Apache 2.0, see [LICENSE](LICENSE).

cmd/logtool/Dockerfile

@@ -0,0 +1,12 @@
+FROM golang:1.12.5-stretch as build
+ARG GOARCH="amd64"
+COPY . /build_dir
+WORKDIR /build_dir
+ENV GOPROXY=https://proxy.golang.org
+RUN make clean && make logtool
+
+FROM       alpine:3.9
+RUN        apk add --update --no-cache ca-certificates
+COPY       --from=build /build_dir/cmd/logtool/logtool /usr/bin/logtool
+EXPOSE     80
+ENTRYPOINT [ "/usr/bin/logtool" ]

cmd/logtool/main.go

@@ -0,0 +1,152 @@
+package main
+
+import (
+	"bufio"
+	"flag"
+	"fmt"
+	"net/url"
+	"os"
+	"regexp"
+	"strconv"
+	"strings"
+	"text/tabwriter"
+	"time"
+)
+
+var (
+	rex    = regexp.MustCompile("(\\S+)=(\".*?\"|\\S+)")
+	layout = "2006-01-02T15:04:05.999999999Z"
+)
+
+func main() {
+
+	fi, _ := os.Stdin.Stat()
+	isPipe := false
+	if (fi.Mode() & os.ModeCharDevice) == 0 {
+		isPipe = true
+	}
+
+	showQuery := flag.Bool("query", false, "show the query")
+	minDur := flag.Duration("dur", 0, "only show queries which took longer than this duration, e.g. 10s")
+	utc := flag.Bool("utc", false, "show timestamp in UTC time")
+	flag.Parse()
+
+	// use tabwriter to format the output spaced out
+	w := tabwriter.NewWriter(os.Stdout, 0, 0, 2, ' ', 0)
+
+	// headings
+	if *showQuery {
+		fmt.Fprintf(w, "Timestamp\tTraceID\tLength\tDuration\tStatus\tPath\tQuery\n")
+	} else {
+		fmt.Fprintf(w, "Timestamp\tTraceID\tLength\tDuration\tStatus\tPath\n")
+	}
+
+	scanner := bufio.NewScanner(os.Stdin)
+	for scanner.Scan() {
+		show := false
+		var qt time.Time
+		var dur, len time.Duration
+		var status, path, query, trace string
+		var err error
+
+		line := scanner.Text()
+		data := rex.FindAllStringSubmatch(line, -1)
+
+		for _, d := range data {
+			switch d[1] {
+			case "traceID":
+				trace = d[2]
+			case "ts":
+				qt, err = time.Parse(layout, d[2])
+				if err != nil {
+					fmt.Println(err, line)
+					continue
+				}
+			case "msg":
+				msg := strings.ReplaceAll(d[2], "\"", "")
+				if !(strings.HasPrefix(msg, "GET /loki/api/") ||
+					strings.HasPrefix(msg, "GET /api/prom")) {
+					continue
+				}
+
+				show = true
+
+				parts := strings.Split(msg, " ")
+				u, err := url.Parse(parts[1])
+				if err != nil {
+					fmt.Println(err, line)
+					continue
+				}
+				vals, err := url.ParseQuery(u.RawQuery)
+				if err != nil {
+					fmt.Println(err, line)
+					continue
+				}
+				start := vals.Get("start")
+				end := vals.Get("end")
+
+				if start != "" && end != "" {
+					var st, et int64
+					var st_err, et_err error
+					// First try to parse as unix sec timestamps
+					st, st_err = strconv.ParseInt(start, 10, 64)
+					et, et_err = strconv.ParseInt(end, 10, 64)
+					if st_err != nil || et_err != nil {
+						//Next try to parse as time/date
+						var st, et time.Time
+						st, st_err = time.Parse(layout, start)
+						et, et_err = time.Parse(layout, end)
+						if st_err != nil || et_err != nil {
+							fmt.Println(err, line)
+							continue
+						}
+						len = et.Sub(st)
+					} else {
+						// Loki queries are nanosecond, simple check to see if it's a second or nanosecond timestamp
+						if st > 9999999999 {
+							len = time.Unix(0, et).Sub(time.Unix(0, st))
+						} else {
+							len = time.Unix(et, 0).Sub(time.Unix(st, 0))
+						}
+
+					}
+
+				}
+
+				status = parts[2]
+				path = u.Path
+				query = vals.Get("query")
+
+				dur, err = time.ParseDuration(parts[3])
+				if err != nil {
+					fmt.Println(err, line)
+					continue
+				}
+			}
+		}
+
+		if show && dur > *minDur {
+			var ts string
+			if *utc {
+				ts = fmt.Sprint(qt)
+			} else {
+				ts = fmt.Sprint(qt.Local())
+			}
+			if *showQuery {
+				fmt.Fprintf(w, "%v\t%v\t%v\t%v\t%v\t%v\t%v\n", ts, trace, len, dur, status, path, query)
+			} else {
+				fmt.Fprintf(w, "%v\t%v\t%v\t%v\t%v\t%v\n", ts, trace, len, dur, status, path)
+			}
+			//If looking at stdin, flush after every line as someone would only paste one line at a time at the terminal
+			if !isPipe {
+				w.Flush()
+			}
+
+		}
+		show = false
+	}
+
+	fmt.Printf("\n")
+	w.Flush()
+
+}