`experimental_shell_command` in a docker environment that timeouts doesn't kill process

[huonw]

Describe the bug
If an experimental_shell_command exceeds its timeout (potentially any command with a timeout?) while running in a docker environment, the underlying process is left still running. This may lead to resource exhaustion.

Reproducer: https://gist.github.com/huonw/d2dea90e86c2c4b16ce5d8ff21cebcdb

git clone https://gist.github.com/huonw/d2dea90e86c2c4b16ce5d8ff21cebcdb
cd d2dea90e86c2c4b16ce5d8ff21cebcdb
./run.sh

# BUILD
docker_environment(
    name="docker",
    image="python:3.9.10-bullseye",
)

experimental_shell_command(
    name="esc",
    command="sleep 100000",
    tools=["sleep"],
    timeout=1,
    environment="docker",
)

#!/bin/bash

pkill -f pantsd
docker stop $(docker ps -aq)

pants version
#> 2.15.0rc4

pants export-codegen :esc
#> ... Exceeded timeout of 1.0 seconds when executing local process: Running experimental_shell_command //:esc

docker top $(docker ps -q)
#> ...
#> root                ...            sleep 100000

Pants version
2.15.0rc4

OS
macOS

Additional info
https://gist.github.com/huonw/d2dea90e86c2c4b16ce5d8ff21cebcdb

[stuhood]

Thanks for the report.

I think that this will require a drop guard which is moved into the stream here:

pants/src/rust/engine/process_execution/src/docker.rs

Lines 495 to 543 in cae2e9a

	let exec_result = docker
	.start_exec(&exec.id, None)
	.await
	.map_err(|err| format!("Failed to start Docker execution `{}`: {:?}", &exec.id, err))?;
	let mut output_stream = if let StartExecResults::Attached { output, .. } = exec_result {
	output.boxed()
	} else {
	panic!("Unexpected value returned from start_exec: {exec_result:?}");
	};
	log::trace!("started execution {}", &exec.id);
	let exec_id = exec.id.to_owned();
	let docker = docker.to_owned();
	let stream = async_stream::try_stream! {
	// Read output from the execution.
	while let Some(output_msg) = output_stream.next().await {
	match output_msg {
	Ok(LogOutput::StdOut { message }) => {
	log::trace!("execution {} wrote {} bytes to stdout", &exec_id, message.len());
	yield ChildOutput::Stdout(message);
	}
	Ok(LogOutput::StdErr { message }) => {
	log::trace!("execution {} wrote {} bytes to stderr", &exec_id, message.len());
	yield ChildOutput::Stderr(message);
	}
	Ok(_) => (),
	Err(err) => {
	log::trace!("error while capturing output of execution {}: {:?}", &exec_id, err);
	}
	}
	}
	let exec_metadata = docker
	.inspect_exec(&exec_id)
	.await
	.map_err(|err| format!("Failed to inspect Docker execution `{}`: {:?}", &exec_id, err))?;
	let status_code = exec_metadata
	.exit_code
	.ok_or_else(|| format!("Inspected execution `{}` for exit status but status was missing.", &exec_id))?;
	log::trace!("execution {} exited with status code {}", &exec_id, status_code);
	yield ChildOutput::Exit(ExitCode(status_code as i32));
	};
	Ok(stream.boxed())

Because we use cached/long-lived containers, the drop guard will probably need to spawn and exec another command to sigkill the first... not trivial, but possible.

[huonw]

Potentially a wild idea: instead of starting the container with /bin/sh as the entry point, start it with a watchdog server process that can:

• be used to kill tasks for this issue
• interact with pantsd (e.g. poll some socket or other communication) to exit/kill the whole container if appropriate for Docker environment leaves old containers running forever on error #18307
• interact with pantsd so pants knows when the container is alive or not for Container ... is not running error if a docker environment container stops while pantsd is running #18209

I suspect this isn't the right choice, but it's there if available.

[kaos]

there's the nailgun protocol between the pants client and pantsd. Perhaps that could be applied here in some shape or form? (I don't mind the idea of a server process as entrypoint to keep tabs on the container state.)