loki icon indicating copy to clipboard operation
loki copied to clipboard

Add logfmt selective label extraction

Open btaani opened this issue 3 years ago • 2 comments

What this PR does / why we need it: This is a draft for #3355

Which issue(s) this PR fixes: Fixes #

Special notes for your reviewer:

Checklist

  • [ ] Documentation added
  • [ ] Tests updated
  • [ ] Is this an important fix or new feature? Add an entry in the CHANGELOG.md.
  • [ ] Changes that require user attention or interaction to upgrade are documented in docs/sources/upgrading/_index.md

btaani avatar Jul 13 '22 14:07 btaani

Hi! This issue has been automatically marked as stale because it has not had any activity in the past 30 days.

We use a stalebot among other tools to help manage the state of issues in this project. A stalebot can be very useful in closing issues in a number of cases; the most common is closing issues or PRs where the original reporter has not responded.

Stalebots are also emotionless and cruel and can close issues which are still very relevant.

If this issue is important to you, please add a comment to keep it open. More importantly, please add a thumbs-up to the original issue entry.

We regularly sort for closed issues which have a stale label sorted by thumbs up.

We may also:

  • Mark issues as revivable if we think it's a valid issue but isn't something we are likely to prioritize in the future (the issue will still remain closed).
  • Add a keepalive label to silence the stalebot if the issue is very common/popular/important.

We are doing our best to respond, organize, and prioritize all issues but it can be a challenging task, our sincere apologies if you find yourself at the mercy of the stalebot.

stale[bot] avatar Sep 21 '22 06:09 stale[bot]

/keepalive

btaani avatar Sep 21 '22 12:09 btaani

Oh my, so sorry to let this hit the stalebot 😬

We've talked about adding this for a long time!!

Thanks so much for the PR, we've been super busy lately but will try to take a look at this as soon as we can!!!

slim-bean avatar Sep 28 '22 18:09 slim-bean

./tools/diff_coverage.sh ../loki-main/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Sep 29 '22 12:09 grafanabot

./tools/diff_coverage.sh ../loki-main/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Sep 29 '22 12:09 grafanabot

/hold I still need to add the benchmark tests

btaani avatar Sep 29 '22 13:09 btaani

Benchmark test added. Results:

$ go test -run=NONE -bench='Logfmt' -benchtime 5s -count 5 .
goos: linux
goarch: amd64
pkg: github.com/grafana/loki/pkg/logql/log
cpu: Intel(R) Core(TM) i7-10610U CPU @ 1.80GHz
BenchmarkLogfmtParser-8             	 1919780	      3389 ns/op	     264 B/op	      17 allocs/op
BenchmarkLogfmtParser-8             	 1765072	      3433 ns/op	     264 B/op	      17 allocs/op
BenchmarkLogfmtParser-8             	 1748881	      3428 ns/op	     264 B/op	      17 allocs/op
BenchmarkLogfmtParser-8             	 1749825	      3406 ns/op	     264 B/op	      17 allocs/op
BenchmarkLogfmtParser-8             	 1757325	      3372 ns/op	     264 B/op	      17 allocs/op
BenchmarkLogfmtExpressionParser-8   	  652922	      9622 ns/op	    5411 B/op	      68 allocs/op
BenchmarkLogfmtExpressionParser-8   	  615289	      9584 ns/op	    5411 B/op	      68 allocs/op
BenchmarkLogfmtExpressionParser-8   	  621687	      9592 ns/op	    5411 B/op	      68 allocs/op
BenchmarkLogfmtExpressionParser-8   	  620328	      9693 ns/op	    5412 B/op	      68 allocs/op
BenchmarkLogfmtExpressionParser-8   	  600560	      9659 ns/op	    5411 B/op	      68 allocs/op
PASS
ok  	github.com/grafana/loki/pkg/logql/log	77.919s

btaani avatar Oct 04 '22 12:10 btaani

./tools/diff_coverage.sh ../loki-main/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Oct 04 '22 12:10 grafanabot

