Skip to content

fix(logql): Fix inconsistency with parsed field short circuiting - #17104

Merged
rfratto merged 1 commit into
grafana:mainfrom
rfratto:logql-parser-bug
Apr 11, 2025
Merged

fix(logql): Fix inconsistency with parsed field short circuiting#17104
rfratto merged 1 commit into
grafana:mainfrom
rfratto:logql-parser-bug

Conversation

@rfratto

@rfratto rfratto commented Apr 10, 2025

Copy link
Copy Markdown
Member

PR #8724 originally changed the behaviour of LogQL so that the first extracted field takes precedence over any later extracted field with the same name.

However, this PR had two subtle issues due to the caching that parse stages perform for key lookups:

  • The precedence logic did not always apply to duplicate fields within the same parse stage (notably for logfmt).

  • The caching behaviour could incorrectly cause stages to permanently ignore fields for future log lines where that stage should otherwise perform extraction.

Additionally, once structured metadata was introduced, it was incorrectly being flagged as an "extracted field." Combined with the caching behaviour described above, this means that parsed fields only take precedence over structured metadata if the first log line encountered by the engine doesn't have that field also set as structured metadata.

This can be demonstrated with the following scenario:

  1. A log line from a stream that uses structured metadata for trace_id is encountered first. This (incorrectly) causes the trace_id field to be ignored in all parse stages.

  2. All later log lines from streams without structured metadata can no longer extract or filter on a parsed trace_id for the lifetime of the query, due to the caching from step 1.

The fix is two-fold:

  • Decouple skipping previously extracted fields from the logic which caches interned keys.

  • Only mark parsed labels as extracted fields (previously all labels).

Because the check for whether a field is already extracted is now called more times, the list of extracted fields has been updated to a map to allow for faster checks.

PR grafana#8724 originally changed the behaviour of LogQL so that the first
extracted field takes precedence over any later extracted field with the
same name.

However, this PR had two subtle issues due to the caching that parse
stages perform for key lookups:

* The precedence logic did not always apply to duplicate fields within
  the same parse stage (notably for logfmt).

* The caching behaviour could incorrectly cause stages to permanently
  ignore fields for future log lines where that stage should otherwise
  perform extraction.

Additionally, once structured metadata was introduced, it was
incorrectly being flagged as an "extracted field." Combined with the
caching behaviour described above, this means that parsed fields only
take precedence over structured metadata if the first log line
encountered by the engine doesn't have that field also set as structured
metadata.

This can be demonstrated with the following scenario:

1. A log line from a stream that uses structured metadata for `trace_id`
   is encountered first. This (incorrectly) causes the trace_id field to
   be skipped for all future extractions.

2. A later log line from a second stream without structured metadata can
   no longer extract or filter on a parsed `trace_id`, due to the caching
   from step 1.

The fix is two-fold:

* Decouple skipping previously extracted fields from the logic which
  caches interned keys.

* Only mark parsed labels as extracted fields (previously all labels).

