Rails server spams log due to getsockopt(2) TCP_INFO ENOPROTOPT

[ArsalanDotMe]

Microsoft Windows [Version 10.0.15063]

Clean installed rails 5.0.2 on Ruby 2.4.0 through rebenv 1.1.0-2-g4f8925a.
Went into a directory owned by Windows. Created a new project and started the server with rails s. The command was extremely slow to start and once it showed the following output, I made a simple GET request to localhost:3000.

/home/arsalan/.rbenv/versions/2.4.0/lib/ruby/gems/2.4.0/gems/railties-5.0.2/lib/rails/app_loader.rb:40: warning: Insecure world writable dir /home/arsalan/.rbenv/versions in PATH, mode 040777
=> Booting Puma
=> Rails 5.0.2 application starting in development on http://0.0.0.0:3000
=> Run `rails server -h` for more startup options
Puma starting in single mode...
* Version 3.8.1 (ruby 2.4.0-p0), codename: Sassy Salamander
* Min threads: 5, max threads: 5
* Environment: development
* Listening on tcp://0.0.0.0:3000
Use Ctrl-C to stop

On making the GET request, the following error showed up.

2017-04-22 11:40:02 +0500: Read error: #<Errno::ENOPROTOOPT: Protocol not available - getsockopt(2)>
/home/arsalan/.rbenv/versions/2.4.0/lib/ruby/gems/2.4.0/gems/puma-3.8.1/lib/puma/server.rb:124:in `getsockopt'
/home/arsalan/.rbenv/versions/2.4.0/lib/ruby/gems/2.4.0/gems/puma-3.8.1/lib/puma/server.rb:124:in `closed_socket?'
/home/arsalan/.rbenv/versions/2.4.0/lib/ruby/gems/2.4.0/gems/puma-3.8.1/lib/puma/server.rb:563:in `handle_request'
/home/arsalan/.rbenv/versions/2.4.0/lib/ruby/gems/2.4.0/gems/puma-3.8.1/lib/puma/server.rb:425:in `process_client'
/home/arsalan/.rbenv/versions/2.4.0/lib/ruby/gems/2.4.0/gems/puma-3.8.1/lib/puma/server.rb:289:in `block in run'
/home/arsalan/.rbenv/versions/2.4.0/lib/ruby/gems/2.4.0/gems/puma-3.8.1/lib/puma/thread_pool.rb:120:in `block in spawn_thread'

I don't know if strace of this command will be useful as it keeps continuously spitting out lines at the speed of light. Never exits.

The relevant error-throwing line from puma seems to be

socket.getsockopt(Socket::SOL_TCP, Socket::TCP_INFO)

[ArsalanDotMe]

It looks like the TCP_INFO option on the linux getsockopt(2) is not supported at this point.

Please see: TCP Options

TCP_INFO (since Linux 2.4)
Used to collect information about this socket. The kernel
returns a struct tcp_info as defined in the file
/usr/include/linux/tcp.h. This option should not be used in
code intended to be portable.

[sunilmut]

@ArsalanDotMe - Thanks for reporting the issue and the detailed information. Very helpful. Yes, we don't need the whole trace. You have already provided the relevant pieces. I can confirm that WSL currently does not implement the TCP_INFO socket option.

I have opened a task at our end to track this. Thanks again for trying WSL and providing feedback.

[guenard]

Just wanted to add that I got a similar log from PHP-FPM 5.6. ~ one line per second is written in /var/log/php5.6-fpm.log (TCP_INFO for socket: Protocol not available). Same as #2090.

[adamluzsi]

+1

[laughloudlylovelife]

+1

[sunilmut]

Can someone share clear (and if possible targeted) repro steps for this? I am looking into it right now and need that for validation.

[ArsalanDotMe]

I'm happy to provide more detailed reproduction steps, but looking at the first message in the thread, what do you think is missing in detail to reproduce the error? I tried to provide exact version numbers and steps for all software involved.

[sunilmut]

@ArsalanDotMe - Thanks. Yes, the first thread does provide the exact versions, but I was hoping to get exact instructions since I am not familiar with rails. That way, I can copy paste the instructions for the repro and focus on fixing the issue.

[ArsalanDotMe]

The guide I followed is this one: https://gorails.com/setup/windows/10

You don't need to setup mysql or postgres, otherwise the guide is the same.

[adamluzsi]

Hy @sunilmut ,

Here is a example repo where all you need is to install and run (or if you have both ruby and bundler all you need is to start the app).
I tried to create an install script but I couldn't test it because I'm not in wsl/ubuntu now.

I met with this too and the problem is about a yet not implemented socket protocol.
I can't confirm that the bug stills on, but if you clone the repo and run it and try call it with some http requests, than you can reproduce the problem.

[Marthyn]

👍
Ruby 2.2.4
Rails 4.2.7.1
Running bundle exec unicorn -p 5001

Results in
Protocol not available- setsockopt(2) (Errno::ENOPROTOOPT)