./tools/diff_coverage.sh ../loki-main/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
- querier/queryrange	-0.1%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Oct 04 '22 13:10 grafanabot

./tools/diff_coverage.sh ../loki-main/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

-           ingester	-0.1%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0.1%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Oct 05 '22 09:10 grafanabot

./tools/diff_coverage.sh ../loki-main/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Oct 05 '22 16:10 grafanabot

./tools/diff_coverage.sh ../loki-main/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Oct 14 '22 10:10 grafanabot

@btaani Thanks for addressing all the comments! 🙌 I gave an additional test case which I expect not to fail.

The one thing I am a bit worried about are the benchmark results, both in terms of speed (ns/op) and allocations (number of allocations and bytes per operation). This seems to be quite a significant degradation. Once we merge this, we cannot remove it any more (easily), so we need to make sure performance is acceptable.

When comparing the benchmark of the JSON parser vs JSON expression parser, there is a 1:1.18 ratio in terms of duration and a 1:1.4 ratio in terms of allocations.

$ go test -run=NONE -bench='JSON' -benchtime 5s -count 5 ./pkg/logql/log
goos: linux
goarch: amd64
pkg: github.com/grafana/loki/pkg/logql/log
cpu: 11th Gen Intel(R) Core(TM) i7-1185G7 @ 3.00GHz
BenchmarkJSONParser-8                        	 5538000	      1081 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParser-8                        	 5438976	      1104 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParser-8                        	 5377080	      1115 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParser-8                        	 5364165	      1218 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParser-8                        	 4561021	      1298 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParserInvalidLine-8             	35815749	       167.4 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONParserInvalidLine-8             	35749088	       169.6 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONParserInvalidLine-8             	35904565	       167.4 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONParserInvalidLine-8             	35645467	       167.3 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONParserInvalidLine-8             	36626263	       166.4 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONExpressionParser-8              	 4432426	      1392 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParser-8              	 4357263	      1379 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParser-8              	 4389457	      1375 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParser-8              	 4217883	      1381 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParser-8              	 4409215	      1409 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8104791	       730.4 ns/op	     296 B/op	      10 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8139670	       721.6 ns/op	     296 B/op	      10 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8395081	       737.9 ns/op	     296 B/op	      10 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8190120	       731.1 ns/op	     296 B/op	      10 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8407848	       713.0 ns/op	     296 B/op	      10 allocs/op
PASS
ok  	github.com/grafana/loki/pkg/logql/log	138.150s

Whereas with Logfmt parser vs Logfmt expression parser there is a ratio of 1:2.8 and 1:4 respectively.

I think we need to try to improve that 🙂

chaudum avatar Oct 17 '22 15:10 chaudum

@btaani Thanks for addressing all the comments! raised_hands I gave an additional test case which I expect not to fail.

The one thing I am a bit worried about are the benchmark results, both in terms of speed (ns/op) and allocations (number of allocations and bytes per operation). This seems to be quite a significant degradation. Once we merge this, we cannot remove it any more (easily), so we need to make sure performance is acceptable.

When comparing the benchmark of the JSON parser vs JSON expression parser, there is a 1:1.18 ratio in terms of duration and a 1:1.4 ratio in terms of allocations.

