Skip to content

Artifact plugin: socket dir created after the plugin server starts, so bind() races and the load hangs 120s — also the cause of intermittent test-examples failures #16784

Description

@myzk-a

Pre-requisites

  • I have double-checked my configuration
  • I have tested with the :latest image tag (i.e. quay.io/argoproj/workflow-controller:latest) and can confirm the issue still exists on :latest. If not, I have explained why, in detail, in my description below.
  • I have searched existing issues and could not find a match for this bug
  • I'd like to contribute the fix myself (see contributing guide)

What happened? What did you expect to happen?

Summary: in the artifact-plugin init container (init-artifact-<name>), argoexec forks the plugin server before creating the directory the server binds its unix socket in. When the forked server wins that race, bind() fails with ENOENT, the server exits, and nothing notices — argoexec then waits out its full 120-second socket timeout while the pod sits in Init:1/2. This affects any workflow that loads an artifact through a plugin; it is also the cause of the intermittent test-examples CI failures on examples/artifact-passing-explicit-plugin.yaml.

I expected the socket directory to exist before the plugin server is started, and I expected argoexec to fail fast when the plugin server dies rather than waiting two minutes for a socket that can never appear.

Root cause

cmd/argoexec/commands/artifact_plugin_init.go (line numbers at de874c1254da8fe170ad7de9c82f11c626349847):

// L32: forks /artifact-server, which binds ArtifactPluginName.SocketPath()
go func() {
    command, closer, err := startCommand(ctx, name, args, &wfv1.Template{}, containerName, includeScriptOutput)
    if err != nil {
        logger.WithError(err).Error(ctx, "failed to start command")
        return
    }
    ...
}()
err := loadArtifactPlugin(ctx, wfv1.ArtifactPluginName(artifactPlugin))   // L47

func loadArtifactPlugin(ctx context.Context, pluginName wfv1.ArtifactPluginName) error {
    if err := os.MkdirAll(pluginName.SocketDir(), 0755); err != nil {     // L59 — too late
        return err
    }
    ...
}

SocketDir() is /tmp/artifact-plugins/<name> and SocketPath() is <SocketDir>/socket. The goroutine that starts the plugin server and the os.MkdirAll that creates the directory it binds in are concurrent, with no ordering between them.

os.MkdirAll normally wins, which is why this is intermittent. It loses when the main goroutine is descheduled — the container runs under a CPU limit (0.5 in the e2e config), so CFS throttling on a loaded node is enough. In the captured failure, the gap between starting command and the next line from the main goroutine is 300 ms, against 12 ms for the child to fork, initialise, and reach bind().

Why the save side is never affected

The sidecar variant (artifact-plugin-<name>, used to save artifacts) gets an emptyDir mounted at exactly the socket directory:

// pkg/apis/workflow/v1alpha1/workflow_types.go
func (a ArtifactPluginName) VolumeMount() apiv1.VolumeMount {
    return apiv1.VolumeMount{Name: a.volumeName(), MountPath: a.SocketDir()}
}

applied at workflow/controller/workflowpod.go:1068 and :1085. kubelet creates that directory, so the sidecar cannot hit this. The init container has no such mount and relies solely on MkdirAll — which is exactly why only init-artifact-* ever hangs.

Second defect: the dead plugin server is never noticed

startCommand returns successfully — the process did start. It is only afterwards that bind() fails and the server exits. The if err != nil branch is therefore not taken, nothing waits on the child, and plugin.NewDriver spins through all 120 one-second retries (workflow/artifacts/plugin/plugin.go:38) before failing at :74.

