[🐛 BUG]: panic in http plugin

[cto-asocial]

No duplicates 🥲.

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

What happened?

From time to time I can see rr panic in logs.

Version (rr --version)

rr version 2023.3.12 (build time: 2024-02-29T18:24:06+0000, go1.22.0), OS: linux, arch: amd64

How to reproduce the issue?

No idea how to reproduce, seems like it happens randomly

# HTTP plugin settings.
http:
  address: 0.0.0.0:8080

  # Maximal incoming request size in megabytes. Zero means no limit.
  #
  # Default: 0
  max_request_size: 16

  # Send raw body (unescaped) to the PHP worker for the application/x-www-form-urlencoded content type
  #
  # Optional, default: false
  raw_body: true

  # Middlewares for the http plugin, order is important. Allowed values is: "headers", "gzip", "static", "sendfile",  [SINCE 2.6] -> "new_relic", [SINCE 2.6] -> "http_metrics", [SINCE 2.7] -> "cache"
  #
  # Default value: []
  middleware: [ "gzip", "http_metrics" ]

  # Workers pool settings.
  pool:
    # Debug mode for the pool. In this mode, pool will not pre-allocate the worker. Worker (only 1, num_workers ignored) will be allocated right after the request arrived.
    #
    # Default: false
    debug: false

    # How many worker processes will be started. Zero (or nothing) means the number of logical CPUs.
    #
    # Default: 0
    num_workers: 4

    # Maximal count of worker executions. Zero (or nothing) means no limit.
    #
    # Default: 0
    max_jobs: 0

    # Timeout for worker allocation. Zero means 60s.
    #
    # Default: 60s
    allocate_timeout: 60s

    # Timeout for the reset timeout. Zero means 60s.
    #
    # Default: 60s
    reset_timeout: 60s

    # Timeout for worker destroying before process killing. Zero means 60s.
    #
    # Default: 60s
    destroy_timeout: 60s

    # Supervisor is used to control http workers (previous name was "limit", video: https://www.youtube.com/watch?v=NdrlZhyFqyQ).
    # "Soft" limits will not interrupt current request processing. "Hard"
    # limit on the contrary - interrupts the execution of the request.
    supervisor:
      # How often to check the state of the workers.
      #
      # Default: 1s
      watch_tick: 15s

      # Maximum time worker is allowed to live (soft limit). Zero means no limit.
      #
      # Default: 0s
      ttl: 0s

      # How long worker can spend in IDLE mode after first using (soft limit). Zero means no limit.
      #
      # Default: 0s
      idle_ttl: 0s

      # Maximal worker memory usage in megabytes (soft limit). Zero means no limit.
      #
      # Default: 0
      max_worker_memory: 256

      # Maximal job lifetime (hard limit). Zero means no limit.
      #
      # Default: 0s
      exec_ttl: 60s

# Application metrics in Prometheus format (docs: https://roadrunner.dev/docs/plugins-metrics/3.x/en). Drop this section
# for this feature disabling.
metrics:
  # Prometheus client address (path /metrics added automatically).
  #
  # Default: "127.0.0.1:2112"
  address: 0.0.0.0:2112

Relevant log output

