The StartDate of an exited container is later than the FinishedAt date. #45445
Description
Description
After a container has succesfully initiated and exited, sometimes the StartedAt date is being later than the FinishedAt date.
Reproduce
docker run --name=test20230501 --detach alpine sh -c "echo 'done'"
docker wait test20230501
docker inspect --format "StartedAt: {{ .State.StartedAt }}, FinishedAt: {{ .State.FinishedAt }}" test20230501
// This messes with the logs being output
docker logs test20230501
docker logs --since "$(docker inspect --format "{{ .State.StartedAt }}" test20230501)" test20230501
docker rm test20230501 > /dev/null
Expected behavior
The StartedAt time should always be before the FinishedAt time.
docker version
Client: Docker Engine - Community
Version: 23.0.5
API version: 1.42
Go version: go1.19.8
Git commit: bc4487a
Built: Wed Apr 26 16:21:07 2023
OS/Arch: linux/amd64
Context: default
Server: Docker Engine - Community
Engine:
Version: 23.0.5
API version: 1.42 (minimum version 1.12)
Go version: go1.19.8
Git commit: 94d3ad6
Built: Wed Apr 26 16:21:07 2023
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: 1.6.20
GitCommit: 2806fc1057397dbaeefbea0e4e17bddfbd388f38
runc:
Version: 1.1.5
GitCommit: v1.1.5-0-gf19387a
docker-init:
Version: 0.19.0
GitCommit: de40ad0docker info
Client:
Context: default
Debug Mode: false
Plugins:
buildx: Docker Buildx (Docker Inc.)
Version: v0.10.4
Path: /usr/libexec/docker/cli-plugins/docker-buildx
compose: Docker Compose (Docker Inc.)
Version: v2.17.3
Path: /usr/libexec/docker/cli-plugins/docker-compose
scan: Docker Scan (Docker Inc.)
Version: v0.23.0
Path: /usr/libexec/docker/cli-plugins/docker-scan
Server:
Containers: 23
Running: 0
Paused: 0
Stopped: 23
Images: 53
Server Version: 23.0.5
Storage Driver: overlay2
Backing Filesystem: extfs
Supports d_type: true
Using metacopy: false
Native Overlay Diff: true
userxattr: false
Logging Driver: json-file
Cgroup Driver: systemd
Cgroup Version: 2
Plugins:
Volume: local
Network: bridge host ipvlan macvlan null overlay
Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: inactive
Runtimes: io.containerd.runc.v2 runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 2806fc1057397dbaeefbea0e4e17bddfbd388f38
runc version: v1.1.5-0-gf19387a
init version: de40ad0
Security Options:
apparmor
seccomp
Profile: builtin
cgroupns
Kernel Version: 5.19.0-41-generic
Operating System: Ubuntu 22.04.2 LTS
OSType: linux
Architecture: x86_64
CPUs: 8
Total Memory: 15.29GiB
Name: mammi
ID: ZECH:RGJA:RAZH:K6SZ:L4PM:WQOR:RZQP:F3KE:EMO4:OUFC:RUE6:3CT3
Docker Root Dir: /var/lib/docker
Debug Mode: false
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: falseAdditional Info
Output of the reproduction script:
834f698eeb90b32e96ac7c19085d7459198d187ea13e3ef5c783da4f78499ec8
0 // exit code, so the container exited
StartedAt: 2023-05-01T14:33:53.017722357Z, FinishedAt: 2023-05-01T14:33:53.022160634Z // this one is correct
done
done // twice the output, for both docker logs commands
Second run
f0eb39943010e8bf01d9a1866bfdf89e22e43c08cc68c4d637621226cef71bf4
0 // exit code, so the container exited
StartedAt: 2023-05-01T14:35:01.954531896Z, FinishedAt: 2023-05-01T14:35:01.954399908Z // StartedAt is slightly later than FinishedAt
done // only once the output