The plugin server's error does reach the container's stderr (startCommand wires the child's stderr straight through), so the diagnosis is in the container log the whole time — it is simply never looked at, because the container stays in Running and the test times out first.

Suggested fix

  1. Create the socket directory before starting the plugin server. Hoisting the os.MkdirAll above the go func() removes the race entirely and is behaviour-preserving.
  2. Fail fast when the plugin server exits. Have the goroutine signal the failure (channel or context cancellation) so NewDriver's socket wait aborts instead of running for two minutes.

I'd be happy to open a PR for (1); happy to discuss the shape of (2) here first.

Related: this is invisible in CI today

.github/actions/e2e-failure-debug/action.yml collects workflow pod logs with:

kubectl logs --all-containers -l workflows.argoproj.io/workflow --prefix || true

kubectl aborts the whole invocation at the first not-yet-started container, and || true only rescues the step's exit status, not its output. On a run with this bug, that produces:

Error from server (BadRequest): container "main" in pod
"artifact-passing-xxxxx-print-message-from-file-nnnnnnnn"
is waiting to start: PodInitializing

and zero log lines from init-artifact-* — the one container that holds the answer — plus the loss of every pod after it. Iterating per pod/container instead fixes this; I can send that as a separate PR.

Note also that E2E_WAIT_TIMEOUT is 90s (Makefile:73) while the plugin's own socket wait is 120s, so the test always gives up before argoexec can print its diagnostic. Raising the test wait above 120s (or lowering the plugin wait) is what made this reproducible.

Reproduction rate

Measured on a fork by running the full test-examples suite repeatedly, INITLESS=false, E2E_WAIT_TIMEOUT=180s, TEST_RETRIES=0, 10 parallel jobs:

suite runs reproductions
run 1 29 0
run 2 25 2
total 54 2

2/54 = 3.7% (95% Wilson CI 1.0–12.5%). test-examples runs twice per CI run (with and without initless), so roughly 7% of CI runs should hit this.

Deterministic reproduction

To confirm the mechanism rather than infer it, I forced the race by delaying only the MkdirAll, adding this one line at the top of loadArtifactPlugin (i.e. before the existing os.MkdirAll, so the forked server is guaranteed to reach bind() first):

func loadArtifactPlugin(ctx context.Context, pluginName wfv1.ArtifactPluginName) error {
	time.Sleep(500 * time.Millisecond) // force the race
	if err := os.MkdirAll(pluginName.SocketDir(), 0755); err != nil {

With that single line, on the same 10-job setup:

jobs failed bind: no such file or directory
unmodified 10 10 10

10/10, every one of them on artifact-passing-explicit-plugin.yaml, with the same error and the same ~130 s duration as the failures that occur naturally. The delay does not create a new failure mode — it makes the existing one certain.

Version(s)

de874c1254da8fe170ad7de9c82f11c626349847 (main).

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

# examples/artifact-passing-explicit-plugin.yaml, unchanged.
# Requires an artifact driver plugin named `test` registered in the
# workflow-controller configmap, as in test/e2e/manifests/components/base/:
#
#   artifactDrivers:
#     - name: test
#       image: ghcr.io/argoproj-labs/artifact-driver-s3:v0.3.1
#
# The hang is in the *consumer* pod's init-artifact-test container; the
# producer pod (which uses the sidecar variant) always succeeds.
apiVersion: argoproj.io/v1alpha1
kind: Workflow
metadata:
  generateName: artifact-passing-
spec:
  entrypoint: artifact-example
  templates:
  - name: artifact-example
    steps:
    - - name: generate-artifact
        template: hello-world-to-file
    - - name: consume-artifact
        template: print-message-from-file
        arguments:
          artifacts:
          - name: message
            from: "{{steps.generate-artifact.outputs.artifacts.hello-art}}"

  - name: hello-world-to-file
    container:
      image: busybox
      command: [sh, -c]
      args: ["sleep 1; echo hello world | tee /tmp/hello_world.txt"]
    outputs:
      artifacts:
      - name: hello-art
        path: /tmp/hello_world.txt
        plugin:
          name: test
          configuration: |
            bucket: my-bucket
            endpoint: minio:9000
            insecure: true
            accessKeySecret:
              name: my-minio-cred
              key: accesskey
            secretKeySecret:
              name: my-minio-cred
              key: secretkey
          key: hi

  - name: print-message-from-file
    inputs:
      artifacts:
      - name: message
        path: /tmp/message
    container:
      image: busybox
      command: [sh, -c]
      args: ["cat /tmp/message"]

Logs from the workflow controller

The controller logs nothing unusual — it creates the pod and then sees no further
state change, because the pod is stuck in Init:1/2:

level=INFO msg="Created pod" nodeName=artifact-passing-xxxxx[1].consume-artifact podName=artifact-passing-xxxxx-print-message-from-file-nnnnnnnn
level=INFO msg="add pod event" component=pod_controller pod=artifact-passing-xxxxx-print-message-from-file-nnnnnnnn
level=INFO msg="update pod event" component=pod_controller pod=artifact-passing-xxxxx-print-message-from-file-nnnnnnnn
(no further events for the next 90+ seconds)

kubectl describe pod at that point:

Init Containers:
  init:
    State:          Terminated
      Reason:       Completed
      Exit Code:    0
  init-artifact-test:
    Container ID:   containerd://c4b489f9c8e8...
    Image:          ghcr.io/argoproj-labs/artifact-driver-s3:v0.3.1
    State:          Running          <-- stays here for 120s
      Started:      2026-08-19T00:56:31Z
    Ready:          False
    Restart Count:  0
    Limits:
      cpu:     500m
      memory:  256Mi
    Mounts:
      /argo/inputs/artifacts from input-artifacts (rw)
      /var/run/argo from var-run-argo (rw)
      (note: no mount at /tmp/artifact-plugins/test)
Containers:
  wait:  State: Waiting  Reason: PodInitializing
  main:  State: Waiting  Reason: PodInitializing

Logs from in your workflow's wait container

The wait container never starts (PodInitializing), so it has no logs. The relevant container is the init container init-artifact-test. Captured with --loglevel=debug on the controller, which the executor inherits via getExecutorLogOpts (workflow/controller/workflowpod.go):

kubectl logs -n argo <pod> -c init-artifact-test

time=00:56:34.164Z level=DEBUG msg="starting command" args=[/tmp/artifact-plugins/test/socket] name=/artifact-server

  {"time":"2026-08-19T00:56:34.176864348Z","level":"ERROR","msg":"Failed to start server",
   "error":"listen unix /tmp/artifact-plugins/test/socket: bind: no such file or directory"}
                                    ^^^^ the plugin server dies here, 12ms after the fork

time=00:56:34.464Z level=INFO  msg="Starting Workflow Executor" ...
time=00:56:34.467Z level=INFO  msg="Start loading input artifacts..." pluginName=test
time=00:56:34.467Z level=INFO  msg="Downloading artifact" name=message
time=00:56:34.467Z level=DEBUG msg="plugin socket not found, retrying in 1s" retry=0   maxRetries=120
time=00:56:35.477Z level=DEBUG msg="plugin socket not found, retrying in 1s" retry=1   maxRetries=120
                                    ... 120 retry lines, one per second ...
time=00:58:33.521Z level=DEBUG msg="plugin socket not found, retrying in 1s" retry=119 maxRetries=120
time=00:58:34.521Z level=ERROR msg="executor error" error="failed to create plugin driver for test: plugin test expected unix socket at \"/tmp/artifact-plugins/test/socket\" but it does not exist after waiting for 120 seconds"

Error: failed to create plugin driver for test: plugin test expected unix socket at "/tmp/artifact-plugins/test/socket" but it does not exist after waiting for 120 seconds

For contrast, a healthy run of the same container:

time=00:09:34.900Z level=DEBUG msg="starting command" name=/artifact-server
time=00:09:35.032Z level=DEBUG msg="plugin socket not found, retrying in 1s" retry=0 maxRetries=120
  {"time":"...35.042771505Z","level":"INFO","msg":"Unix socket created successfully","mode":"Srwxr-xr-x"}
  {"time":"...35.043047764Z","level":"INFO","msg":"Server ready to accept connections"}
time=00:09:36.032Z level=INFO  msg="plugin socket file exists and is a unix socket" mode=Srwxr-xr-x
time=00:09:36.056Z level=INFO  msg="Load artifact" artifactName=message duration=21.884018ms
time=00:09:36.060Z level=INFO  msg="Successfully download file"

The socket normally appears ~140 ms after the container starts, so the failure mode is "never" rather than "slow".

Incidentally, that healthy trace also shows a small fixed cost: the socket is ready 10 ms after the first check, but the retry loop always sleeps a full second before re-checking, so every plugin artifact load pays ~1 s. A short initial backoff would remove that. Happy to file it separately if it's worth having.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions