Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Consistently corrupt log data for long (>16kB) log lines #12197

Closed
jonaslb opened this issue Mar 13, 2024 · 4 comments · Fixed by #12374
Closed

Consistently corrupt log data for long (>16kB) log lines #12197

jonaslb opened this issue Mar 13, 2024 · 4 comments · Fixed by #12374
Labels
type/bug Somehing is not working as expected

Comments

@jonaslb
Copy link
Contributor

jonaslb commented Mar 13, 2024

Describe the bug
When a log is >16kB in size, we see "random" injected iso8601-timestamps in the data.
These timestamps appear every 16k characters (1<<14) exactly, and they are equal to the Loki timestamp (to the nanosecond), so they are not actually random but fully consistent.

To Reproduce
I have attached a tar file with a small docker compose reproducer project. Using this, it is enough to run docker compose up -d and inspect, using Grafana's explore functionality on localhost:3000, the logs from the example_logger service, which will be corrupt.

However, the steps can also be explained slightly more detailed:

  1. Have an example logger that produces large logs. In my compose example, a small python script repeatedly outputs a large log (>32k).
  2. Have a minimal local loki + grafana setup. I am using 2.9.5, also tested on 2.9.0.
  3. Use promtail to ship docker logs to loki. Also 2.9.5.
  4. Inspect in e.g. grafana explore using the query {container=~`.*logger.*`} |~ `\w2024-` . This will highlight the timestamps that have been injected.

Expected behavior
Logs should appear in their original form. Ie. in my reproducer compose project, i would expect 32k 'a' characters uninterrupted by iso timestamps.

Environment:

  • Infrastructure: docker
  • Deployment tool: docker compose

Screenshots, Promtail config, or terminal output

billede

badlogs.tar.gz

@jonaslb
Copy link
Contributor Author

jonaslb commented Mar 13, 2024

Ah, finally managed to find an old issue on the topic: #2281
I guess this issue will be a duplicate of that.

Edit: Scratch that, the old issue mentions that logs are being split, which is not the case here: The logs are indeed split by docker but seems to be combined again by promtail. It just does it incorrectly, by the looks of things - as the timestamp should not be there.

@fredsig
Copy link

fredsig commented Jun 12, 2024

@cstyan Are you planning to port this fix to Grafana Agent or Alloy?

@LegoFed3
Copy link

+1 we're also experiencing this issue and would benefit from having the fix ported to Alloy.

@matteo-zanoni
Copy link

This is still an issue in Alloy, are there any plans to reproduce this fix there?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type/bug Somehing is not working as expected
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants