docker inspect error in system testing with short-lived Docker integration services

[ebeahan]

Summary

System tests fail unexpected for packages using the docker-compose service deployer if the container's lifetime is short, such as mounting a volume for filestream inputs.

Packages experiencing this failure include trendmicro and mysql_enterprise.

Example

Using trendmicro package which deploys a single, short-lived container to mount a volume for system testing: https://github.com/elastic/integrations/blob/main/packages/trendmicro/_dev/deploy/docker/docker-compose.yml.

Note missing value for container ID in DEBUG Wait for healthy containers and DEBUG output command: /usr/local/bin/docker inspect

$ elastic-package test system -v
2023/09/29 14:42:45  WARN CommitHash is undefined, in both /Users/ericbeahan/.elastic-package/version and the compiled binary, config may be out of date.
2023/09/29 14:42:45 DEBUG Enable verbose logging
2023/09/29 14:42:45 DEBUG latest version (cached): &{v0.87.1 https://github.com/elastic/elastic-package/releases/tag/v0.87.1 2023-09-29 14:22:21.071471 -0500 CDT}
2023/09/29 14:42:45  INFO New version is available - v0.87.1. Download from: https://github.com/elastic/elastic-package/releases/tag/v0.87.1
Run system tests for the package
2023/09/29 14:42:45 DEBUG GET https://127.0.0.1:5601/api/status
2023/09/29 14:42:45 DEBUG Running system tests for data stream
2023/09/29 14:42:45 DEBUG running test with configuration 'filestream'
2023/09/29 14:42:45 DEBUG setting up service...
2023/09/29 14:42:45 DEBUG setting up service using Docker Compose service deployer
2023/09/29 14:42:45 DEBUG running command: /usr/local/bin/docker-compose version --short
2023/09/29 14:42:45 DEBUG Determined Docker Compose version: 2.21.0-desktop.1
2023/09/29 14:42:45 DEBUG output command: /usr/local/bin/docker network inspect elastic-package-stack_default
2023/09/29 14:42:45 DEBUG running command: /usr/local/bin/docker-compose -f /Users/ericbeahan/dev/integrations/packages/trendmicro/_dev/deploy/docker/docker-compose.yml -p elastic-package-service up --build -d
[+] Running 2/2
 ✔ Network elastic-package-service_default                        Created                                                                                                                                                                                                                                                                                              0.0s
 ✔ Container elastic-package-service-trendmicro-log-filestream-1  Started                                                                                                                                                                                                                                                                                              0.0s
2023/09/29 14:42:45 DEBUG running command: /usr/local/bin/docker-compose -f /Users/ericbeahan/dev/integrations/packages/trendmicro/_dev/deploy/docker/docker-compose.yml -p elastic-package-service ps -q
2023/09/29 14:42:45 DEBUG Wait for healthy containers:
2023/09/29 14:42:45 DEBUG output command: /usr/local/bin/docker inspect
2023/09/29 14:42:46 DEBUG running command: /usr/local/bin/docker-compose -f /Users/ericbeahan/dev/integrations/packages/trendmicro/_dev/deploy/docker/docker-compose.yml -p elastic-package-service logs
2023/09/29 14:42:46  INFO service container hasn't written anything logs.
Error: error running package system tests: could not complete test run: could not setup service: service is unhealthy: could not inspect containers (stderr="\"docker inspect\" requires at least 1 argument.\nSee 'docker inspect --help'.\n\nUsage:  docker inspect [OPTIONS] NAME|ID [NAME|ID...]\n\nReturn low-level information on Docker objects\n"): exit status 1

Working comparison

Here's a working comparison ran within the panw package. Note, however, with four containers started by the Docker service deployer, only three report in the docker inspect. The longer lived udp, tcp, and tls services prevent the docker inspect command from failing and testing continues.

# Four containers started
 ✔ Container elastic-package-service-panw-panos-udp-1                                                                                                            Started                                                                                                                                                                                               0.1s
 ✔ Container elastic-package-service-panw-logfile-1                                                                                                              Started                                                                                                                                                                                               0.1s
 ✔ Container elastic-package-service-panw-panos-tls-1                                                                                                            Started                                                                                                                                                                                               0.1s
 ✔ Container elastic-package-service-panw-panos-tcp-1                                                                                                            Started                                                                                                                                                                                               0.1s

2023/09/29 14:35:25 DEBUG running command: /usr/local/bin/docker-compose -f /Users/ericbeahan/dev/integrations/packages/panw/_dev/deploy/docker/docker-compose.yml -p elastic-package-service ps -q
2023/09/29 14:35:25 DEBUG Wait for healthy containers: 4643552da6e6a8ea9c7d9142451524096328e7bb47ff7d1aa775d0d4243fb21e,88a0bbbef0bfed5b13c36d8d589178189dc32d30e0777454010a834e2640c973,36c5ed532d759e0eb70f2b412af8033be9792777125b5de0fc1270234d4f1314

# Only three containers inspected
2023/09/29 14:35:25 DEBUG output command: /usr/local/bin/docker inspect 4643552da6e6a8ea9c7d9142451524096328e7bb47ff7d1aa775d0d4243fb21e 88a0bbbef0bfed5b13c36d8d589178189dc32d30e0777454010a834e2640c973 36c5ed532d759e0eb70f2b412af8033be9792777125b5de0fc1270234d4f1314
2023/09/29 14:35:25 DEBUG Container status: {"Config":{"Image":"docker.elastic.co/observability/stream:v0.8.0","Labels":{"BRANCH_NAME":"v0.8.0","GIT_SHA":"3df2f6636c0b047f4e9903ff226dab5064da0ad4","GO_VERSION":"1.19.1","TIMESTAMP":"2022-09-15_16:29","com.docker.compose.config-hash":"d4c28a49392f1c4b32c8cb1f221add07fdedcdbcb0183e2faae874186bbb1bad","com.docker.compose.container-number":"1","com.docker.compose.depends_on":"","com.docker.compose.image":"sha256:62eb4cdf2c37cd9619e21a06f9639399a187e970c88adec4ed8cd166ffb5c5a8","com.docker.compose.oneoff":"False","com.docker.compose.project":"elastic-package-service","com.docker.compose.project.config_files":"/Users/ericbeahan/dev/integrations/packages/panw/_dev/deploy/docker/docker-compose.yml","com.docker.compose.project.working_dir":"/Users/ericbeahan/dev/integrations/packages/panw/_dev/deploy/docker","com.docker.compose.service":"panw-panos-tcp","com.docker.compose.version":"2.21.0"}},"ID":"4643552da6e6a8ea9c7d9142451524096328e7bb47ff7d1aa775d0d4243fb21e","State":{"Status":"running","ExitCode":0,"Health":null}}
2023/09/29 14:35:25 DEBUG Container status: {"Config":{"Image":"docker.elastic.co/observability/stream:v0.8.0","Labels":{"BRANCH_NAME":"v0.8.0","GIT_SHA":"3df2f6636c0b047f4e9903ff226dab5064da0ad4","GO_VERSION":"1.19.1","TIMESTAMP":"2022-09-15_16:29","com.docker.compose.config-hash":"3051a8fc0256ef9bfb8f1e965d665e165a3419f47402fa563721c7525908b36f","com.docker.compose.container-number":"1","com.docker.compose.depends_on":"","com.docker.compose.image":"sha256:62eb4cdf2c37cd9619e21a06f9639399a187e970c88adec4ed8cd166ffb5c5a8","com.docker.compose.oneoff":"False","com.docker.compose.project":"elastic-package-service","com.docker.compose.project.config_files":"/Users/ericbeahan/dev/integrations/packages/panw/_dev/deploy/docker/docker-compose.yml","com.docker.compose.project.working_dir":"/Users/ericbeahan/dev/integrations/packages/panw/_dev/deploy/docker","com.docker.compose.service":"panw-panos-tls","com.docker.compose.version":"2.21.0"}},"ID":"88a0bbbef0bfed5b13c36d8d589178189dc32d30e0777454010a834e2640c973","State":{"Status":"running","ExitCode":0,"Health":null}}
2023/09/29 14:35:25 DEBUG Container status: {"Config":{"Image":"docker.elastic.co/observability/stream:v0.8.0","Labels":{"BRANCH_NAME":"v0.8.0","GIT_SHA":"3df2f6636c0b047f4e9903ff226dab5064da0ad4","GO_VERSION":"1.19.1","TIMESTAMP":"2022-09-15_16:29","com.docker.compose.config-hash":"dacfae67c7543569c2e67a6d816a4cf393745ad0a9e5acd9fac829965dbc1c3a","com.docker.compose.container-number":"1","com.docker.compose.depends_on":"","com.docker.compose.image":"sha256:62eb4cdf2c37cd9619e21a06f9639399a187e970c88adec4ed8cd166ffb5c5a8","com.docker.compose.oneoff":"False","com.docker.compose.project":"elastic-package-service","com.docker.compose.project.config_files":"/Users/ericbeahan/dev/integrations/packages/panw/_dev/deploy/docker/docker-compose.yml","com.docker.compose.project.working_dir":"/Users/ericbeahan/dev/integrations/packages/panw/_dev/deploy/docker","com.docker.compose.service":"panw-panos-udp","com.docker.compose.version":"2.21.0"}},"ID":"36c5ed532d759e0eb70f2b412af8033be9792777125b5de0fc1270234d4f1314","State":{"Status":"running","ExitCode":0,"Health":null}}

[ebeahan]

One workaround is to create a long running service alongside the existing short running one.

$ cat _dev/deploy/docker/docker-compose.yml
version: '2.3'
services:
  trendmicro-log-filestream:
    image: alpine
    volumes:
      - ./sample_logs:/sample_logs:ro
      - ${SERVICE_LOGS_DIR}:/var/log
    command: /bin/sh -c "cp /sample_logs/* /var/log/"
  trendmicro-log-udp:
    image: docker.elastic.co/observability/stream:v0.8.0
    volumes:
      - ./sample_logs:/sample_logs:ro
    command: log --start-signal=SIGHUP --delay=5s --addr elastic-agent:9514 -p=udp /sample_logs/*.log

[bhapas]

May be related - docker/for-win#13242

[bhapas]

I have modified docker-compose to get this issue worked around even with single service

version: '2.3'
services:
  trendmicro-log-filestream:
    image: alpine
    volumes:
      - ./sample_logs:/sample_logs:ro
      - ${SERVICE_LOGS_DIR}:/var/log
    command: /bin/sh -c "cp /sample_logs/* /var/log/ && tail -F anything"

tail -F anything is added to keep the container alive after executing the logs copy.