runsc > redirection is non-deterministic

[stepancheg]

Description

runsc seems to grab stdout/stderr itself, not inherit them, but it does not do it determistically.

Steps to reproduce

Running the command repeatedly:

runsc exec my-container-id 'date' > a

Usually it outputs

Fri Jan 10 02:36:40 UTC 2025

with a file empty.

In about 1 in 20 cases, it outputs nothing, and the file a contains the date.

Container is started with sudo runsc run my-container-id. Nothing special in config.json.

Update: The issue does not reproduce if stdin is redirected:

runsc exec my-container-id 'date' > a < /dev/null

So I guess somewhere gvisors opens stdin for stdout.

runsc version

runsc version 0.0~20230807.0
spec: 1.1.0

docker version (if using docker)

No docker.

uname

Linux xxx.internal 6.8.0-1020-gcp #22-Ubuntu SMP Mon Dec 9 17:09:22 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

kubectl (if using Kubernetes)

repo state (if built from source)

No response

runsc debug logs (if available)

Logs when date is printed to stderr:


I0110 02:43:38.613887   30658 main.go:180] ***************************
I0110 02:43:38.613936   30658 main.go:181] Args: [runsc --debug --strace --debug-log=/tmp/runsc/ exec my-container-id date]
I0110 02:43:38.613957   30658 main.go:182] Version 0.0~20230807.0
I0110 02:43:38.613964   30658 main.go:183] GOOS: linux
I0110 02:43:38.613972   30658 main.go:184] GOARCH: amd64
I0110 02:43:38.613981   30658 main.go:185] PID: 30658
I0110 02:43:38.613991   30658 main.go:186] UID: 0, GID: 0
I0110 02:43:38.613999   30658 main.go:187] Configuration:
I0110 02:43:38.614007   30658 main.go:188] 		RootDir: /var/run/runsc
I0110 02:43:38.614014   30658 main.go:189] 		Platform: systrap
I0110 02:43:38.614022   30658 main.go:190] 		FileAccess: exclusive
I0110 02:43:38.614032   30658 main.go:191] 		Directfs: true
I0110 02:43:38.614050   30658 main.go:192] 		Overlay: root:self
I0110 02:43:38.614059   30658 main.go:193] 		Network: sandbox, logging: false
I0110 02:43:38.614069   30658 main.go:194] 		Strace: true, max size: 1024, syscalls:
I0110 02:43:38.614077   30658 main.go:195] 		IOURING: false
I0110 02:43:38.614084   30658 main.go:196] 		Debug: true
I0110 02:43:38.614112   30658 main.go:197] 		Systemd: false
I0110 02:43:38.614120   30658 main.go:198] ***************************
D0110 02:43:38.614185   30658 state_file.go:78] Load container, rootDir: "/var/run/runsc", id: {SandboxID: ContainerID:my-container-id}, opts: {Exact:false SkipCheck:false TryLock:false RootContainer:false}
D0110 02:43:38.615759   30658 container.go:648] Signal container, cid: my-container-id, signal: signal 0 (0)
D0110 02:43:38.615797   30658 sandbox.go:1177] Signal sandbox "my-container-id"
D0110 02:43:38.615805   30658 sandbox.go:603] Connecting to sandbox "my-container-id"
D0110 02:43:38.615893   30658 urpc.go:568] urpc: successfully marshalled 95 bytes.
D0110 02:43:38.616270   30658 urpc.go:611] urpc: unmarshal success.
D0110 02:43:38.616336   30658 exec.go:129] Exec arguments: date
D0110 02:43:38.616351   30658 exec.go:130] Exec capabilities: <nil>
I0110 02:43:38.616400   30658 exec.go:148] Using exec capabilities from container: &{PermittedCaps:536871968 InheritableCaps:536871968 EffectiveCaps:536871968 BoundingCaps:536871968 AmbientCaps:0}
D0110 02:43:38.616421   30658 container.go:567] Execute in container, cid: my-container-id, args: date
D0110 02:43:38.616430   30658 sandbox.go:552] Executing new process in container "my-container-id" in sandbox "my-container-id"
D0110 02:43:38.616439   30658 sandbox.go:1454] Changing "/dev/stdin" ownership to 0/0
D0110 02:43:38.616462   30658 sandbox.go:1454] Changing "/dev/stdout" ownership to 0/0
D0110 02:43:38.616475   30658 sandbox.go:1454] Changing "/dev/stderr" ownership to 0/0
D0110 02:43:38.616483   30658 sandbox.go:603] Connecting to sandbox "my-container-id"
D0110 02:43:38.616737   30658 urpc.go:568] urpc: successfully marshalled 476 bytes.
D0110 02:43:38.617883   30658 urpc.go:611] urpc: unmarshal success.
D0110 02:43:38.617934   30658 container.go:679] Forwarding all signals to container, cid: my-container-id, PIDPID: 320, fgProcess: true
D0110 02:43:38.619040   30658 container.go:636] Wait on process 320 in container, cid: my-container-id
D0110 02:43:38.619121   30658 sandbox.go:1131] Waiting for PID 320 in sandbox "my-container-id"
D0110 02:43:38.619146   30658 sandbox.go:603] Connecting to sandbox "my-container-id"
D0110 02:43:38.619281   30658 urpc.go:568] urpc: successfully marshalled 79 bytes.
D0110 02:43:38.630816   30658 urpc.go:611] urpc: unmarshal success.
D0110 02:43:38.630892   30658 container.go:687] Done forwarding signals to container, cid: my-container-id, PID: 320, fgProcess: true
I0110 02:43:38.630953   30658 main.go:215] Exiting with status: 0


