Closed gbmeuk closed 7 years ago
A more minimal repro seems to point to the filter for the stopped
status.
$ docker run -d --name test alpine:3.5 sleep 86400
$ docker ps --filter="status=running" # verify we're provisioned and running first
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
45bfd5b330b4 alpine:3.5 "sleep 86400" 23 seconds ago Up 9 seconds test
$ docker stop test
test
$ docker ps --filter="status=stopped"
Error response from daemon: Unrecognised filter value for status (045f6ffe-eb15-4b69-b580-dfbd71ccbf97)
All the other filters in https://github.com/docker/docker/commit/ea09f036824aee74112a75ac99579ae4f10251b5 appear to be working correctly.
submitted pull request #111
@tgross
$ docker ps --filter="status=stopped" Error response from daemon: Unrecognised filter value for status (045f6ffe-eb15-4b69-b580-dfbd71ccbf97)
That is not correct, as docker/docker also does the same thing with the filter status value:
docker ps --filter="status=stopped"
Error response from daemon: Unrecognised filter value for status: stopped
Docker's server currently accepts these status values: https://github.com/docker/docker/blob/b59ee9486fad5fa19f3d0af0eb6c5ce100eae0fc/container/state.go#L150
so by that it looks like sdc-docker is missing dead
and removing
status fields... and to be honest I'm not sure if adding these will solve the original reported problem.
removed previous comment about #111 working. Tests weren't thorough enough.
Only obvious thing that still stands out for me is the missing "Status" and "Dead" keys in the sdc-docker State object returned from docker inspect. Also, the "StartedAt" and "FinishedAt" values alternately have "0001-01-01T00:00:00Z" as their value depending on whether the container is stopped or running. This differs from docker engine
So following some of the logs, this seems to be an issue of not correctly handling the docker -a
flag when passing filters. For example:
(gaz@gMac)-(13:30:30)-(dockerlx)
$docker ps --all=true -n=-1 --no-trunc=false --size=false --filter label=com.docker.compose.project=dockerlx -f label=com.docker.compose.service=consul -f label=com.docker.compose.oneoff=False
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
2a55b51de079 mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_2
e61cf429d85c mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_3
245a8582694e mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_1
(gaz@gMac)-(13:30:34)-(dockerlx)
$docker ps --all=false -n=-1 --no-trunc=false --size=false --filter label=com.docker.compose.project=dockerlx -f label=com.docker.compose.service=consul -f label=com.docker.compose.oneoff=False
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
2a55b51de079 mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_2
e61cf429d85c mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_3
245a8582694e mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_1
(gaz@gMac)-(13:30:42)-(dockerlx)
$
whereas when running the same commands on docker-engine:
(gaz@gMac)-(11:47:11)-(dockerlx)
$docker ps --all=false -n=-1 --no-trunc=false --size=false --filter label=com.docker.compose.project=dockerlx -f label=com.docker.compose.service=consul -f label=com.docker.compose.oneoff=False
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
(gaz@gMac)-(11:47:12)-(dockerlx)
$docker ps --all=true -n=-1 --no-trunc=false --size=false --filter label=com.docker.compose.project=dockerlx -f label=com.docker.compose.service=consul -f label=com.docker.compose.oneoff=False
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
a1bcaaa1de6f mesoform/consul:latest "/usr/local/bin/co..." About a minute ago Exited (137) About a minute ago dockerlx_consul_3
d55839b4ca86 mesoform/consul:latest "/usr/local/bin/co..." About a minute ago Exited (137) About a minute ago dockerlx_consul_2
260a5df0c03a mesoform/consul:latest "/usr/local/bin/co..." About a minute ago Exited (137) About a minute ago dockerlx_consul_1
(gaz@gMac)-(11:47:19)-(dockerlx)
$
And without filters:
(gaz@gMac)-(13:36:46)-(dockerlx)
$docker ps --all=false -n=-1 --no-trunc=false --size=false | grep consul
(gaz@gMac)-(13:37:22)-(dockerlx)
$docker ps --all=true -n=-1 --no-trunc=false --size=false | grep consul
2a55b51de079 mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_2
e61cf429d85c mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_3
245a8582694e mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_1
(gaz@gMac)-(13:37:32)-(dockerlx)
$
This is the same with any filter:
(gaz@gMac)-(13:38:18)-(dockerlx)
$docker ps --all=false -n=-1 --no-trunc=false --size=false --filter name=dockerlx_consul_*
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
2a55b51de079 mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_2
e61cf429d85c mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_3
245a8582694e mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_1
(gaz@gMac)-(13:38:45)-(dockerlx)
$
except of course "exited":
(gaz@gMac)-(13:39:30)-(dockerlx)
$docker ps --all=false -n=-1 --no-trunc=false --size=false --filter label=com.docker.compose.project=dockerlx -f label=com.docker.compose.service=consul -f label=com.docker.compose.oneoff=False --filter status=running
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
(gaz@gMac)-(13:39:41)-(dockerlx)
$docker ps --all=false -n=-1 --no-trunc=false --size=false --filter label=com.docker.compose.project=dockerlx -f label=com.docker.compose.service=consul -f label=com.docker.compose.oneoff=False --filter status=exited
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
2a55b51de079 mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_2
e61cf429d85c mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_3
245a8582694e mesoform/consul "/usr/local/bin/co..." 24 hours ago Exited (-9) 12 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_1
(gaz@gMac)-(13:39:48)-(dockerlx)
$
I've tried playing around with some of the logic between getContainers() and listDockerVms() and making certain changes around the usage of opts.all has a clear effect but I'm not seeing where is has any relationship with filters. I also don't have a javascript plugin for my IDE to help understand what is going on better. Maybe someone else can shed some light?
@gbmeuk Nice digging - it is indeed the label filters where I think the sdc-docker code is causing a problem.
From the docker API docs:
https://docs.docker.com/engine/api/v1.23/#containers
some query parameters passed to docker ps API result in a check against all containers, whilst others are only against running containers, for example docker ps --limit 10
will return stopped containers (even though you did not pass the -a flag).
Now here's the rub, it seems that filter is special, it returns a match against all containers if you specify the status filter (docker ps --filter status=X), but not when you specify another filter like label (docker ps --filter label=Y). This is where sdc-docker gets it wrong, as even for label filters, it is returning against all matches.
The code that handles the specifics of this are here: https://github.com/joyent/sdc-docker/blob/master/lib/endpoints/containers.js#L89
I can write up a patch that should resolve this - ensuring the all flag is only set for status filters and not on all filters.
Should be solved with the above change.
Something is still differing. Running:
docker-compose ps
(gaz@gMac)-(12:54:52)-(dockerlx)
$docker-compose ps
SubjectAltNameWarning
Name Command State Ports
-------------------------------------------------------------------------------------------------------------------------------------------------
dockerlx_consul_1 /usr/local/bin/containerpi ... Exit 0 53/tcp, 53/udp, 8300/tcp,
8301/tcp, 8301/udp, 8302/tcp,
8302/udp, 8400/tcp,
0.0.0.0:8500->8500/tcp
dockerlx_consul_2 /usr/local/bin/containerpi ... Exit 1 53/tcp, 53/udp, 8300/tcp,
8301/tcp, 8301/udp, 8302/tcp,
8302/udp, 8400/tcp,
0.0.0.0:8500->8500/tcp
dockerlx_consul_3 /usr/local/bin/containerpi ... Exit 1 53/tcp, 53/udp, 8300/tcp,
8301/tcp, 8301/udp, 8302/tcp,
8302/udp, 8400/tcp,
0.0.0.0:8500->8500/tcp
(gaz@gMac)-(12:55:40)-(dockerlx)
$
performs the following API request (shown in sdc-docker logs)
GET /v1.22/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddockerlx%22%2C+%22com.docker.compose.oneoff%3DTrue%22%5D%7D&trunc_cmd=0&size=0 HTTP/1.1
As does docker-compose scale (runs with all=0)
(gaz@gMac)-(12:55:40)-(dockerlx)
$docker-compose scale consul=3
Desired container number already achieved
(gaz@gMac)-(12:57:44)-(dockerlx)
$
logs
GET /v1.22/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Ddockerlx%22%2C+%22com.docker.compose.service%3Dconsul%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0 HTTP/1.1
Whereas docker ps --all=false ... (with patch)
(gaz@gMac)-(13:00:22)-(dockerlx)
$docker ps --all=false -n=-1 --no-trunc=false --size=false --filter label=com.docker.compose.project=dockerlx -f label=com.docker.compose.service=consul -f label=com.docker.compose.oneoff=False
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
(gaz@gMac)-(13:00:51)-(dockerlx)
$
calls the API as follows
GET /v1.24/containers/json?filters=%7B%22label%22%3A%7B%22com.docker.compose.oneoff%3DFalse%22%3Atrue%2C%22com.docker.compose.project%3Ddockerlx%22%3Atrue%2C%22com.docker.compose.service%3Dconsul%22%3Atrue%7D%7D HTTP/1.1
and with --all=true
$docker ps --all=true -n=-1 --no-trunc=false --size=false --filter label=com.docker.compose.project=dockerlx -f label=com.docker.compose.service=consul -f label=com.docker.compose.oneoff=False
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
baac29e3c4cc mesoform/consul "/usr/local/bin/co..." 2 days ago Exited (1) 25 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_3
605b2a1884de mesoform/consul "/usr/local/bin/co..." 2 days ago Exited (1) 25 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_2
c194b140e193 mesoform/consul "/usr/local/bin/co..." 2 days ago Exited (0) 25 hours ago 53/tcp, 53/udp, 8300-8302/tcp, 8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp dockerlx_consul_1
(gaz@gMac)-(13:03:31)-(dockerlx)
$
calls
GET /v1.24/containers/json?all=1&filters=%7B%22label%22%3A%7B%22com.docker.compose.oneoff%3DFalse%22%3Atrue%2C%22com.docker.compose.project%3Ddockerlx%22%3Atrue%2C%22com.docker.compose.service%3Dconsul%22%3Atrue%7D%7D HTTP/1.1
@twhiteman @tgross @joshwilsdon, I'm afraid I don't seem to have the ability to reopen this issue. It seems like what was fixed was a related but different bug.
@gbmeuk Indeed, my bad - docker-compose scale still seems to be counting stopped containers.
Docker compose is passing limit=-1
, which is thus enabling the all
flag in sdc-docker.
Thanks. So how/why does limit=-1 enable the all flag?
@gbmeuk The docker API docs just say using limit enables all containers: https://docs.docker.com/engine/api/v1.23/#containers
and sdc-docker takes that literally, so if a limit (any limit) is used, it would filter against all containers: https://github.com/joyent/sdc-docker/blob/master/lib/endpoints/containers.js#L89
FYI, a sdc-docker change is under review here: https://cr.joyent.us/#/c/1441/
I am defeated by docker docs (useless for giving intent of options to /containers/json and/or docker ps
). The core logic seems to be in docker.git:daemon/list.go#foldFilter.
Closing, again... at least I tested it with docker-compose this time ;)
I can see it was understood that way. Validated working on my environment as well. Thanks.
I have found that there is a divergence in the state response returned from sdc-docker when compared to standard docker engine. This means that when running
docker-compose scale
correct checks against ''stopped=False'' in the docker-compose code is failing to correctly identify the number of running containers. For exampleRunning against sdc-docker
Whereas on docker-engine, this doesn't happen
We've noticed that there is a difference in the State object returned when inspecting the container.
On sdc-docker:
And on docker-engine:
We expect there is some mismatch with what is considered the current state with the Docker container state class