elixir-plug / plug

Compose web applications with functions
https://hex.pm/packages/plug
Other
2.85k stars 586 forks source link

Performance Regression in Plug.Conn.Cookies.decode/1 after Upgrading Elixir and Erlang #1227

Closed isavita closed 3 months ago

isavita commented 3 months ago

Description

After upgrading to Elixir 1.16.2 and Erlang 26.2.5, we have observed a significant performance regression in the Plug.Conn.Cookies.decode/1 function. The function is now approximately 4 times slower than it was in the previous versions of Elixir 1.14.3 and Erlang 24.3.2.8.

Benchmark Results

Elixir 1.14.3 / Erlang 24.3.2.8:

Benchmarking Plug.Conn.Cookies.decode/1 ...
Calculating statistics...
Formatting results...

Name                                      ips        average  deviation         median         99th %
Plug.Conn.Cookies.decode/1       12.54 K       79.74 μs    ±11.94%       75.71 μs      106.92 μs
Memory usage statistics:
Name                               Memory usage
Plug.Conn.Cookies.decode/1       134.95 KB

Elixir 1.16.2 / Erlang 26.2.5:

Benchmarking Plug.Conn.Cookies.decode/1 ...
Calculating statistics...
Formatting results...

Name                                      ips        average  deviation         median         99th %
Plug.Conn.Cookies.decode/1        3.42 K      292.65 μs    ±24.63%      291.38 μs      381.39 μs
Memory usage statistics:
Name                               Memory usage
Plug.Conn.Cookies.decode/1       263.25 KB
josevalim commented 3 months ago

Just to confirm, those are the same Plug versions, correct?

josevalim commented 3 months ago

And can you please provide the benchmarking code?

isavita commented 3 months ago

@josevalim Yes, the benchmark is on the same version

"plug": {:hex, :plug, "1.16.0", "1d07d50cb9bb05097fdf187b31cf087c7297aafc3fed8299aac79c128a707e47", [:mix], [{:mime, "~> 1.0 or ~> 2.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.1.1 or ~> 1.2 or ~> 2.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4.3 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "cbf53aa1f5c4d758a7559c0bd6d59e286c2be0c6a1fac8cc3eee2f638243b93e"},

The benchmark code (slightly modified but still shows 4x diff) is

defmodule Benchmark.CookieDecode do
  def run(_) do
    cookie =
    "a=1; b=111; b_exp=1738257503023; c=july2023; b=fsasfd1d46277134810r0.11893443256905789; d=b9d4ad1d-94dc-7fd6-ae1d-305e63791ac6; e=[%22somestuff%22]; fff={%22volume%22:0.7}; anotherstuff=hh; aaa3=hh; bbb={}; uii=somemorerandomstuf; hhhh=morestuff; kkk=eyJhYiI6Im8xOCIsInBhIjoiQ003IiwiZXAiOnRydWUsImV6IjpmYWxzZSwicGwiOmZhbHNlLCJwcyI6IjE0V2VDNElVaTRJaU9hSlp2NnpfM0tSMTJDMjE0NUU3UVN4SjZ4RHJRNG8iLCJjbCI6ZmFsc2UsImNjIjoiZ2IiLCJyZWFsbSI6Ii8iLCJzZXMtZXhwIjoxNzEyMDYzNzkwMDAwLCJqd3QtZXhwIjoxNzc1MTM0ODkwMDAwLCJydGtuLWV4cCI6MTc3NTEzNDg5MDAwMCwidGtuLWV4cCI6MTcxODgxNzMwMjAwMCwicG4iOjM5fQ; _chartbeat2=.1706277135627.1718810705253.0000001011000111.Cbuhe6BNM-tUCX5KjaCce88iBsBqeL.2; _cccc=Bfhgdfgd_dfsafsKKK; some_nonve=D9Uze6r1L5Cb9iZE8BXHXfMU; some_token=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxMjM0NTY3ODkwIiwibmFtZSI6IkpvaG4gRG8gbGRqa2Zza2xyZWpmYXNsa2RmamtzamFma2RsanNrYWxmamRza2xqZmtsZHNqZmtsZHNqZmtsYWpza2xkZmpzYWZkcyBNYWtlIHRoaXMgYXMgYmlnIGFzIHBvc3NpYmxlLkVsaXhpciBpcyBhIGR5bmFtaWMsIGZ1bmN0aW9uYWwgbGFuZ3VhZ2UgZGVzaWduZWQgZm9yIGJ1aWxkaW5nIHNjYWxhYmxlIGFuZCBtYWludGFpbmFibGUgYXBwbGljYXRpb25zLiBJdCBsZXZlcmFnZXMgdGhlIEVybGFuZyBWTSwga25vd24gZm9yIHJ1bm5pbmcgbG93LWxhdGVuY3ksIGRpc3RyaWJ1dGVkLCBhbmQgZmF1bHQtdG9sZXJhbnQgc3lzdGVtcy4gICAgIEVsaXhpciBpcyBhIGR5bmFtaWMsIGZ1bmN0aW9uYWwgbGFuZ3VhZ2UgZGVzaWduZWQgZm9yIGJ1aWxkaW5nIHNjYWxhYmxlIGFuZCBtYWludGFpbmFibGUgYXBwbGljYXRpb25zLiBJdCBsZXZlcmFnZXMgdGhlIEVybGFuZyBWTSwga25vd24gZm9yIHJ1bm5pbmcgbG93LWxhdGVuY3ksIGRpc3RyaWJ1dGVkLCBhbmQgZmF1bHQtdG9sZXJhbnQgc3lzdGVtcy5FbGl4aXIgaXMgYSBkeW5hbWljLCBmdW5jdGlvbmFsIGxhbmd1YWdlIGRlc2lnbmVkIGZvciBidWlsZGluZyBzY2FsYWJsZSBhbmQgbWFpbnRhaW5hYmxlIGFwcGxpY2F0aW9ucy4gSXQgbGV2ZXJhZ2VzIHRoZSBFcmxhbmcgVk0sIGtub3duIGZvciBydW5uaW5nIGxvdy1sYXRlbmN5LCBkaXN0cmlidXRlZCwgYW5kIGZhdWx0LXRvbGVyYW50IHN5c3RlbXMuIiwiaWF0IjoxNTE2MjM5MDIyfQ.g_440sF_734II0EyaWnOCI-nmM-AbQ41JPfl8gnv6Ow; kkktkn=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxMjM0NTY3ODkwIiwibmFtZSI6IkpvaG4gRG9lIiwiaWF0IjoxNTE2MjM5MDIyfQ.SflKxwRJSMeKKF2QT4fwpMeJf36POk6yJV_adQssw5c; idid=Elixir%20is%20a%20dynamic%2C%20functional%20language%20designed%20for%20building%20scalable%20and%20maintainable%20applications.%20It%20leverages%20the%20Erlang%20VM%2C%20known%20for%20running%20low-latency%2C%20distributed%2C%20and%20fault-tolerant%20systems; _aaaa=random; TTT_fdsdfd=1; HHH_fdsfds=1"

    Benchee.run(
      %{
      "Plug.Conn.Cookies.decode/1" => fn ->
        Plug.Conn.Cookies.decode(cookie)
      end
      },
      time: 5,
      memory_time: 2
    )
  end
end