$ go test -run=NONE -bench='JSON' -benchtime 5s -count 5 ./pkg/logql/log
goos: linux
goarch: amd64
pkg: github.com/grafana/loki/pkg/logql/log
cpu: 11th Gen Intel(R) Core(TM) i7-1185G7 @ 3.00GHz
BenchmarkJSONParser-8                        	 5538000	      1081 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParser-8                        	 5438976	      1104 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParser-8                        	 5377080	      1115 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParser-8                        	 5364165	      1218 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParser-8                        	 4561021	      1298 ns/op	     184 B/op	      10 allocs/op
BenchmarkJSONParserInvalidLine-8             	35815749	       167.4 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONParserInvalidLine-8             	35749088	       169.6 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONParserInvalidLine-8             	35904565	       167.4 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONParserInvalidLine-8             	35645467	       167.3 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONParserInvalidLine-8             	36626263	       166.4 ns/op	      24 B/op	       1 allocs/op
BenchmarkJSONExpressionParser-8              	 4432426	      1392 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParser-8              	 4357263	      1379 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParser-8              	 4389457	      1375 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParser-8              	 4217883	      1381 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParser-8              	 4409215	      1409 ns/op	     160 B/op	      14 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8104791	       730.4 ns/op	     296 B/op	      10 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8139670	       721.6 ns/op	     296 B/op	      10 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8395081	       737.9 ns/op	     296 B/op	      10 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8190120	       731.1 ns/op	     296 B/op	      10 allocs/op
BenchmarkJSONExpressionParserInvalidLine-8   	 8407848	       713.0 ns/op	     296 B/op	      10 allocs/op
PASS
ok  	github.com/grafana/loki/pkg/logql/log	138.150s

Whereas with Logfmt parser vs Logfmt expression parser there is a ratio of 1:2.8 and 1:4 respectively.

I think we need to try to improve that slightly_smiling_face

@chaudum I believe this is due to the allocation of a separate set of empty labels at each label extraction process in order to convert it to a key-value format, just to make it easier for me to parse and extract the values, and to treat similarly to a regular logfmt (here), in contrary to JSON, which can be easily parsed through json libraries.

I will try to improve this bit, thanks for pointing it out!

btaani avatar Oct 18 '22 11:10 btaani

./tools/diff_coverage.sh ../loki-main/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
- querier/queryrange	-0.1%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Oct 26 '22 13:10 grafanabot

@chaudum I just pushed the modified version of LogfmtExpressionParser. All the test cases are passing, I also tried with logcli to make sure it gives me correct results.

Here are the benchmark results:

$ go test -run=NONE -bench='Logfmt' -benchtime 5s -count 3 ./pkg/logql/log
goos: linux
goarch: amd64
pkg: github.com/grafana/loki/pkg/logql/log
cpu: Intel(R) Core(TM) i7-10610U CPU @ 1.80GHz
BenchmarkLogfmtParser-8             	 1811230	      3189 ns/op	     264 B/op	      17 allocs/op
BenchmarkLogfmtParser-8             	 1997640	      2991 ns/op	     264 B/op	      17 allocs/op
BenchmarkLogfmtParser-8             	 1959325	      3146 ns/op	     264 B/op	      17 allocs/op
BenchmarkLogfmtExpressionParser-8   	 2235099	      2669 ns/op	      90 B/op	       3 allocs/op
BenchmarkLogfmtExpressionParser-8   	 2174637	      2771 ns/op	      90 B/op	       3 allocs/op
BenchmarkLogfmtExpressionParser-8   	 2129344	      2847 ns/op	      90 B/op	       3 allocs/op
PASS
ok  	github.com/grafana/loki/pkg/logql/log	53.839s

btaani avatar Oct 26 '22 13:10 btaani

./tools/diff_coverage.sh ../loki-target-branch/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0%
+               iter	0%
+            storage	0%
+           chunkenc	0%
-              logql	-0.4%
+               loki	0%

grafanabot avatar Nov 02 '22 11:11 grafanabot

./tools/diff_coverage.sh ../loki-target-branch/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0%
+               iter	0%
+            storage	0%
+           chunkenc	0%
+              logql	0%
+               loki	0%

grafanabot avatar Nov 03 '22 11:11 grafanabot

./tools/diff_coverage.sh ../loki-target-branch/test_results.txt test_results.txt ingester,distributor,querier,querier/queryrange,iter,storage,chunkenc,logql,loki

Change in test coverage per package. Green indicates 0 or positive change, red indicates that test coverage for a package fell.

+           ingester	0%
+        distributor	0%
+            querier	0%
+ querier/queryrange	0%
+               iter	0%
+            storage	0%
+           chunkenc	0%
-              logql	-0.1%
+               loki	0%

grafanabot avatar Nov 03 '22 19:11 grafanabot