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

Log messages do not have stable argument ordering #706

Open
joeblubaugh opened this issue Jun 22, 2023 · 2 comments
Open

Log messages do not have stable argument ordering #706

joeblubaugh opened this issue Jun 22, 2023 · 2 comments
Assignees
Labels
bug Something isn't working

Comments

@joeblubaugh
Copy link

joeblubaugh commented Jun 22, 2023

What happened:

I'm using the github.com/grafana/grafana-plugin-sdk-go/backend/log package in my SDK code, writing logs like so:

logger.Info("Log Message", "fieldOne", "1", "fieldTwo", "2")

Log messages are printed with nondeterministic ordering after the message field:

msg="Log Message" fieldOne=1 fieldTwo=2
msg="Log Message" fieldTwo=2 fieldOne=1
msg="Log Message" fieldTwo=2 fieldOne=1
msg="Log Message" fieldOne=1 fieldTwo=2
msg="Log Message" fieldTwo=2 fieldOne=1
msg="Log Message" fieldOne=1 fieldTwo=2
msg="Log Message" fieldOne=1 fieldTwo=2

The logger uses hclog and marshals to JSON at some point, passing through a map[string]interface{}, which makes the output order non-deterministic

What you expected to happen:
Log fields should always be written to Grafana logs in the order that they're provided.

How to reproduce it (as minimally and precisely as possible):

pkg main

import (
	"github.com/grafana/grafana-plugin-sdk-go/backend/log"
)

func main() {
  l := log.New()
  t := time.NewTimer(1*time.Second)
  for {
    select {
      case <- t.C:
        l.Info("msg", "fieldOne", "1", "fieldTwo", "2")
    }
  }
}

Anything else we need to know?:

Environment:

  • SDK version: v0.164.0
  • Grafana version: v10.0.1
  • Go version: 1.21
@joeblubaugh joeblubaugh added the bug Something isn't working label Jun 22, 2023
@oshirohugo oshirohugo self-assigned this Jul 27, 2023
@oshirohugo
Copy link
Contributor

This issue is happening in github.com/hashicorp/go-plugin
As @joeblubaugh indicated, t's indeed an problem related to unmarshalling and marshalling the logs. The host pipes the plugin logs, unmarshal and marshal it to wrap it into the host logger and the issue comes from this process which is not deterministic.

I created an issue on their repo:
hashicorp/go-plugin#266
And I've also submitted a PR for the issue:
hashicorp/go-plugin#267

Once this is accepted we can update the package and fix the issue

@github-actions github-actions bot added the stale Issue or PR without activity label Feb 29, 2024
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Mar 15, 2024
@joeblubaugh
Copy link
Author

I'm re-opening since the issue isn't actually addressed yet (waiting on upstream submission to hashicorp plugin library).

@joeblubaugh joeblubaugh reopened this May 8, 2024
@github-actions github-actions bot removed the stale Issue or PR without activity label May 8, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
Archived in project
Development

No branches or pull requests

2 participants