Race condition in mergeMap

[pi-alexander-popel]

https://github.com/hashicorp/consul-template/blob/main/docs/templating-language.md#mergemap

Consul Template version

consul-template v0.28.1 (d8d30a97)

Configuration

Template:

{{ $type := (env "TYPE") -}}
{{ $env := (env "ENVIRONMENT") -}}
{{ $common := tree "test/common" | explode -}}
{{ $typeCommon := tree (print "test/" $type "/common") | explode | mergeMapWithOverride $common -}}
{{ $envCommon := tree (print "test/" $type "/" $env "/common") | explode | mergeMapWithOverride $typeCommon -}}
{{ $values := tree (print "test/" $type "/" $env "/service") | explode | mergeMapWithOverride $envCommon -}}

{{ with $values }}
{{ .log.file }}{{ end }}

Can't really include any sample data, sorry.

Command

consul-template -consul-addr=https://example.com -once -template=test.tpl:result.txt

Debug output

$ consul-template -consul-addr=https://example.com -once -template=test.tpl:result.txt && cat result.txt 

"/dev/stderr"

$ consul-template -consul-addr=https://example.com -once -template=test.tpl:result.txt && cat result.txt 
2022-06-27T13:49:29.998+0300 [ERR] (cli) test.tpl: execute: template: :9:7: executing "" at <.log.file>: nil pointer evaluating interface {}.file
$ consul-template -consul-addr=https://example.com -once -template=test.tpl:result.txt && cat result.txt 
2022-06-27T13:49:32.119+0300 [ERR] (cli) test.tpl: execute: template: :9:7: executing "" at <.log.file>: nil pointer evaluating interface {}.file
$ consul-template -consul-addr=https://example.com -once -template=test.tpl:result.txt && cat result.txt 

"/dev/stderr"

Expected behavior

Consistently getting the value.

Actual behavior

Sometimes works, sometimes don't.

Steps to reproduce

1. Use the template above
2. Run the command above

[eikenb]

Hey @pi-alexander-popel, thanks for filing a ticket!

Quick initial question. The title of the bug is that there is a race in the example, but the template you give is different from the examples in the docs linked to. Were you able to reproduce this with just the example code or is the version in the template above needed to reproduce it?

Thanks!

[pi-alexander-popel]

Hmm, doesn't look like I can. My template only has more of the same, so I didn't think it mattered. May I ask you to rename the issue to something more appropriate?

Thanks for looking into it!

[eikenb]

Thanks for the quick reply! Name updated.

[eikenb]

I'm trying to reproduce it but can't and it probably has to do with my data. Could you try to give some example of your data? Just the basic layout so I have an idea of the depth and forms of the trees. I'll keep poking but it would be a lot easier if I wasn't just guessing. Thanks!

[pi-alexander-popel]

Here you go. I trimmed it down quite a bit, but still can reproduce the bug with the following data:

[
        {
                "key": "test/",
                "flags": 0,
                "value": ""
        },
        {
                "key": "test/common/",
                "flags": 0,
                "value": ""
        },
        {
                "key": "test/common/listen_port",
                "flags": 0,
                "value": "IjgwODAi"
        },
        {
                "key": "test/common/log/access_file",
                "flags": 0,
                "value": "Ii9kZXYvc3Rkb3V0Ig=="
        },
        {
                "key": "test/common/log/file",
                "flags": 0,
                "value": "Ii9kZXYvc3RkZXJyIg=="
        },
        {
                "key": "test/dev/",
                "flags": 0,
                "value": ""
        },
        {
                "key": "test/dev/common/log/level",
                "flags": 0,
                "value": "ImRlYnVnIg=="
        },
        {
                "key": "test/dev/env1/service/rules",
                "flags": 0,
                "value": "Int9Ig=="
        },
        {
                "key": "test/dev/env1/common/client_name",
                "flags": 0,
                "value": "InRlc3QxIg=="
        }
]

Edit: Oh, and if it's relevant - my Consul instance is located in western US, while I'm in Europe, so the ping is quite high.

[eikenb]

Thanks for the example data @pi-alexander-popel.

I'll try to reproduce with this and thanks for that additional info... if I can't replicate it with the data I'll see if I can use something like trickle to replicate the latency.

[eikenb]

If it is the ping latency that is contributing to this... maybe try setting the wait {min:} setting. It it designed more to help with value flapping but might help with these if they are latency based.

Just a thought that this might help mitigate the issue.

[pi-alexander-popel]

Maybe I'm using it wrong, but just adding -wait=10s doesn't seem to do anything. consul-template doesn't wait for 10 seconds and the issue still appears.

[eikenb]

That's right. It just didn't help. I wasn't sure as I don't know the source of the race yet. Thanks for trying.

[Chinikins]

I just wanted to add that I'm experiencing this as well and I'm operating under circumstances with little latency (both me and my consul are in the US)

[eikenb]

Hey @Chinikins, welcome to the ticket. If you have any luck coming up with a, hopefully simple, way to reproduce this please let me know. I've yet to reproduce this. Thanks!

[Chinikins]

sure, here is an example:

keys:

services:
  myFunService:
    jaeger:
      enabled: false

accounts:
  myAccount:
    myFunService:
      otherKeyNotJaeger:stuff

regions:
  myRegion:
    myFunService:
      otherKeyNotJaeger:stuff

clusters:
  myCluster:
    myFunService:
      jaeger:
        enabled: true

template:

{{- $SERVICE := "myFunService" -}}
{{- $ACCOUNT := "myAccount" -}}
{{- $REGION := "myRegion" -}}
{{- $CLUSTER := "myCluster" -}}

{{- $GLOBAL_SERVICE_SPEC := tree (printf "services/%s" $SERVICE) | explode }}
{{- $ACC_SERVICE_SPEC := tree (printf "accounts/%s/services/%s" $ACCOUNT $SERVICE) | explode | mergeMapWithOverride $GLOBAL_SERVICE_SPEC }}
{{- $REGIONAL_SERVICE_SPEC := tree (printf "regions/%s/services/%s" $REGION $SERVICE) | explode | mergeMapWithOverride $ACC_SERVICE_SPEC }}
{{- $SERVICE_SPEC := tree (printf "clusters/%s/services/%s" $CLUSTER $SERVICE) | explode | mergeMapWithOverride $REGIONAL_SERVICE_SPEC }}
{{- with $SERVICE_SPEC | explodeMap -}}

then later in my template, I can render this as a string:

{{- $SERVICE_SPEC.jaeger.enabled }}

will correctly show as true

but if I try to do a conditional on it:

{{- if $SERVICE_SPEC.jaeger.enabled }}

will always return true as expected, but indicates that still it isn't null. but if I try:

{{- if $SERVICE_SPEC.jaeger.enabled | parseBool }}

all of a sudden it's execute: template: :83:46: executing "" at <parseBool>: invalid value; expected string

if I instead add in:

{{- with $SERVICE_SPEC.jaeger -}}

it seems to help, but wondering if there's a way to not have to do this :pray:

[Chinikins]

my consul-template version is consul-template v0.28.0 (ae2bbca1) if that also helps and if you think there's any fixes after that commit that you think would help, i'm happy to try with an update

[eikenb]

Added to 0.30.0 to remind me to try your repro when I work on this again. Thanks!