Expression template tag not evaluated when using `sprig.substr` together with `len`

[rduga]

Pre-requisites

• [X] I have double-checked my configuration
• [X] I can confirm the issues exists when I tested with :latest
• [ ] I'd like to contribute the fix myself (see contributing guide)

What happened/what you expected to happen?

Expected to output "bcdefghi" for line2 and line3 of the script.

But line2 returns not evaluated expression in argo version v3.4.7 (but on v3.4.6 expression is evaluated with no issues)

Actual output:

line1: example-input: abcdefghij
line2: expression which evaluates in v3.4.6 but does not evaluate in latest (from v3.4.7): {{=sprig.substr(1,len(inputs.parameters['example-input'])-1,inputs.parameters['example-inp
ut'])}}
line3: expression which evaluates in v3.4.6 and evaluates also in latest (from v3.4.7):    bcdefghi

Expected output:

line1: example-input: abcdefghij
line2: expression which evaluates in v3.4.6 but does not evaluate in latest (from v3.4.7): bcdefghi
line3: expression which evaluates in v3.4.6 and evaluates also in latest (from v3.4.7):    bcdefghi

Version

v.3.4.7 (reproducible also on latest)

Paste a small workflow that reproduces the issue. We must be able to run the workflow; don't enter a workflows that uses private images.

metadata:
  name: "sample-workflow-1621914"
spec:
  entrypoint: "entrypoint"
  templates:
    - name: "entrypoint"
      inputs:
        parameters:
          - name: "example-input"
            value: 'abcdefghij'
          - name: "len-of-example-input"
            value: "{{=len(inputs.parameters['example-input'])}}"
      script:
        command:
          - "bash"
        image: "debian:9.4"
        name: "main"
        source:  >
          echo "line1: example-input: {{=inputs.parameters['example-input']}}";
          echo "line2: expression which evaluates in v3.4.6 but does not evaluate in latest (from v3.4.7): {{=sprig.substr(1,len(inputs.parameters['example-input'])-1,inputs.parameters['example-input'])}}";
          echo "line3: expression which evaluates in v3.4.6 and evaluates also in latest (from v3.4.7):    {{=sprig.substr(1,asInt(inputs.parameters['len-of-example-input'])-1,inputs.parameters['example-input'])}}";

Logs from the workflow controller

time="2023-05-18T22:11:19.819Z" level=info msg="Processing workflow" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:19.829Z" level=info msg="Updated phase  -> Running" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:19.829Z" level=info msg="Pod node sample-workflow-1621914 initialized Pending" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:19.909Z" level=info msg="Created pod: sample-workflow-1621914 (sample-workflow-1621914)" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:19.909Z" level=info msg="TaskSet Reconciliation" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:19.909Z" level=info msg=reconcileAgentPod namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:19.918Z" level=info msg="Workflow update successful" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute phase=Running resourceVersion=383220019 workflow=sample-workflow-1621914
time="2023-05-18T22:11:29.819Z" level=info msg="Processing workflow" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:29.819Z" level=info msg="Task-result reconciliation" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute numObjs=1 workflow=sample-workflow-1621914
time="2023-05-18T22:11:29.819Z" level=info msg="task-result changed" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute nodeID=sample-workflow-1621914 workflow=sample-workflow-1621914
time="2023-05-18T22:11:29.820Z" level=info msg="node changed" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute new.message= new.phase=Running new.progress=0/1 nodeID=sample-workflow-1621914 old.message= old.phase=Pending old.progress=0/1 workflow=sample-workflow-1621914
time="2023-05-18T22:11:29.820Z" level=info msg="TaskSet Reconciliation" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:29.820Z" level=info msg=reconcileAgentPod namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:29.825Z" level=info msg="cleaning up pod" action=terminateContainers key=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute/sample-workflow-1621914/terminateContainers
time="2023-05-18T22:11:29.826Z" level=info msg="https://172.20.0.1:443/api/v1/namespaces/workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute/pods/sample-workflow-1621914/exec?command=%2Fbin%2Fsh&command=-c&command=kill+-15+1&container=istio-proxy&stderr=true&stdout=true&tty=false"
time="2023-05-18T22:11:29.830Z" level=info msg="Workflow update successful" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute phase=Running resourceVersion=383220207 workflow=sample-workflow-1621914
time="2023-05-18T22:11:29.983Z" level=info msg="signaled container" container=istio-proxy error="<nil>" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute pod=sample-workflow-1621914 stderr= stdout=
time="2023-05-18T22:11:39.831Z" level=info msg="Processing workflow" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.831Z" level=info msg="Task-result reconciliation" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute numObjs=1 workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.831Z" level=info msg="node changed" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute new.message= new.phase=Succeeded new.progress=0/1 nodeID=sample-workflow-1621914 old.message= old.phase=Running old.progress=0/1 workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.832Z" level=info msg="TaskSet Reconciliation" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.832Z" level=info msg=reconcileAgentPod namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.832Z" level=info msg="Updated phase Running -> Succeeded" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.832Z" level=info msg="Marking workflow completed" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.832Z" level=info msg="Marking workflow as pending archiving" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.832Z" level=info msg="Checking daemoned children of " namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.837Z" level=info msg="cleaning up pod" action=deletePod key=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute/sample-workflow-1621914-1340600742-agent/deletePod
time="2023-05-18T22:11:39.844Z" level=info msg="Workflow update successful" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute phase=Succeeded resourceVersion=383220394 workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.862Z" level=info msg="archiving workflow" namespace=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute uid=2e857042-ceee-49a0-80d2-47c247148032 workflow=sample-workflow-1621914
time="2023-05-18T22:11:39.867Z" level=info msg="cleaning up pod" action=labelPodCompleted key=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute/sample-workflow-1621914/labelPodCompleted
time="2023-05-18T22:11:39.886Z" level=info msg="Queueing Succeeded workflow workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute/sample-workflow-1621914 for delete in 5m0s due to TTL"
time="2023-05-18T22:11:59.984Z" level=info msg="cleaning up pod" action=killContainers key=workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-compute/sample-workflow-1621914/killContainers

Logs from in your workflow's wait container

time="2023-05-18T22:11:25.202Z" level=info msg="No output artifacts"
time="2023-05-18T22:11:25.202Z" level=info msg="S3 Save path: /tmp/argo/outputs/logs/main.log, key: sample-workflow-1621914/sample-workflow-1621914/main.log"
time="2023-05-18T22:11:25.202Z" level=info msg="Creating minio client using static credentials" endpoint="argo-minio.workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-support.svc.cluster.local:9000"
time="2023-05-18T22:11:25.202Z" level=info msg="Saving file to s3" bucket=artifacts endpoint="argo-minio.workspace-03d08c9e-6d3e-4b43-826a-3a269984d4e5-support.svc.cluster.local:9000" key=sample-workflow-1621914/sample-workflow-1621914/main.log path=/tmp/argo/outputs/logs/main.log
time="2023-05-18T22:11:25.288Z" level=info msg="Save artifact" artifactName=main-logs duration=85.465023ms error="<nil>" key=sample-workflow-1621914/sample-workflow-1621914/main.log
time="2023-05-18T22:11:25.288Z" level=info msg="not deleting local artifact" localArtPath=/tmp/argo/outputs/logs/main.log
time="2023-05-18T22:11:25.288Z" level=info msg="Successfully saved file: /tmp/argo/outputs/logs/main.log"
time="2023-05-18T22:11:25.325Z" level=info msg="Create workflowtaskresults 201"
time="2023-05-18T22:11:25.326Z" level=info msg="Alloc=7620 TotalAlloc=15686 Sys=35181 NumGC=5 Goroutines=10"
time="2023-05-18T22:11:25.326Z" level=info msg="Deadline monitor stopped"

[sarabala1979]

@rduga looks like a bug in sprig library. Do you like to triage issue on the workflow controller side? here the code pointer https://github.com/argoproj/argo-workflows/blob/04d527c7dd12aadb00527481b1a83f9db967e4b3/util/expr/argoexpr/eval.go#LL10C24-L10C24

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If this is a mentoring request, please provide an update here. Thank you for your contributions.