[🐛 BUG]: Socket errors during workers restarting

[tarampampam]

No duplicates 🥲.

• I have searched for a similar issue in our bug tracker and didn't find any solutions.

What happened?

When the socket is used as a relay and http.pool.max_jobs are limited, during wrk tests there are a lot of errors in the RR logs and failed requests. With relay type pipes or without jobs limiting (http.pool.max_jobs: 0) all works fine.

$ wrk -t12 -c50 -d30s http://127.0.0.1:8080/
Running 30s test @ http://127.0.0.1:8080/
  12 threads and 50 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   304.27ms  298.83ms   2.00s    85.54%
    Req/Sec    23.41     24.79   151.00     90.27%
  5611 requests in 30.09s, 94.04MB read
  Socket errors: connect 0, read 0, write 0, timeout 19
  Non-2xx or 3xx responses: 131 # <--- FAILED REQUESTS
Requests/sec:    186.45
Transfer/sec:      3.12MB

Playground: https://github.com/tarampampam/laravel-roadrunner-in-docker

Relay: pipes, http.pool.max_jobs: 64

Without errors.

wrk -t12 -c100 -d30s http://127.0.0.1:8080/
Running 30s test @ http://127.0.0.1:8080/
  12 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   182.49ms  112.73ms 690.92ms   76.60%
    Req/Sec    49.36     30.75   161.00     74.48%
  16332 requests in 30.09s, 280.20MB read
Requests/sec:    542.70
Transfer/sec:      9.31MB

Relay: socket, http.pool.max_jobs: 0

Without errors.

wrk -t12 -c100 -d30s http://127.0.0.1:8080/
Running 30s test @ http://127.0.0.1:8080/
  12 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    75.84ms   10.54ms 177.28ms   64.45%
    Req/Sec   105.66     19.06   161.00     69.88%
  37984 requests in 30.09s, 651.69MB read
Requests/sec:   1262.34
Transfer/sec:     21.66MB

Relay: pipes, http.pool.max_jobs: 0

Without errors.

wrk -t12 -c100 -d30s http://127.0.0.1:8080/
Running 30s test @ http://127.0.0.1:8080/
  12 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    79.44ms   10.35ms 142.01ms   67.85%
    Req/Sec   100.87     17.39   161.00     63.25%
  36229 requests in 30.10s, 621.57MB read
Requests/sec:   1203.48
Transfer/sec:     20.65MB

Version

2.7.8

Relevant log output

web_1       | 2022-02-14T07:42:23.354Z  INFO    http            http access log {"status": 200, "method": "GET", "URI": "http://127.0.0.1:8080/", "remote_address": "172.23.0.1", "query": "", "content_len": 0, "host": "127.0.0.1:8080", "user_agent": "", "referer": "", "time_local": "14/Feb/22:07:42:23 +0000", "request_time": "2022-02-14T07:42:23.354Z", "start": "2022-02-14T07:42:23.242Z", "elapsed": "111.671259ms"}
web_1       | 2022-02-14T07:42:23.356Z  INFO    server          In SocketRelay.php line 190:
web_1       |                                                      
web_1       | 
web_1       | 2022-02-14T07:42:23.357Z  WARN    server          network error, worker will be restarted {"reason": "network", "pid": 1084, "internal_event_name": "EventWorkerError", "error": "sync_worker_exec_worker_with_timeout: Network:\n\tsync_worker_exec_payload: read unix /var/run/rr/rr-relay.sock->@: read: connection reset by peer"}
web_1       | 2022-02-14T07:42:23.357Z  DEBUG   server          worker stopped  {"internal_event_name": "EventWorkerWaitExit", "error": "signal: killed; process_wait: signal: killed", "errorCauses": [{"error": "signal: killed"}, {"error": "process_wait: signal: killed"}]}
web_1       | 2022-02-14T07:42:23.357Z  ERROR   http            execute {"start": "2022-02-14T07:42:23.243Z", "elapsed": "114.629788ms", "error": "supervised_exec_with_context: Network:\n\tsync_worker_exec_worker_with_timeout:\n\tsync_worker_exec_payload: read unix /var/run/rr/rr-relay.sock->@: read: connection reset by peer"}
web_1       | 2022-02-14T07:42:23.357Z  INFO    server            Unable to read frame header: No error information  
web_1       | 
web_1       | 2022-02-14T07:42:23.357Z  INFO    server                                                               
web_1       | 
web_1       | start [--laravel-path [LARAVEL-PATH]] [--relay-dsn RELAY-DSN] [--refresh-app] [--worker-mode WORKER-MODE]
web_1       | 
web_1       | 
web_1       | 2022-02-14T07:42:23.358Z  DEBUG   server          worker stopped  {"internal_event_name": "EventWorkerWaitExit", "error": "signal: killed; process_wait: signal: killed", "errorCauses": [{"error": "signal: killed"}, {"error": "process_wait: signal: killed"}]}