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

[funcr.NewJSON] Naive RenderValuesHook incorrectly triggered recursive labels #120

Closed
DazWilkin opened this issue Nov 11, 2021 · 1 comment · Fixed by #121
Closed

[funcr.NewJSON] Naive RenderValuesHook incorrectly triggered recursive labels #120

DazWilkin opened this issue Nov 11, 2021 · 1 comment · Fixed by #121
Assignees

Comments

@DazWilkin
Copy link

DazWilkin commented Nov 11, 2021

This isn't an issue with go-logr but it may be worth identifying as a potential trap for the unwary; I will update my blog post.

My naive implementation of RenderValuesHook was:

renderLabels := func(kvList []interface{}) []interface{} {
  // loggingLabels becomes the only label key
  return []interface{}{
    loggingLabels,
    funcr.PseudoStruct(kvList),
  }
}

This worked fine if WithValues is only called once per Logger. If WithValues is called again, the existing labels are nested within the new set, i.e.:

{
  "jsonPayload": {
    "logging.googleapis.com/labels": {
      "logging.googleapis.com/labels": { <--- INCORRECT
        "foo": "X"
      },
      "bar": "Y"
    }
  }
  "labels": {
    "instanceId": "00bf4bf0..."
  }
}

NOTE In my case, Google Cloud Logging no longer recognized the borked logging.googleapis.com/labels as special values and does not merge them with the labels field.

Using NewStdoutLogger, the issue does not occur:

	l := NewStdoutLogger()
	l.Info("info")

	l = l.WithValues("foo", "X")
	l.Info("info")

	l = l.WithValues("bar", "Y")
	l.Info("info")

Outputs:

"level"=0 "msg"="info"
"level"=0 "msg"="info" "foo"="X"
"level"=0 "msg"="info" "foo"="X" "bar"="Y"

So, it's an issue with my implementation.

I revised the implementation (improvements welcome):

renderLabels := func(kvList []interface{}) []interface{} {
  // If loggingLabels is present, it will be the first label key
  k, _ := kvList[0].(string)
  if k == loggingLabels && len(kvList) > 2 {
    // The label values should be a PseudoStruct
    v, _ := kvList[1].(funcr.PseudoStruct)
    // Append additional ([2:]) label keys|values to the existing loggingLabels
    // loggingLabels becomes the only label key
      return []interface{}{
        loggingLabels,
        append(v, funcr.PseudoStruct(kvList[2:])...),
      }
    }

    // loggingLabels becomes the only label key
    return []interface{}{
      loggingLabels,
      funcr.PseudoStruct(kvList),
    }
}

And, replacing NewStdoutLogger with NewStructuredLogger, I get:

{"level":0,"msg":"info"}
{"level":0,"msg":"info","logging.googleapis.com/labels":{"foo":"X"}}
{"level":0,"msg":"info","logging.googleapis.com/labels":{"foo":"X","bar":"Y"}}
@thockin
Copy link
Contributor

thockin commented Nov 24, 2021

Your trivial impl should be right. This is a bug.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants