systemd AF_UNIX domain socket activation not working #1976

risen · 2019-09-18T21:18:22Z

Even though I try to follow the guide at: systemd.md, if the systemd hellopuma.socket file is started first and creates an AF_UNIX domain socket file, then the hellopuma.service fails with:

Sep 18 22:53:17 gretel hellopuma[13387]: /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/binder.rb:377:in `add_unix_listener': There is already a server bound to: puma.sock (RuntimeError)

systemd config

using a per-user systemd instance, using loginctl enable-linger user and systemctl --user …

[Unit]
Description=hellopuma service
After=network.target
Requires=hellopuma.socket

[Service]
Type=simple
Environment=PUMA_DEBUG=1
WorkingDirectory=/srv/user/hellopuma
ExecStart=/srv/user/.gem/ruby/2.5.0/bin/puma -b unix://puma.sock hello.ru
ExecReload=/bin/kill -USR2
Restart=always
SyslogIdentifier=hellopuma

[Install]
WantedBy=multi-user.target

[Unit]
Description=hellopuma socket

[Socket]
ListenStream=/srv/user/hellopuma/puma.sock
Backlog=1024

[Install]
WantedBy=sockets.target

rack application

run lambda { |env| [200, {"Content-Type" => "text/plain"}, ["Hello World"]] }

expected behavior

Puma takes over/binds to systemd's AF_UNIX domain socket file

used versions

ruby: 2.5.5p157 (and 2.6.3)
OS: Debian GNU/Linux 10 (buster)
puma: 4.1.1

full log

Sep 18 22:53:17 gretel systemd[5700]: Started hellopuma service.
Sep 18 22:53:17 gretel hellopuma[13387]: % Registered unix:/srv/user/hellopuma/puma.sock for activation from LISTEN_FDS
Sep 18 22:53:17 gretel hellopuma[13387]: Puma starting in single mode...
Sep 18 22:53:17 gretel hellopuma[13387]: * Version 4.1.1 (ruby 2.5.5-p157), codename: Fourth and One
Sep 18 22:53:17 gretel hellopuma[13387]: * Min threads: 0, max threads: 16
Sep 18 22:53:17 gretel hellopuma[13387]: * Environment: development
Sep 18 22:53:17 gretel hellopuma[13387]: /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/binder.rb:377:in `add_unix_listener': There is already a server bound to: puma.sock (RuntimeError)
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/binder.rb:148:in `block in parse'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/binder.rb:97:in `each'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/binder.rb:97:in `parse'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/runner.rb:154:in `load_and_bind'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/single.rb:98:in `run'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/launcher.rb:188:in `run'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/lib/puma/cli.rb:80:in `run'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/gems/puma-4.1.1/bin/puma:10:in `<top (required)>'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/bin/puma:23:in `load'
Sep 18 22:53:17 gretel hellopuma[13387]:         from /srv/user/.gem/ruby/2.5.0/bin/puma:23:in `<main>'
Sep 18 22:53:17 gretel systemd[5700]: hellopuma.service: Main process exited, code=exited, status=1/FAILURE
Sep 18 22:53:17 gretel systemd[5700]: hellopuma.service: Failed with result 'exit-code'.
Sep 18 22:53:18 gretel systemd[5700]: hellopuma.service: Service RestartSec=100ms expired, scheduling restart.
Sep 18 22:53:18 gretel systemd[5700]: hellopuma.service: Scheduled restart job, restart counter is at 5.
Sep 18 22:53:18 gretel systemd[5700]: Stopped hellopuma service.
Sep 18 22:53:18 gretel systemd[5700]: hellopuma.service: Start request repeated too quickly.
Sep 18 22:53:18 gretel systemd[5700]: hellopuma.service: Failed with result 'exit-code'.
Sep 18 22:53:18 gretel systemd[5700]: Failed to start hellopuma service.

The text was updated successfully, but these errors were encountered:

dentarg · 2019-09-18T22:49:59Z

Same as #1842 (#1775)? If so, the fix, #1970, will be released in 4.2.0.

Are you able to try the master branch and see if there still is a problem?

risen · 2019-09-19T00:01:27Z

Just tried with master, same error:

Sep 19 01:46:43 gretel hellopuma[18420]: /srv/user/.gem/ruby/2.5.0/gems/puma-4.2.0/lib/puma/binder.rb:378:in `add_unix_listener': There is already a server bound to: puma.sock (RuntimeError)

The code around there is this:

        if File.exist? path
          begin
            old = UNIXSocket.new path
          rescue SystemCallError, IOError
            File.unlink path
          else
            old.close
            raise "There is already a server bound to: #{path}"
          end
        end

        s = UNIXServer.new(path)

… UNIXSocket.new('puma.sock') doesn't raise an exception until you do somethin with it, not sure how this check is supposed to work.

nateberkopec · 2019-09-19T11:45:22Z

👋 I've just committed an example Dockerfile to the repo: 58acb80

If you could kindly construct a Dockerfile that reproduces the issue, we can nail down the problem 👍

rromanchuk · 2019-09-19T22:13:36Z

@nateberkopec i need to do this too #1970 (comment)

nateberkopec · 2019-09-20T09:24:10Z

👍

risen · 2019-09-20T13:10:12Z

I'm not sure what you're asking… this is about socket activation with systemd. Running systemd in a Docker container is pretty difficult, Docker and systemd don't play nice together (see: https://lwn.net/Articles/676831/ for example).

Also, did you intend to close this issue?

nateberkopec · 2019-09-20T13:26:38Z

whoops, I did not

nateberkopec · 2019-09-20T13:27:43Z

@risen Ah I didn't know that. I guess I'll have to repro on AWS or something then, as I don't have access to a physical Linux machine.

dentarg · 2019-09-20T14:16:26Z

Vagrant is pretty sweet for stuff like this

sorah · 2020-01-23T17:39:33Z

try -b unix:/srv/user/hellopuma/puma.sock

risen · 2020-05-26T10:45:46Z

I've just tried again with version 4.3.5, and it seems to work now.

The socket triggers the service, as expected. Puma mentions LISTEN_FDS on startup:

May 26 12:36:52 pino hellopuma[49388]: % Registered unix:/srv/user/hellopuma/hellopuma.sock for activation from LISTEN_FDS
May 26 12:36:52 pino hellopuma[49388]: Puma starting in single mode...
May 26 12:36:52 pino hellopuma[49388]: * Version 4.3.5 (ruby 2.6.6-p146), codename: Mysterious Traveller
May 26 12:36:52 pino hellopuma[49388]: * Min threads: 0, max threads: 16
May 26 12:36:52 pino hellopuma[49388]: * Environment: development
May 26 12:36:52 pino hellopuma[49388]: * Activated unix:///srv/user/hellopuma/hellopuma.sock
May 26 12:36:52 pino hellopuma[49388]: Use Ctrl-C to stop

For completeness sake, here's my ~/.config/systemd/user/hellopuma.service

[Unit]
Description=hellopuma service
After=network.target
Requires=hellopuma.socket

[Service]
Type=simple
Environment=PUMA_DEBUG=1
WorkingDirectory=/srv/user/hellopuma
ExecStart=/usr/bin/rbenv exec bundle exec puma --bind "unix:///srv/user/hellopuma/hellopuma.sock" --pidfile /srv/user/hellopuma/hellopuma.pid hellopuma.ru
Restart=always
SyslogIdentifier=hellopuma

[Install]
WantedBy=multi-user.target

And my ~/.config/systemd/user/hellopuma.socket:

[Unit]
Description=hellopuma socket

[Socket]
ListenStream=/srv/user/hellopuma/hellopuma.sock
Backlog=1024

[Install]
WantedBy=sockets.target

I'm not sure in which version this issue got resolved, but thanks for fixing this.

nateberkopec added docs needs-repro systemd and removed docs labels Sep 19, 2019

MSP-Greg mentioned this issue Sep 19, 2019

Update test_integration files per PR #1956 #1965

Merged

nateberkopec closed this as completed Sep 20, 2019

nateberkopec reopened this Sep 20, 2019

MSP-Greg mentioned this issue Sep 24, 2019

Socket removed after reload, part II #1842

Closed

nateberkopec mentioned this issue Mar 8, 2020

systemd, Binder#import_from_env, Binder#inherit_unix_listener #1881

Closed

dentarg mentioned this issue May 2, 2020

Cannot get puma to work with systemctl when configured for multiple workers #2246

Closed

nateberkopec added the contrib-wanted label May 8, 2020

risen closed this as completed May 26, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

systemd AF_UNIX domain socket activation not working #1976

systemd AF_UNIX domain socket activation not working #1976

risen commented Sep 18, 2019

dentarg commented Sep 18, 2019

risen commented Sep 19, 2019

nateberkopec commented Sep 19, 2019

rromanchuk commented Sep 19, 2019

nateberkopec commented Sep 20, 2019

risen commented Sep 20, 2019

nateberkopec commented Sep 20, 2019

nateberkopec commented Sep 20, 2019 •

edited

dentarg commented Sep 20, 2019

sorah commented Jan 23, 2020

risen commented May 26, 2020

systemd AF_UNIX domain socket activation not working #1976

systemd AF_UNIX domain socket activation not working #1976

Comments

risen commented Sep 18, 2019

systemd config

rack application

expected behavior

used versions

full log

dentarg commented Sep 18, 2019

risen commented Sep 19, 2019

nateberkopec commented Sep 19, 2019

rromanchuk commented Sep 19, 2019

nateberkopec commented Sep 20, 2019

risen commented Sep 20, 2019

nateberkopec commented Sep 20, 2019

nateberkopec commented Sep 20, 2019 • edited

dentarg commented Sep 20, 2019

sorah commented Jan 23, 2020

risen commented May 26, 2020

nateberkopec commented Sep 20, 2019 •

edited