shutdown signal ServerUnix

[tiolan]

Hey, I am using the following code for my own Docker log-plugin:

package main
import (
    "fmt"
    "github.com/docker/go-plugins-helpers/sdk"
)
func main() {
    h := sdk.NewHandler('{"Implements": ["LoggingDriver"]}')
    handlers(&h, newDriver())
    if err := h.ServeUnix("logdriver", 0); err != nil {
        fmt.Println("Ending Go main with PANIC")
        panic(err)
    }
    fmt.Println("Ending Go main")
}

It seems, that ServeUnix is the blocking call, as it does not return. I would expect, that when invoking docker plugin disable driver:v1, it returns and one of the lines

"Ending Go main with PANIC"

or

"Ending Go main"

is visible in the stdout of the plugin (meaning in the logs of Dockerd). Note: I can see other logs from this plugin using fmt.Println in Dockerd logs, so logging works.

I guess, that ServeUnix does not handle shutdown signals. Do I need to do it manually?

BTW: In the documentation of server.Serve, which is called inside sdk.ServeUnix, they say:

Serve always returns a non-nil error. After Shutdown or Close, the returned error is ErrServerClosed.

So, is the if err := h.ServeUnix("logdriver", 0); err != nil { wrong?

[thaJeztah]

@cpuguy83 ptal

[cpuguy83]

Are you sure you aren't running the plugin with /bin/sh? Signal handlers are setup by Go. In some cases, at least in other languages, the default signal handlers are dropped when a process is run as PID1 (e.g. /bin/sh does this), but I don't recall that being my experience with go.

[cpuguy83]

So, is the if err := h.ServeUnix("logdriver", 0); err != nil { wrong?

If you want to not panic on a legitimate ErrClosed, then yep it's wrong 😄

[tiolan]

No I do not run it manually using sh. I use docker plugin create and docker plugin enable to run it. With the binary specified as entrypoint in the plugin config.json. Any other thoughts?

[cpuguy83]

@tiolan I'm referring to how it's actually getting execute in the container. If the entrypont is specified as a string, instead of a []string, docker will execute it with /bin/sh -c <ENTRYPOINT>... at least it does for normal containers, I can't recall if that's true for plugins. Anyway you should be able to ps faux on the system and see the process hierarchy.

[tiolan]

@cpuguy83 Now I got your point, sorry.

The entrypoint looks like this: "entrypoint": ["/usr/bin/docker-log-driver"], so should be a []string, right?

It seems not to be running under /bin/sh -c. ps faux gave me this (sorry seems formatting is not kept here):

root 28620 1.3 0.3 797236 70684 ? Ssl 08:58 0:23 /usr/bin/dockerd -H fd:// root 28661 0.2 0.1 858848 27912 ? Ssl 08:58 0:04 _ containerd --config /var/run/docker/containerd/containerd.toml --log-level debug root 31092 0.0 0.0 109100 5096 ? Sl 09:16 0:00 _ containerd-shim -namespace plugins.moby -workdir /var/lib/docker/containerd/daemon/io.containerd.runtime.v1.linux/plugins.moby/43f91e4abd38f1b1a500d7276a0022287a5ae08e833464ba61d62e41fdaff5a5 -address /var/run/docker/containerd/containerd.sock -containerd-binary /usr/bin/containerd -runtime-root /run/docker/plugins/runtime-root -debug root 31119 0.0 0.0 647832 11100 ? Ssl 09:16 0:00 | _ /usr/bin/docker-log-driver root 31218 0.0 0.0 107692 5764 ? Sl 09:16 0:00 _ containerd-shim -namespace moby -workdir /var/lib/docker/containerd/daemon/io.containerd.runtime.v1.linux/moby/d57ca7f983bd81678ef7934f6a97b701774f3a31d35a46ad4d4e06195d4fe024 -address /var/run/docker/containerd/containerd.sock -containerd-binary /usr/bin/containerd -runtime-root /var/run/docker/runtime-runc -debug root 31242 0.0 0.0 1644 4 pts/0 Ss+ 09:16 0:00 _ sh

I did another test: I run the executable/entrypoint manually like ./docker-log-driver directly on the host and then stopped it by pressing Ctrl-C. It was immediately stoped. Did not see the expected logs either.

Any other thing that comes to your mind?

[GSeibt]

Hey,

looking at the documentation, it seems to me that, by default, any SIGINT or SIGTERM received by the program will kill it immediately. That is why deferred methods do not run. This includes for example the removal of the automatically created socket: https://github.com/docker/go-plugins-helpers/blob/c9a8a2d92ccca898008b580693c4a688963575b1/sdk/handler.go#L64

The correct way to handle this would be following this example and calling the http.Server#Shutdown method on on the Server created in Handler#Serve. https://github.com/docker/go-plugins-helpers/blob/c9a8a2d92ccca898008b580693c4a688963575b1/sdk/handler.go#L33

A user of this library can't do that however since that reference is not available outside.

I have rewritten the Handler#Serve method to correctly shutdown when SIGINT or SIGTERM is received.

What do you think?

[tiolan]

Hey @GSeibt , looks very promising. Looking forward to completion of the PR.