{
  "level": "error",
  "ts": 1713874889354486800,
  "logger": "http",
  "msg": "internal server error",
  "message": "http_plugin: 2024/04/23 12:21:29 http: panic serving 10.32.35.12:34376: interface conversion: interface {} is nil, not []uint8\ngoroutine 22231 [running]:\nnet/http.(*conn).serve.func1()\n\tnet/http/server.go:1898 +0xbe\npanic({0x1b529e0?, 0xc001b44840?})\n\truntime/panic.go:770 +0x132\ngithub.com/roadrunner-server/http/v4/handler.(*Request).Payload(...)\n\tgithub.com/roadrunner-server/http/[email protected]/handler/request.go:172\ngithub.com/roadrunner-server/http/v4/handler.(*Handler).ServeHTTP(0xc0008763c0, {0x24dca20, 0xc00153e480}, 0xc00135dd40)\n\tgithub.com/roadrunner-server/http/[email protected]/handler/handler.go:149 +0x1c89\ngithub.com/roadrunner-server/http/v4.(*Plugin).ServeHTTP(0xc0007fed20, {0x24dca20, 0xc00153e480}, 0xc00135dd40)\n\tgithub.com/roadrunner-server/http/[email protected]/plugin.go:205 +0x487\ngithub.com/roadrunner-server/http/v4.(*Plugin).applyBundledMiddleware.MaxRequestSize.func1({0x24dca20, 0xc00153e480}, 0xc00135dc20)\n\tgithub.com/roadrunner-server/http/[email protected]/middleware/maxRequest.go:15 +0xb6\nnet/http.HandlerFunc.ServeHTTP(0xc00135d9e0?, {0x24dca20?, 0xc00153e480?}, 0x1da7300?)\n\tnet/http/server.go:2166 +0x29\ngithub.com/roadrunner-server/http/v4.(*Plugin).applyBundledMiddleware.NewLogMiddleware.(*lm).Log.func5({0x24dd0b0, 0xc00083cc00}, 0xc00135d9e0)\n\tgithub.com/roadrunner-server/http/[email protected]/middleware/log.go:125 +0x16d\nnet/http.HandlerFunc.ServeHTTP(0x10?, {0x24dd0b0?, 0xc00083cc00?}, 0x7f979473f900?)\n\tnet/http/server.go:2166 +0x29\ngithub.com/roadrunner-server/gzip/v4.(*Plugin).Middleware.func1({0x24dd0b0, 0xc00083cc00}, 0xc00135d9e0)\n\tgithub.com/roadrunner-server/gzip/[email protected]/plugin.go:43 +0x449\nnet/http.HandlerFunc.ServeHTTP(0x0?, {0x24dd0b0?, 0xc00083cc00?}, 0x4?)\n\tnet/http/server.go:2166 +0x29\ngithub.com/klauspost/compress/gzhttp.NewWrapper.func1.1({0x24dcb10, 0xc000c92648}, 0xc00135d9e0)\n\tgithub.com/klauspost/[email protected]/gzhttp/compress.go:501 +0x453\nnet/http.HandlerFunc.ServeHTTP(0xc00081c0e0?, {0x24dcb10?, 0xc000c92648?}, 0x10?)\n\tnet/http/server.go:2166 +0x29\ngithub.com/roadrunner-server/prometheus/v4.(*Plugin).Middleware.func1({0x24dba60, 0xc001b4a1c0}, 0xc00135d9e0)\n\tgithub.com/roadrunner-server/prometheus/[email protected]/plugin.go:131 +0x567\nnet/http.HandlerFunc.ServeHTTP(0xc001b44660?, {0x24dba60?, 0xc001b4a1c0?}, 0x6?)\n\tnet/http/server.go:2166 +0x29\nnet/http.serverHandler.ServeHTTP(...)\n\tnet/http/server.go:3137\nnet/http.(*conn).serve(0xc0017e4e10, {0x24e0368, 0xc0008c01e0})\n\tnet/http/server.go:2039 +0x651\ncreated by net/http.(*Server).Serve in goroutine 86\n\tnet/http/server.go:3285 +0x4b4\n"
}

[rustatian]

Hey @cto-asocial 👋
Fixed. Fix version 2024.1.1 (planned release date: next week).

[rustatian]

Keep in mind, that to have better perf, with versions v2024.x.x you need to install protobuf extension from pecl (or compile it by yourself, or using your favorite method).

[cto-asocial]

Hi, @rustatian! Appreciate for the speed!

I've already tried to migrate to v2024.1.0, but got this error

{
  "message": "Uncaught Exception: Control character error, possibly incorrectly encoded",
  "context": {
    "exception": {
      "class": "JsonException",
      "message": "Control character error, possibly incorrectly encoded",
      "code": 3,
      "file": "/app/vendor/spiral/roadrunner-http/src/HttpWorker.php:77"
    }
  },
  "level": 500,
  "level_name": "CRITICAL",
  "channel": "php",
  "datetime": "2024-04-15T09:26:13.515142+00:00",
  "extra": {}
}

Upgrade was without any changes in RR config or environment, just bump RR version + protobuf from pecl.

I'll go deeper after 2024.1.1 released, but maybe you have ideas where to start from ?

[rustatian]

You need to update PHP packages as well: https://docs.roadrunner.dev/general/compatibility#upgrading-to-rr-v2024.x.x

[cto-asocial]

I'll try and let you know, thanks!