Because the check for whether a field is already extracted is now called
more times, the list of extracted fields has been updated to a map to
allow for faster checks.
@rfratto
rfratto requested a review from a team as a code owner April 10, 2025 14:05
@rfratto
rfratto merged commit 88beefb into grafana:main Apr 11, 2025
@rfratto
rfratto deleted the logql-parser-bug branch April 11, 2025 12:09
trevorwhitney added a commit that referenced this pull request Apr 11, 2025
commit 7e9be1148c3154fba157c4d543c49846261b2d73
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Fri Apr 11 11:56:36 2025 -0600

    Squashed commit of the following:

    commit bd43313
    Author: Robert Fratto <robertfratto@gmail.com>
    Date:   Fri Apr 11 09:52:42 2025 -0400

        chore: align benchmark results between chunks and dataobjs (#17127)

    commit 88beefb
    Author: Robert Fratto <robertfratto@gmail.com>
    Date:   Fri Apr 11 08:09:33 2025 -0400

        fix(logql): Fix inconsistency with parsed field short circuiting (#17104)

        PR #8724 originally changed the behaviour of LogQL so that the first extracted
        field takes precedence over any later extracted field with the same name.

        However, this PR had two subtle issues due to the caching that parse stages
        perform for key lookups:

        * The precedence logic did not always apply to duplicate fields within the same
          parse stage (notably for logfmt).

        * The caching behaviour could incorrectly cause stages to permanently ignore
          fields for future log lines where that stage should otherwise perform
          extraction.

        Additionally, once structured metadata was introduced, it was incorrectly being
        flagged as an "extracted field." Combined with the caching behaviour described
        above, this means that parsed fields only take precedence over structured
        metadata if the first log line encountered by the engine doesn't have that
        field also set as structured metadata.

        This can be demonstrated with the following scenario:

        1. A log line from a stream that uses structured metadata for `trace_id` is
           encountered first. This (incorrectly) causes the trace_id field to be
           ignored in all parse stages.

        2. All later log lines from streams without structured metadata can no longer
           extract or filter on a parsed `trace_id` for the lifetime of the query, due
           to the caching from step 1.

        The fix is two-fold:

        * Decouple skipping previously extracted fields from the logic which caches
          interned keys.

        * Only mark parsed labels as extracted fields (previously all labels).

        Because the check for whether a field is already extracted is now called more
        times, the list of extracted fields has been updated to a map to allow for
        faster checks.

    commit 7312ccb
    Author: Karsten Jeschkies <karsten.jeschkies@grafana.com>
    Date:   Fri Apr 11 11:46:23 2025 +0200

        refactor(stringlabels): Support stringlabels distributor tests (#17123)

    commit 5bba0c2
    Author: Karsten Jeschkies <karsten.jeschkies@grafana.com>
    Date:   Fri Apr 11 11:06:04 2025 +0200

        refactor(stringlabels): Support stringlabels ingester tests (#17121)

    commit 8e42118
    Author: benclive <ben.clive@grafana.com>
    Date:   Fri Apr 11 09:47:52 2025 +0100

        chore: Collect basic stats from dataobj queries (#17111)

    commit d197cda
    Author: George Robinson <george.robinson@grafana.com>
    Date:   Fri Apr 11 09:33:36 2025 +0100

        feat: add enforceLimits to ingest_limits.go (#17117)

    commit b0931b1
    Author: George Robinson <george.robinson@grafana.com>
    Date:   Fri Apr 11 09:23:27 2025 +0100

        chore: change the result of exceedsLimits (#17112)

    commit bcceded
    Author: George Robinson <george.robinson@grafana.com>
    Date:   Fri Apr 11 09:09:12 2025 +0100

        chore: fix private interface had exported methods (#17115)

    commit 75593e0
    Author: Karsten Jeschkies <karsten.jeschkies@grafana.com>
    Date:   Fri Apr 11 07:41:52 2025 +0200

        refactor(stringlabels): Support stringlabels in loghttp, pattern and ruler tests. (#17102)

commit e616f89e9dca98f4341c54587f5f71759f2433bb
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Thu Apr 10 14:58:00 2025 -0600

    fix: lint and format

commit e52bca19f611b5107ac56f93a426429404935e30
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Thu Apr 10 12:54:32 2025 -0600

    fix: fix a few more signatures

commit 6c5cbde7e290146ca33ffc5300f9343b1f8a8de0
Merge: b289991170 c7ffeb5
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Thu Apr 10 12:11:49 2025 -0600

    Merge branch 'main' into refactor-extractors-multiple-samples

commit b2899911701762e81348611da3d72197477594ef
Merge: 9bc6909 2aed4c3
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Tue Apr 8 15:29:34 2025 -0600

    Merge branch 'main' into refactor-extractors-multiple-samples

commit 9bc6909
Author: Trevort Whitney <trevorjwhitney@gmail.com>
Date:   Tue Apr 8 09:57:28 2025 -0600

    refactor: extractors can return multiple samples

commit 4c44821
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Mon Apr 7 11:28:28 2025 -0600

    fix: slices.Delete usage

commit b150156
Merge: b1b41c5 9e9f534
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Mon Apr 7 10:46:25 2025 -0600

    Merge branch 'main' into multi-variant-series-limits

commit b1b41c5
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Mon Apr 7 10:45:53 2025 -0600

    refactor: apply feedback from review

commit d668449
Merge: 63911a5 0a3230f
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Tue Apr 1 11:53:26 2025 -0600

    Merge branch 'main' into multi-variant-series-limits

commit 63911a5
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Tue Apr 1 11:48:30 2025 -0600

    perf: mutate response data in place

commit c16f134
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Thu Mar 27 17:23:13 2025 -0600

    feat: return varaints not exceeding limits

commit 127f29e
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Tue Mar 25 17:15:08 2025 -0600

    fix: lint and format

commit b534760
Merge: d45a53a c40053a
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Tue Mar 25 17:02:29 2025 -0600

    Merge branch 'main' into multi-variant-series-limits

commit d45a53a
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Tue Mar 25 17:01:31 2025 -0600

    feat: fix limit enforcement in step evaluator

commit 2202364
Merge: 8ffc96d 0497c6b
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Mon Mar 24 14:23:31 2025 -0600

    Merge branch 'main' into multi-variant-series-limits

commit 8ffc96d
Author: Trevor Whitney <trevorjwhitney@gmail.com>
Date:   Mon Mar 24 14:16:29 2025 -0600

    chore: apply series limit per variant for MV queries
rfratto added a commit to rfratto/loki that referenced this pull request Apr 11, 2025
The timestamp bounds of a chunk are used to update the query range
bounds; the previous code always truncated the bounds down, which caused
backwards queries to ignore the latest log line in a chunk if that log
line was less than a millisecond beyond the truncated timestamp.

PR grafana#17104 was inadvertently running generated code with this fix already
present, but the fix was removed after I thought it wasn't important.

Turns out it was important :)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

2 participants