Logs when printed to file:


I0110 02:44:23.665860   30745 main.go:180] ***************************
I0110 02:44:23.665918   30745 main.go:181] Args: [runsc --debug --strace --debug-log=/tmp/runsc/ exec my-container-id date]
I0110 02:44:23.665938   30745 main.go:182] Version 0.0~20230807.0
I0110 02:44:23.665946   30745 main.go:183] GOOS: linux
I0110 02:44:23.665954   30745 main.go:184] GOARCH: amd64
I0110 02:44:23.665963   30745 main.go:185] PID: 30745
I0110 02:44:23.665973   30745 main.go:186] UID: 0, GID: 0
I0110 02:44:23.665981   30745 main.go:187] Configuration:
I0110 02:44:23.665989   30745 main.go:188] 		RootDir: /var/run/runsc
I0110 02:44:23.665997   30745 main.go:189] 		Platform: systrap
I0110 02:44:23.666004   30745 main.go:190] 		FileAccess: exclusive
I0110 02:44:23.666014   30745 main.go:191] 		Directfs: true
I0110 02:44:23.666022   30745 main.go:192] 		Overlay: root:self
I0110 02:44:23.666031   30745 main.go:193] 		Network: sandbox, logging: false
I0110 02:44:23.666041   30745 main.go:194] 		Strace: true, max size: 1024, syscalls:
I0110 02:44:23.666049   30745 main.go:195] 		IOURING: false
I0110 02:44:23.666065   30745 main.go:196] 		Debug: true
I0110 02:44:23.666073   30745 main.go:197] 		Systemd: false
I0110 02:44:23.666081   30745 main.go:198] ***************************
D0110 02:44:23.666147   30745 state_file.go:78] Load container, rootDir: "/var/run/runsc", id: {SandboxID: ContainerID:my-container-id}, opts: {Exact:false SkipCheck:false TryLock:false RootContainer:false}
D0110 02:44:23.667831   30745 container.go:648] Signal container, cid: my-container-id, signal: signal 0 (0)
D0110 02:44:23.667874   30745 sandbox.go:1177] Signal sandbox "my-container-id"
D0110 02:44:23.667882   30745 sandbox.go:603] Connecting to sandbox "my-container-id"
D0110 02:44:23.667996   30745 urpc.go:568] urpc: successfully marshalled 95 bytes.
D0110 02:44:23.668339   30745 urpc.go:611] urpc: unmarshal success.
D0110 02:44:23.668379   30745 exec.go:129] Exec arguments: date
D0110 02:44:23.668397   30745 exec.go:130] Exec capabilities: <nil>
I0110 02:44:23.668411   30745 exec.go:148] Using exec capabilities from container: &{PermittedCaps:536871968 InheritableCaps:536871968 EffectiveCaps:536871968 BoundingCaps:536871968 AmbientCaps:0}
D0110 02:44:23.668426   30745 container.go:567] Execute in container, cid: my-container-id, args: date
D0110 02:44:23.668435   30745 sandbox.go:552] Executing new process in container "my-container-id" in sandbox "my-container-id"
D0110 02:44:23.668443   30745 sandbox.go:1454] Changing "/dev/stdin" ownership to 0/0
D0110 02:44:23.668457   30745 sandbox.go:1454] Changing "/dev/stdout" ownership to 0/0
D0110 02:44:23.668470   30745 sandbox.go:1454] Changing "/dev/stderr" ownership to 0/0
D0110 02:44:23.668477   30745 sandbox.go:603] Connecting to sandbox "my-container-id"
D0110 02:44:23.668728   30745 urpc.go:568] urpc: successfully marshalled 476 bytes.
D0110 02:44:23.669893   30745 urpc.go:611] urpc: unmarshal success.
D0110 02:44:23.669978   30745 container.go:679] Forwarding all signals to container, cid: my-container-id, PIDPID: 330, fgProcess: true
D0110 02:44:23.671332   30745 container.go:636] Wait on process 330 in container, cid: my-container-id
D0110 02:44:23.671399   30745 sandbox.go:1131] Waiting for PID 330 in sandbox "my-container-id"
D0110 02:44:23.671416   30745 sandbox.go:603] Connecting to sandbox "my-container-id"
D0110 02:44:23.671633   30745 urpc.go:568] urpc: successfully marshalled 79 bytes.
D0110 02:44:23.683670   30745 urpc.go:611] urpc: unmarshal success.
D0110 02:44:23.683742   30745 container.go:687] Done forwarding signals to container, cid: my-container-id, PID: 330, fgProcess: true
I0110 02:44:23.683864   30745 main.go:215] Exiting with status: 0