Skip to content

Commit

Permalink
fix(logql): Make LabelSampleExtractor work as expected when label d…
Browse files Browse the repository at this point in the history 
…oesn't exist in logline (grafana#6766)

* fix(logql): Make `StringLabelfilter` work as expected

Consider Log lines

```
msg=hello subqueries=5
msg=hello subqueries=0
msg=hello
```

If you run following logql
```
{foo="bar"}|logfmt|subqueries!=0
```
it returns
```
msg=hello subqueries=5
```

But if you run following logql
```
{foo="bar"}|logfmt|subqueries!="0" # NOTE: "0" as string.
```
it returns
```
msg=hello subqueries=5
msg=hello
```

NOTE: it also returns log lines that doesn't contain `subqueries` label in the first
place.

This cause subtle error if used in metric queries using that `label` in unwrap.

e.g: following logql on above log lines returns
```
sum_over_time({foo="bar"}|logfmt|subqueries!="0"|unwrap subqueries[1m])
```

Returns `pipeline error: 'SampleExtractionErr'`. Because, the lines without `subqueries`
labels are not skipped during `ProcessLine` and during metric extraction, our extractor
sets this `SampleExtractionerror`.

Fixes: grafana#6713

* Add it on changelog

Signed-off-by: Kaviraj <kavirajkanagaraj@gmail.com>

* Fix linter

Signed-off-by: Kaviraj <kavirajkanagaraj@gmail.com>

* Add more tests and fix the edge case with equality to empty strings

Signed-off-by: Kaviraj <kavirajkanagaraj@gmail.com>

* typo on the comment

Signed-off-by: Kaviraj <kavirajkanagaraj@gmail.com>

* handle this edge case during metric extraction. Not in label filter

Signed-off-by: Kaviraj <kavirajkanagaraj@gmail.com>

* Fix linter

Signed-off-by: Kaviraj <kavirajkanagaraj@gmail.com>

* Remove commented code

Signed-off-by: Kaviraj <kavirajkanagaraj@gmail.com>

* Update changelog

Signed-off-by: Kaviraj <kavirajkanagaraj@gmail.com>
  • Loading branch information
@kavirajk @lxwzy
kavirajk authored and lxwzy committed Nov 7, 2022
1 parent 0af4de7 commit 6582719
Show file tree
Hide file tree
Showing 5 changed files with 146 additions and 7 deletions.
1 change: 1 addition & 0 deletions CHANGELOG.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@
* [6395](https://github.com/grafana/loki/pull/6395) **DylanGuedes**: Add encoding support

##### Fixes
* [6766](https://github.com/grafana/loki/pull/6766) **kavirajk**: fix(logql): Make `LabelSampleExtractor` ignore processing the line if it doesn't contain that specific label. Fixes unwrap behavior explained in the issue https://github.com/grafana/loki/issues/6713

##### Changes

Expand Down
1 change: 1 addition & 0 deletions pkg/logql/log/label_filter.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -342,6 +342,7 @@ func (s *StringLabelFilter) Process(_ int64, line []byte, lbs *LabelsBuilder) ([
if s.Name == logqlmodel.ErrorLabel {
return line, s.Matches(lbs.GetErr())
}

v, _ := lbs.Get(s.Name)
return line, s.Matches(v)
}
Expand Down
70 changes: 70 additions & 0 deletions pkg/logql/log/label_filter_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (
"time"

"github.com/prometheus/prometheus/model/labels"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"

"github.com/grafana/loki/pkg/logqlmodel"
Expand Down Expand Up @@ -350,3 +351,72 @@ func TestReduceAndLabelFilter(t *testing.T) {
})
}
}

func TestStringLabelFilter(t *testing.T) {
// NOTE: https://github.com/grafana/loki/issues/6713

tests := []struct {
name string
filter *StringLabelFilter
labels labels.Labels
shouldMatch bool
}{
{
name: `logfmt|subqueries!="0" (without label)`,
filter: NewStringLabelFilter(labels.MustNewMatcher(labels.MatchNotEqual, "subqueries", "0")),
labels: labels.Labels{{Name: "msg", Value: "hello"}}, // no label `subqueries`
// without `subqueries` label, the value is assumed to be empty `subqueries=""` is matches the label filter `subqueries!="0"`.
shouldMatch: true,
},
{
name: `logfmt|subqueries!="0" (with label)`,
filter: NewStringLabelFilter(labels.MustNewMatcher(labels.MatchNotEqual, "subqueries", "0")),
labels: labels.Labels{{Name: "msg", Value: "hello"}, {Name: "subqueries", Value: "2"}}, // label `subqueries` exist
shouldMatch: true,
},
{
name: `logfmt|subqueries!~"0" (without label)`,
filter: NewStringLabelFilter(labels.MustNewMatcher(labels.MatchNotRegexp, "subqueries", "0")),
labels: labels.Labels{{Name: "msg", Value: "hello"}}, // no label `subqueries`
// without `subqueries` label, the value is assumed to be empty `subqueries=""` is matches the label filter `subqueries!="0"`.
shouldMatch: true,
},
{
name: `logfmt|subqueries!~"0" (with label)`,
filter: NewStringLabelFilter(labels.MustNewMatcher(labels.MatchNotRegexp, "subqueries", "0")),
labels: labels.Labels{{Name: "msg", Value: "hello"}, {Name: "subqueries", Value: "2"}}, // label `subqueries` exist
shouldMatch: true,
},
{
name: `logfmt|subqueries="0" (without label)`,
filter: NewStringLabelFilter(labels.MustNewMatcher(labels.MatchEqual, "subqueries", "")),
labels: labels.Labels{{Name: "msg", Value: "hello"}}, // no label `subqueries`
shouldMatch: true,
},
{
name: `logfmt|subqueries="0" (with label)`,
filter: NewStringLabelFilter(labels.MustNewMatcher(labels.MatchEqual, "subqueries", "")),
labels: labels.Labels{{Name: "msg", Value: "hello"}, {Name: "subqueries", Value: ""}}, // label `subqueries` exist
shouldMatch: true,
},
{
name: `logfmt|subqueries=~"0" (without label)`,
filter: NewStringLabelFilter(labels.MustNewMatcher(labels.MatchRegexp, "subqueries", "")),
labels: labels.Labels{{Name: "msg", Value: "hello"}}, // no label `subqueries`
shouldMatch: true,
},
{
name: `logfmt|subqueries=~"0" (with label)`,
filter: NewStringLabelFilter(labels.MustNewMatcher(labels.MatchRegexp, "subqueries", "")),
labels: labels.Labels{{Name: "msg", Value: "hello"}, {Name: "subqueries", Value: ""}}, // label `subqueries` exist
shouldMatch: true,
},
}

for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
_, ok := tc.filter.Process(0, []byte("sample log line"), NewBaseLabelsBuilder().ForLabels(tc.labels, tc.labels.Hash()))
assert.Equal(t, tc.shouldMatch, ok)
})
}
}
17 changes: 10 additions & 7 deletions pkg/logql/log/metrics_extraction.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -179,15 +179,18 @@ func (l *streamLabelSampleExtractor) Process(ts int64, line []byte) (float64, La
var v float64
stringValue, _ := l.builder.Get(l.labelName)
if stringValue == "" {
// NOTE: It's totally fine for log line to not have this particular label.
// See Issue: https://github.com/grafana/loki/issues/6713
return 0, nil, false
}

var err error
v, err = l.conversionFn(stringValue)
if err != nil {
l.builder.SetErr(errSampleExtraction)
} else {
var err error
v, err = l.conversionFn(stringValue)
if err != nil {
l.builder.SetErr(errSampleExtraction)
l.builder.SetErrorDetails(err.Error())
}
l.builder.SetErrorDetails(err.Error())
}

// post filters
if _, ok = l.postFilter.Process(ts, line, l.builder); !ok {
return 0, nil, false
Expand Down
64 changes: 64 additions & 0 deletions pkg/logql/log/metrics_extraction_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import (
"time"

"github.com/prometheus/prometheus/model/labels"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

Expand Down Expand Up @@ -152,6 +153,69 @@ func Test_Extract_ExpectedLabels(t *testing.T) {
require.True(t, ok)
require.Equal(t, (20 * time.Millisecond).Seconds(), f)
require.Equal(t, labels.Labels{{Name: "foo", Value: "json"}}, lbs.Labels())

}
func TestLabelExtractorWithStages(t *testing.T) {

// A helper type to check if particular logline should be skipped
// during `ProcessLine` or got correct sample value extracted.
type checkLine struct {
logLine string
skip bool
sample float64
}

tests := []struct {
name string
extractor SampleExtractor
checkLines []checkLine
shouldFail bool
}{
{
name: "with just logfmt and stringlabelfilter",
// {foo="bar"} | logfmt | subqueries != "0" (note: "0", a stringlabelfilter)
extractor: mustSampleExtractor(
LabelExtractorWithStages("subqueries", ConvertFloat, []string{"foo"}, false, false, []Stage{NewLogfmtParser(), NewStringLabelFilter(labels.MustNewMatcher(labels.MatchNotEqual, "subqueries", "0"))}, NoopStage),
),
checkLines: []checkLine{
{logLine: "msg=hello subqueries=5", skip: false, sample: 5},
{logLine: "msg=hello subqueries=0", skip: true},
{logLine: "msg=hello ", skip: true}, // log lines doesn't contain the `subqueries` label
},
},
{
name: "with just logfmt and numeric labelfilter",
// {foo="bar"} | logfmt | subqueries != 0 (note: "0", a numericLabelFilter)
extractor: mustSampleExtractor(
LabelExtractorWithStages("subqueries", ConvertFloat, []string{"foo"}, false, false, []Stage{NewLogfmtParser(), NewNumericLabelFilter(LabelFilterNotEqual, "subqueries", 0)}, NoopStage),
),
checkLines: []checkLine{
{logLine: "msg=hello subqueries=5", skip: false, sample: 5},
{logLine: "msg=hello subqueries=0", skip: true},
{logLine: "msg=hello ", skip: true}, // log lines doesn't contain the `subqueries` label
},
},
}

for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
for _, line := range tc.checkLines {
v, lbs, ok := tc.extractor.ForStream(labels.Labels{{Name: "bar", Value: "foo"}}).ProcessString(0, line.logLine)
skipped := !ok
assert.Equal(t, line.skip, skipped, "line", line.logLine)
if !skipped {
assert.Equal(t, line.sample, v)

// lbs shouldn't have __error__ = SampleExtractionError
assert.Empty(t, lbs.Labels())
return
}

// if line is skipped, `lbs` will be nil.
assert.Nil(t, lbs, "line", line.logLine)
}
})
}
}

func mustSampleExtractor(ex SampleExtractor, err error) SampleExtractor {
Expand Down

0 comments on commit 6582719

Please sign in to comment.