time.now() error: time: now: cannot set array element for non-numeric key 'key_name'

[viraj-lunani]

Hey team, we are running into a substation error when we are trying to use the time.now() transform.
We are using the transform as below
sub.tf.time.now({ obj: { trg: 'key_name.model.event.ingested' } })
and we are getting an error message as follows
{ "errorMessage": "time: now: cannot set array element for non-numeric key 'key_name'", "errorType": "errorString" }
It's happening infrequently and only on certain logs, but it's hard to find which logs it's erroring on bc of our log volume and the fact that the failing log isn't printed in the error logs. Just wondering if you have run into this error before and if you have any ideas on how to fix it.

[jshlbrd]

@viraj-lunani Substation uses sjson for modifying JSON in-place, and that error can be traced here:

• https://github.com/tidwall/sjson/blob/b279807a1bad9fa155988667d97a3d2fff4061b5/sjson.go#L367
• https://github.com/tidwall/sjson/blob/b279807a1bad9fa155988667d97a3d2fff4061b5/sjson.go#L343
• https://github.com/tidwall/sjson/blob/b279807a1bad9fa155988667d97a3d2fff4061b5/sjson.go#L323

Based on that, the JSON object you're attempting to put the time into is likely an array -- the error is saying that you can't index an array with a non-numeric value (which in this case is key_name). I'd double check that the JSON object isn't an array.

[jshlbrd]

@viraj-lunani I was able to reproduce your issue, and I think this confirms that the events you're processing must be arrays. You can test this yourself using these files with this example app.

config.jsonnet:

local sub = import '../../../../../build/config/substation.libsonnet';

{
  transforms: [
    sub.tf.time.now({obj: {trg: 'key_name.model.event.ingested'}}),
    sub.tf.send.stdout(),
  ]
}

data.json:

["a", "b", "c"]

The error returned by the app is:

% ./substation -config config.json -file data.json
panic: main: transform d2bf04d0-ad0d7ee5: cannot set array element for non-numeric key 'key_name'

If the event is an object (e.g. {"a":"b"}) then it works as expected. We don't print messages to an error log because we don't want the application to leak sensitive data, but you can print the failing log to stdout (or send it somewhere else) with a conditional transform, like this:

local sub = import '../../../../../build/config/substation.libsonnet';

{
  transforms: [
    // If the message looks like an array, then
    // print and drop it from the pipeline.
    sub.pattern.tf.conditional(
      condition=sub.cnd.all([
        sub.cnd.str.prefix({value: '['}),  
        sub.cnd.str.suffix({value: ']'}),
      ]), 
      transform=sub.tf.meta.pipe({transforms: [
        sub.tf.send.stdout(),
        sub.tf.util.drop(),
      ]}),
    ),
    // At this point all array-like messages have
    // been dropped, and no errors should be thrown.
    sub.tf.time.now({obj: {trg: 'key_name.model.event.ingested'}}),
  ]
}

[viraj-lunani]

Hmm okay yea this was super helpful, thanks for the quick response. I looked into it more and it looks like our kubernetes logs randomly have lines that are not of the expected object format. Sometimes logs are truncated (e.g end w/ [Truncated...]) or just have a few characters. I guess in this case we just want to drop the logs. Is there a convenient function in substation to check if the log is a valid object?

[shellcromancer]

Is there a convenient function in substation to check if the log is a valid object?

Yep! You can use a JSON format condition to check if the object is valid JSON with a drop transform to achieve what you're describing. It might look like this:

local sub = import '../../../../../build/config/substation.libsonnet';

{
  transforms: [
    sub.pattern.tf.conditional(
      condition=sub.cnd.none([
        sub.cnd.fmt.json()
      ]), 
      transform=sub.tf.util.drop(),
    ),
    // Only valid JSON objects past this point
  ]
}

[viraj-lunani]

Awesome, thanks team! Super helpful as always

[jshlbrd]

If you want to keep valid JSON then you want to wrap the JSON condition with a negation, otherwise you'll drop all valid JSON. The negate function is documented on this page: https://substation.readme.io/docs/cnd-meta.

Edit: An alternative is to change the all keyword to none, that has the same effect.