argoproj / argoproj/argo-workflows
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
- Dominant language
- Go
- Stars
- 17k
- Forks
- 3.7k
- Avg merge
- 1d 20h
- Merged PRs (30d)
- 138
Description
### Pre-requisites
- [x] I have double-checked my configuration
- [x] 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.
- [x] I have searched existing issues and could not find a match for this bug
- [x] I'd like to contribute the fix myself (see [contributing guide](https://github.com/argoproj/argo-workflows/blob/main/docs/CONTRIBUTING.md))
### What happened? What did you expect to happen?
**Summary:** in the artifact-plugin **init** container (`init-artifact-`), 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`):
```go
// 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/` and `SocketPath()` is `/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-`, used to *save* artifacts) gets an emptyDir mounted at exactly the socket directory:
```go
// 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):
```go
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.
```YAML
# 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`:
```text
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:
```text
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`):
```text
kubectl logs -n argo -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:
```text
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.
Contributor guide
Research direction
Start in cmd/argoexec/commands/artifact_plugin_init.go, reading the init path around loadArtifactPlugin and the goroutine that starts /artifact-server. Compare its socket setup with workflow/artifacts/plugin/plugin.go, then run the test-examples case examples/artifact-passing-explicit-plugin.yaml. Done means the socket directory exists before bind can run and the workflow no longer hangs when loading the plugin.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go, kubernetes
- Domain
- backend, infrastructure
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Active
- Clarity
- Clearly specified
- Newbie friendliness
- 72/100