Bug #17437

connecting from controller using nginx <-> api

Added by Nico César about 2 months ago. Updated about 16 hours ago.

Status:
Rejected
Priority:
Normal
Assigned To:
Category:
-
Start date:
04/20/2021
Due date:
% Done:

100%

Estimated time:
(Total: 0.00 h)
Story points:
-

Description

If RailsAPI is deployed using WEBrick -- which is the "default development web server" for rails, although it is not a good idea to run it in production and it is not used in our usual test/dev setups -- and the arvados configuration indicates controller should connect directly to WEBrick without going through an Nginx proxy, then WEBrick does not decode controller requests properly.

See details below. tl;dr: this appears to be caused by WEBrick's improper handling of HTTP/1.1 Transfer-Encoding and Content-Length headers. The problem can be avoided by proxying requests through Nginx, which defaults to HTTP/1.0 for upstream proxy requests... or by not using WEBrick at all.


this is the nginx configuration

upstream api_upstream {
  # This matches the port where the api rails app is listening
  # in docker-compose.yml
  server api:8004 fail_timeout=10s;
}
server {
    listen 8084;
    server_name nginx-api;
    client_max_body_size 128m;

    location / {
        proxy_pass http://api_upstream;
        proxy_read_timeout 300;
        proxy_connect_timeout 90;
        # From https://www.phusionpassenger.com/library/deploy/standalone/reverse_proxy.html
        proxy_http_version 1.1;
        proxy_set_header Host $http_host;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection $connection_upgrade;
        proxy_buffering off;

        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        # proxy_redirect off;
        # proxy_set_header X-Forwarded-Proto https;
        # proxy_set_header X-Real-IP $remote_addr;
        # proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
    }
}

if we have this in arvados config:

      RailsAPI:
        InternalURLs:
          # WE need to pass requests through nginx, or bad things will happen
          'http://nginx-api:8084': {}

request go thru with no issue:

# arv --format=uuid group create --group '{"owner_uuid":"z1119-tpzed-000000000000000", "group_class":"project", "name":"Arvados Standard Docker 10"}'
z1119-j7d0g-qbsbvbmen4mhdck

This is what rails API sees:

[req-9tfluusd20d015sgr5uf] {"CONTENT_LENGTH"=>"130", "CONTENT_TYPE"=>"application/json", "GATEWAY_INTERFACE"=>"CGI/1.1", "PATH_INFO"=>"/arvados/v1/groups", "QUERY_STRING"=>"_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", "REMOTE_ADDR"=>"192.168.48.4", "REMOTE_HOST"=>"192.168.48.4", "REQUEST_METHOD"=>"POST", "REQUEST_URI"=>"https://z1119.arv.local:8000/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", "SCRIPT_NAME"=>"", "SERVER_NAME"=>"z1119.arv.local", "SERVER_PORT"=>"8000", "SERVER_PROTOCOL"=>"HTTP/1.1", "SERVER_SOFTWARE"=>"WEBrick/1.6.0 (Ruby/2.7.2/2020-10-01)", "HTTP_HOST"=>"z1119.arv.local:8000", "HTTP_CONNECTION"=>"close", "HTTP_X_REAL_IP"=>"192.168.48.14", "HTTP_X_FORWARDED_FOR"=>"192.168.48.5,192.168.48.4:52266, 192.168.48.14", "HTTP_USER_AGENT"=>"arvados-cli/1.0 google-api-ruby-client/0.8.7.4 Linux/5.10.0-3-amd64 (gzip)", "HTTP_ACCEPT"=>"application/json", "HTTP_AUTHORIZATION"=>"OAuth2 v2/z1119-gj3su-rkahytczn9o7wf1/1bxebbjmt92479f7c169q5wcxgz0yewuw839fs666a3qj6wi5k", "HTTP_VIA"=>"HTTP/1.0 arvados-controller", "HTTP_X_FORWARDED_PROTO"=>"https", "HTTP_X_REQUEST_ID"=>"req-9tfluusd20d015sgr5uf", "HTTP_ACCEPT_ENCODING"=>"gzip", "rack.version"=>[1, 3], "rack.input"=>#<StringIO:0x00007f846050d908>, "rack.errors"=>#<IO:<STDERR>>, "rack.multithread"=>true, "rack.multiprocess"=>false, "rack.run_once"=>false, "rack.url_scheme"=>"http", "rack.hijack?"=>true, "rack.hijack"=>#<Proc:0x00007f846050d890 /cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/handler/webrick.rb:83 (lambda)>, "rack.hijack_io"=>nil, "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_PATH"=>"/arvados/v1/groups", "action_dispatch.parameter_filter"=>[:password, :password], "action_dispatch.redirect_filter"=>[], "action_dispatch.secret_token"=>nil, "action_dispatch.secret_key_base"=>"ezx6lj8ro3f0joezenqcdn319dwsgdh8z7c7m3unwyg4y3qmg", "action_dispatch.show_exceptions"=>true, "action_dispatch.show_detailed_exceptions"=>true, "action_dispatch.logger"=>#<ActiveSupport::Logger:0x0000560ae23d1ad8 @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x0000560ae23d1a10 @datetime_format=nil>, @formatter=#<ActiveSupport::Logger::SimpleFormatter:0x0000560ae2a15908 @datetime_format=nil, @thread_key="activesupport_tagged_logging_tags:10520">, @logdev=#<Logger::LogDevice:0x0000560ae23d1970 @shift_period_suffix="%Y%m%d", @shift_size=1048576, @shift_age=0, @filename="/arvados/services/api/log/development.log", @dev=#<File:/arvados/services/api/log/development.log>, @binmode=false, @mon_data=#<Monitor:0x0000560ae23d18f8>, @mon_data_owner_object_id=8560>, @local_levels=#<Concurrent::Map:0x0000560ae23d1768 entries=0 default_proc=nil>>, "action_dispatch.backtrace_cleaner"=>#<Rails::BacktraceCleaner:0x00007f8460054f38 @filters=[#<Proc:0x00007f8460054e20 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:16>, #<Proc:0x00007f8460054df8 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:17>, #<Proc:0x00007f8460054dd0 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:18>, #<Proc:0x00007f8460054ad8 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:31>], @silencers=[#<Proc:0x00007f8460054ab0 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:21>], @root="/arvados/services/api/">, "action_dispatch.key_generator"=>#<ActiveSupport::CachingKeyGenerator:0x0000560ae421b5e8 @key_generator=#<ActiveSupport::KeyGenerator:0x0000560ae421b610 @secret="ezx6lj8ro3f0joezenqcdn319dwsgdh8z7c7m3unwyg4y3qmg", @iterations=1000>, @cache_keys=#<Concurrent::Map:0x0000560ae421b5c0 entries=1 default_proc=nil>>, "action_dispatch.http_auth_salt"=>"http authentication", "action_dispatch.signed_cookie_salt"=>"signed cookie", "action_dispatch.encrypted_cookie_salt"=>"encrypted cookie", "action_dispatch.encrypted_signed_cookie_salt"=>"signed encrypted cookie", "action_dispatch.authenticated_encrypted_cookie_salt"=>"authenticated encrypted cookie", "action_dispatch.use_authenticated_cookie_encryption"=>false, "action_dispatch.encrypted_cookie_cipher"=>nil, "action_dispatch.signed_cookie_digest"=>nil, "action_dispatch.cookies_serializer"=>:marshal, "action_dispatch.cookies_digest"=>nil, "action_dispatch.cookies_rotations"=>#<ActiveSupport::Messages::RotationConfiguration:0x0000560ae0f69488 @signed=[], @encrypted=[]>, "action_dispatch.content_security_policy"=>nil, "action_dispatch.content_security_policy_report_only"=>false, "action_dispatch.content_security_policy_nonce_generator"=>nil, "action_dispatch.routes"=>#<ActionDispatch::Routing::RouteSet:0x0000560ae20dacf8>, "ROUTES_8360_SCRIPT_NAME"=>"", "ORIGINAL_FULLPATH"=>"/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", "ORIGINAL_SCRIPT_NAME"=>"", "rack.request.query_string"=>"_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", "rack.request.query_hash"=>{"_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false"}, "action_dispatch.request_id"=>"req-9tfluusd20d015sgr5uf", "rack.session"=>{}, "rack.session.options"=>{:skip=>true}, "rack.tempfiles"=>[], "action_dispatch.request.path_parameters"=>{:controller=>"arvados/v1/groups", :action=>"create"}, "action_controller.instance"=>#<Arvados::V1::GroupsController:0x0000560ae3f31e90 @_action_has_layout=true, @_routes=nil, @_request=#<ActionDispatch::Request:0x00007f8460530a98 @env={...}, @filtered_parameters={"group"=>"{\"owner_uuid\":\"z1119-tpzed-000000000000000\", \"group_class\":\"project\", \"name\":\"Arvados Standard Docker 10\"}", "_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create"}, @filtered_env=nil, @filtered_path=nil, @protocol=nil, @port=nil, @method=nil, @request_method="POST", @remote_ip=nil, @original_fullpath=nil, @fullpath="/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", @ip=nil, @headers=#<ActionDispatch::Http::Headers:0x00007f846053b858 @req=#<ActionDispatch::Request:0x00007f8460530a98 ...>>>, @_response=#<ActionDispatch::Response:0x0000560ae3f32408 @mon_data=#<Monitor:0x0000560ae3f322c8>, @mon_data_owner_object_id=66900, @header={"X-Frame-Options"=>"SAMEORIGIN", "X-XSS-Protection"=>"1; mode=block", "X-Content-Type-Options"=>"nosniff", "X-Download-Options"=>"noopen", "X-Permitted-Cross-Domain-Policies"=>"none", "Referrer-Policy"=>"strict-origin-when-cross-origin", "X-Request-Id"=>"req-9tfluusd20d015sgr5uf", "Access-Control-Allow-Origin"=>"*", "Access-Control-Allow-Methods"=>"GET, HEAD, PUT, POST, DELETE", "Access-Control-Allow-Headers"=>"Authorization, Content-Type", "Access-Control-Max-Age"=>"86486400"}, @stream=#<ActionDispatch::Response::Buffer:0x0000560ae3f32228 @response=#<ActionDispatch::Response:0x0000560ae3f32408 ...>, @buf=[], @closed=false, @str_body=nil>, @status=200, @cv=#<MonitorMixin::ConditionVariable:0x0000560ae3f321b0 @monitor=#<Monitor:0x0000560ae3f322c8>, @cond=#<Thread::ConditionVariable:0x0000560ae3f32188>>, @committed=false, @sending=false, @sent=false, @cache_control={}, @request=#<ActionDispatch::Request:0x00007f8460530a98 @env={...}, @filtered_parameters={"group"=>"{\"owner_uuid\":\"z1119-tpzed-000000000000000\", \"group_class\":\"project\", \"name\":\"Arvados Standard Docker 10\"}", "_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create"}, @filtered_env=nil, @filtered_path=nil, @protocol=nil, @port=nil, @method=nil, @request_method="POST", @remote_ip=nil, @original_fullpath=nil, @fullpath="/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", @ip=nil, @headers=#<ActionDispatch::Http::Headers:0x00007f846053b858 @req=#<ActionDispatch::Request:0x00007f8460530a98 ...>>>>, @object=nil, @objects=nil, @offset=nil, @limit=nil, @select=nil, @distinct=nil, @response_resource_name=nil, @attrs={:owner_uuid=>"z1119-tpzed-000000000000000", :group_class=>"project", :name=>"Arvados Standard Docker 10"}, @extra_included=nil, @_lookup_context=#<ActionView::LookupContext:0x0000560ae3f31cb0 @details_key=nil, @cache=true, @prefixes=["arvados/v1/groups", "application"], @rendered_format=nil, @details={:locale=>[:en], :formats=>[:json], :variants=>[], :handlers=>[:raw, :erb, :html, :builder, :ruby]}, @view_paths=#<ActionView::PathSet:0x0000560ae3f31a08 @paths=[#<ActionView::OptimizedFileSystemResolver:0x0000560ae2303f70 @pattern=":prefix/:action{.:locale,}{.:formats,}{+:variants,}{.:handlers,}", @cache=#<ActionView::Resolver::Cache:0x20580 keys=0 queries=0>, @path="/arvados/services/api/app/views">]>>, @_action_name="create", @_response_body=nil, @_params=<ActionController::Parameters {"group"=>"{\"owner_uuid\":\"z1119-tpzed-000000000000000\", \"group_class\":\"project\", \"name\":\"Arvados Standard Docker 10\"}", "_profile"=>"true", "async"=>false, "cluster_id"=>"", "ensure_unique_name"=>false, "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create"} permitted: true>, @marked_for_same_origin_verification=false, @_config={}, @remote_ip="192.168.48.14", @read_auths=[#<ApiClientAuthorization id: 38, api_token: "1bxebbjmt92479f7c169q5wcxgz0yewuw839fs666a3qj6wi5k", api_client_id: 2, user_id: 3, created_by_ip_address: "192.168.48.2", last_used_by_ip_address: nil, last_used_at: nil, expires_at: nil, created_at: "2021-03-02 17:38:54", updated_at: "2021-03-02 17:38:54", default_owner_uuid: nil, scopes: ["all"], uuid: "z1119-gj3su-rkahytczn9o7wf1">], @read_users=[#<User id: 3, uuid: "z1119-tpzed-8ybit9f3z3asq79", owner_uuid: "z1119-tpzed-000000000000000", created_at: "2021-03-01 20:07:14", modified_by_client_uuid: "z1119-ozdt8-x3ld63y2ibkzt42", modified_by_user_uuid: "z1119-tpzed-000000000000000", modified_at: "2021-03-01 20:07:14", email: "alice@z1119.arv.local", first_name: "", last_name: "", identity_url: nil, is_admin: true, prefs: {}, updated_at: "2021-03-01 20:07:14", default_owner_uuid: nil, is_active: true, username: "alice", redirect_to_user_uuid: nil>]>, "action_dispatch.request.content_type"=>#<Mime::Type:0x0000560ae1b9e8c0 @synonyms=["text/x-json", "application/jsonrequest"], @symbol=:json, @string="application/json", @hash=2070501007913819523>, "RAW_POST_DATA"=>"{\"group\":\"{\\\"owner_uuid\\\":\\\"z1119-tpzed-000000000000000\\\", \\\"group_class\\\":\\\"project\\\", \\\"name\\\":\\\"Arvados Standard Docker 10\\\"}\"}", "action_dispatch.request.request_parameters"=>{"group"=>"{\"owner_uuid\":\"z1119-tpzed-000000000000000\", \"group_class\":\"project\", \"name\":\"Arvados Standard Docker 10\"}"}, "action_dispatch.request.query_parameters"=>{"_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false"}, "action_dispatch.request.parameters"=>{"group"=>"{\"owner_uuid\":\"z1119-tpzed-000000000000000\", \"group_class\":\"project\", \"name\":\"Arvados Standard Docker 10\"}", "_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create", "format"=>"json"}, "action_dispatch.request.accepts"=>[#<Mime::Type:0x0000560ae1b9e8c0 @synonyms=["text/x-json", "application/jsonrequest"], @symbol=:json, @string="application/json", @hash=2070501007913819523>], "action_dispatch.request.formats"=>[#<Mime::Type:0x0000560ae1b9e8c0 @synonyms=["text/x-json", "application/jsonrequest"], @symbol=:json, @string="application/json", @hash=2070501007913819523>], "action_dispatch.request.flash_hash"=>nil, "action_dispatch.cookies"=>#<ActionController::RequestForgeryProtection::ProtectionMethods::NullSession::NullCookieJar:0x00007f846053abb0 @set_cookies={}, @delete_cookies={}, @request=#<ActionDispatch::Request:0x00007f8460530a98 @env={...}, @filtered_parameters={"group"=>"{\"owner_uuid\":\"z1119-tpzed-000000000000000\", \"group_class\":\"project\", \"name\":\"Arvados Standard Docker 10\"}", "_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create"}, @filtered_env=nil, @filtered_path=nil, @protocol=nil, @port=nil, @method=nil, @request_method="POST", @remote_ip=nil, @original_fullpath=nil, @fullpath="/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", @ip=nil, @headers=#<ActionDispatch::Http::Headers:0x00007f846053b858 @req=#<ActionDispatch::Request:0x00007f8460530a98 ...>>>, @cookies={}, @committed=false>}

BUT if we cahange the configuration to make it go via railsapi straight:

      RailsAPI:
        InternalURLs:
          'http://api:8004': {}

then:

arv --format=uuid group create --group '{"owner_uuid":"z1119-tpzed-000000000000000", "group_class":"project", "name":"Arvados Standard Docker 11"}'
Error: Group class value must be one of 'project' or 'role', was '' (req-1r4olxje7knuxzxetkds)

[req-1r4olxje7knuxzxetkds] {"CONTENT_TYPE"=>"application/json", "GATEWAY_INTERFACE"=>"CGI/1.1", "PATH_INFO"=>"/arvados/v1/groups", "QUERY_STRING"=>"_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", "REMOTE_ADDR"=>"192.168.48.14", "REMOTE_HOST"=>"192.168.48.14", "REQUEST_METHOD"=>"POST", "REQUEST_URI"=>"https://z1119.arv.local:8000/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", "SCRIPT_NAME"=>"", "SERVER_NAME"=>"z1119.arv.local", "SERVER_PORT"=>"8000", "SERVER_PROTOCOL"=>"HTTP/1.1", "SERVER_SOFTWARE"=>"WEBrick/1.6.0 (Ruby/2.7.2/2020-10-01)", "HTTP_HOST"=>"z1119.arv.local:8000", "HTTP_USER_AGENT"=>"arvados-cli/1.0 google-api-ruby-client/0.8.7.4 Linux/5.10.0-3-amd64 (gzip)", "HTTP_TRANSFER_ENCODING"=>"chunked", "HTTP_ACCEPT"=>"application/json", "HTTP_AUTHORIZATION"=>"OAuth2 v2/z1119-gj3su-rkahytczn9o7wf1/1bxebbjmt92479f7c169q5wcxgz0yewuw839fs666a3qj6wi5k", "HTTP_VIA"=>"HTTP/1.0 arvados-controller", "HTTP_X_FORWARDED_FOR"=>"192.168.48.5,192.168.48.4:52394", "HTTP_X_FORWARDED_PROTO"=>"https", "HTTP_X_REAL_IP"=>"192.168.48.5", "HTTP_X_REQUEST_ID"=>"req-1r4olxje7knuxzxetkds", "HTTP_ACCEPT_ENCODING"=>"gzip", "rack.version"=>[1, 3], "rack.input"=>#<StringIO:0x00007f84606c00e8>, "rack.errors"=>#<IO:<STDERR>>, "rack.multithread"=>true, "rack.multiprocess"=>false, "rack.run_once"=>false, "rack.url_scheme"=>"http", "rack.hijack?"=>true, "rack.hijack"=>#<Proc:0x00007f84606c0070 /cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/handler/webrick.rb:83 (lambda)>, "rack.hijack_io"=>nil, "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_PATH"=>"/arvados/v1/groups", "action_dispatch.parameter_filter"=>[:password, :password], "action_dispatch.redirect_filter"=>[], "action_dispatch.secret_token"=>nil, "action_dispatch.secret_key_base"=>"ezx6lj8ro3f0joezenqcdn319dwsgdh8z7c7m3unwyg4y3qmg", "action_dispatch.show_exceptions"=>true, "action_dispatch.show_detailed_exceptions"=>true, "action_dispatch.logger"=>#<ActiveSupport::Logger:0x0000560ae23d1ad8 @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x0000560ae23d1a10 @datetime_format=nil>, @formatter=#<ActiveSupport::Logger::SimpleFormatter:0x0000560ae2a15908 @datetime_format=nil, @thread_key="activesupport_tagged_logging_tags:10520">, @logdev=#<Logger::LogDevice:0x0000560ae23d1970 @shift_period_suffix="%Y%m%d", @shift_size=1048576, @shift_age=0, @filename="/arvados/services/api/log/development.log", @dev=#<File:/arvados/services/api/log/development.log>, @binmode=false, @mon_data=#<Monitor:0x0000560ae23d18f8>, @mon_data_owner_object_id=8560>, @local_levels=#<Concurrent::Map:0x0000560ae23d1768 entries=0 default_proc=nil>>, "action_dispatch.backtrace_cleaner"=>#<Rails::BacktraceCleaner:0x00007f8460054f38 @filters=[#<Proc:0x00007f8460054e20 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:16>, #<Proc:0x00007f8460054df8 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:17>, #<Proc:0x00007f8460054dd0 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:18>, #<Proc:0x00007f8460054ad8 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:31>], @silencers=[#<Proc:0x00007f8460054ab0 /cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/backtrace_cleaner.rb:21>], @root="/arvados/services/api/">, "action_dispatch.key_generator"=>#<ActiveSupport::CachingKeyGenerator:0x0000560ae421b5e8 @key_generator=#<ActiveSupport::KeyGenerator:0x0000560ae421b610 @secret="ezx6lj8ro3f0joezenqcdn319dwsgdh8z7c7m3unwyg4y3qmg", @iterations=1000>, @cache_keys=#<Concurrent::Map:0x0000560ae421b5c0 entries=1 default_proc=nil>>, "action_dispatch.http_auth_salt"=>"http authentication", "action_dispatch.signed_cookie_salt"=>"signed cookie", "action_dispatch.encrypted_cookie_salt"=>"encrypted cookie", "action_dispatch.encrypted_signed_cookie_salt"=>"signed encrypted cookie", "action_dispatch.authenticated_encrypted_cookie_salt"=>"authenticated encrypted cookie", "action_dispatch.use_authenticated_cookie_encryption"=>false, "action_dispatch.encrypted_cookie_cipher"=>nil, "action_dispatch.signed_cookie_digest"=>nil, "action_dispatch.cookies_serializer"=>:marshal, "action_dispatch.cookies_digest"=>nil, "action_dispatch.cookies_rotations"=>#<ActiveSupport::Messages::RotationConfiguration:0x0000560ae0f69488 @signed=[], @encrypted=[]>, "action_dispatch.content_security_policy"=>nil, "action_dispatch.content_security_policy_report_only"=>false, "action_dispatch.content_security_policy_nonce_generator"=>nil, "action_dispatch.routes"=>#<ActionDispatch::Routing::RouteSet:0x0000560ae20dacf8>, "ROUTES_8360_SCRIPT_NAME"=>"", "ORIGINAL_FULLPATH"=>"/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", "ORIGINAL_SCRIPT_NAME"=>"", "rack.request.query_string"=>"_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", "rack.request.query_hash"=>{"_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false"}, "action_dispatch.request_id"=>"req-1r4olxje7knuxzxetkds", "rack.session"=>{}, "rack.session.options"=>{:skip=>true}, "rack.tempfiles"=>[], "action_dispatch.request.path_parameters"=>{:controller=>"arvados/v1/groups", :action=>"create"}, "action_controller.instance"=>#<Arvados::V1::GroupsController:0x00007f84606ecd78 @_action_has_layout=true, @_routes=nil, @_request=#<ActionDispatch::Request:0x00007f84606ee6f0 @env={...}, @filtered_parameters={"_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create", "group"=>{}}, @filtered_env=nil, @filtered_path=nil, @protocol=nil, @port=nil, @method=nil, @request_method="POST", @remote_ip=nil, @original_fullpath=nil, @fullpath="/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", @ip=nil, @headers=#<ActionDispatch::Http::Headers:0x0000560ae3b8ad28 @req=#<ActionDispatch::Request:0x00007f84606ee6f0 ...>>>, @_response=#<ActionDispatch::Response:0x00007f84606ecfa8 @mon_data=#<Monitor:0x00007f84606ecf58>, @mon_data_owner_object_id=67460, @header={"X-Frame-Options"=>"SAMEORIGIN", "X-XSS-Protection"=>"1; mode=block", "X-Content-Type-Options"=>"nosniff", "X-Download-Options"=>"noopen", "X-Permitted-Cross-Domain-Policies"=>"none", "Referrer-Policy"=>"strict-origin-when-cross-origin", "X-Request-Id"=>"req-1r4olxje7knuxzxetkds", "Access-Control-Allow-Origin"=>"*", "Access-Control-Allow-Methods"=>"GET, HEAD, PUT, POST, DELETE", "Access-Control-Allow-Headers"=>"Authorization, Content-Type", "Access-Control-Max-Age"=>"86486400"}, @stream=#<ActionDispatch::Response::Buffer:0x00007f84606ecee0 @response=#<ActionDispatch::Response:0x00007f84606ecfa8 ...>, @buf=[], @closed=false, @str_body=nil>, @status=200, @cv=#<MonitorMixin::ConditionVariable:0x00007f84606eceb8 @monitor=#<Monitor:0x00007f84606ecf58>, @cond=#<Thread::ConditionVariable:0x00007f84606ece90>>, @committed=false, @sending=false, @sent=false, @cache_control={}, @request=#<ActionDispatch::Request:0x00007f84606ee6f0 @env={...}, @filtered_parameters={"_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create", "group"=>{}}, @filtered_env=nil, @filtered_path=nil, @protocol=nil, @port=nil, @method=nil, @request_method="POST", @remote_ip=nil, @original_fullpath=nil, @fullpath="/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", @ip=nil, @headers=#<ActionDispatch::Http::Headers:0x0000560ae3b8ad28 @req=#<ActionDispatch::Request:0x00007f84606ee6f0 ...>>>>, @object=nil, @objects=nil, @offset=nil, @limit=nil, @select=nil, @distinct=nil, @response_resource_name=nil, @attrs=<ActionController::Parameters {} permitted: true>, @extra_included=nil, @_lookup_context=#<ActionView::LookupContext:0x00007f84606ecc60 @details_key=nil, @cache=true, @prefixes=["arvados/v1/groups", "application"], @rendered_format=nil, @details={:locale=>[:en], :formats=>[:json], :variants=>[], :handlers=>[:raw, :erb, :html, :builder, :ruby]}, @view_paths=#<ActionView::PathSet:0x00007f84606ecb70 @paths=[#<ActionView::OptimizedFileSystemResolver:0x0000560ae2303f70 @pattern=":prefix/:action{.:locale,}{.:formats,}{+:variants,}{.:handlers,}", @cache=#<ActionView::Resolver::Cache:0x20580 keys=0 queries=0>, @path="/arvados/services/api/app/views">]>>, @_action_name="create", @_response_body=nil, @_params=<ActionController::Parameters {"_profile"=>"true", "async"=>false, "cluster_id"=>"", "ensure_unique_name"=>false, "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create", "group"=><ActionController::Parameters {} permitted: true>} permitted: true>, @marked_for_same_origin_verification=false, @_config={}, @remote_ip="192.168.48.5", @read_auths=[#<ApiClientAuthorization id: 38, api_token: "1bxebbjmt92479f7c169q5wcxgz0yewuw839fs666a3qj6wi5k", api_client_id: 2, user_id: 3, created_by_ip_address: "192.168.48.2", last_used_by_ip_address: nil, last_used_at: nil, expires_at: nil, created_at: "2021-03-02 17:38:54", updated_at: "2021-03-02 17:38:54", default_owner_uuid: nil, scopes: ["all"], uuid: "z1119-gj3su-rkahytczn9o7wf1">], @read_users=[#<User id: 3, uuid: "z1119-tpzed-8ybit9f3z3asq79", owner_uuid: "z1119-tpzed-000000000000000", created_at: "2021-03-01 20:07:14", modified_by_client_uuid: "z1119-ozdt8-x3ld63y2ibkzt42", modified_by_user_uuid: "z1119-tpzed-000000000000000", modified_at: "2021-03-01 20:07:14", email: "alice@z1119.arv.local", first_name: "", last_name: "", identity_url: nil, is_admin: true, prefs: {}, updated_at: "2021-03-01 20:07:14", default_owner_uuid: nil, is_active: true, username: "alice", redirect_to_user_uuid: nil>]>, "action_dispatch.request.content_type"=>#<Mime::Type:0x0000560ae1b9e8c0 @synonyms=["text/x-json", "application/jsonrequest"], @symbol=:json, @string="application/json", @hash=2070501007913819523>, "action_dispatch.request.request_parameters"=>{"group"=>{}}, "action_dispatch.request.query_parameters"=>{"_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false"}, "action_dispatch.request.parameters"=>{"_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create", "group"=>{}, "format"=>"json"}, "action_dispatch.request.accepts"=>[#<Mime::Type:0x0000560ae1b9e8c0 @synonyms=["text/x-json", "application/jsonrequest"], @symbol=:json, @string="application/json", @hash=2070501007913819523>], "action_dispatch.request.formats"=>[#<Mime::Type:0x0000560ae1b9e8c0 @synonyms=["text/x-json", "application/jsonrequest"], @symbol=:json, @string="application/json", @hash=2070501007913819523>], "action_dispatch.request.flash_hash"=>nil, "action_dispatch.cookies"=>#<ActionController::RequestForgeryProtection::ProtectionMethods::NullSession::NullCookieJar:0x0000560ae3b89388 @set_cookies={}, @delete_cookies={}, @request=#<ActionDispatch::Request:0x00007f84606ee6f0 @env={...}, @filtered_parameters={"_profile"=>"true", "async"=>"false", "cluster_id"=>"", "ensure_unique_name"=>"false", "group_given"=>"true", "help"=>"false", "controller"=>"arvados/v1/groups", "action"=>"create", "group"=>{}}, @filtered_env=nil, @filtered_path=nil, @protocol=nil, @port=nil, @method=nil, @request_method="POST", @remote_ip=nil, @original_fullpath=nil, @fullpath="/arvados/v1/groups?_profile=true&async=false&cluster_id=&ensure_unique_name=false&group_given=true&help=false", @ip=nil, @headers=#<ActionDispatch::Http::Headers:0x0000560ae3b8ad28 @req=#<ActionDispatch::Request:0x00007f84606ee6f0 ...>>>, @cookies={}, @committed=false>}
[req-1r4olxje7knuxzxetkds]    (0.1ms)  BEGIN
[req-1r4olxje7knuxzxetkds]    (0.1ms)  SELECT clock_timestamp() AT TIME ZONE 'UTC'
[req-1r4olxje7knuxzxetkds]    (0.4ms)  SELECT COUNT(*) FROM "users" WHERE (redirect_to_user_uuid is null) AND (users.owner_uuid NOT IN (SELECT group_uuid FROM trashed_groups where trash_at <= statement_timestamp()) ) AND "users"."uuid" = $1  [["uuid", "z1119-tpzed-8ybit9f3z3asq79"]]
[req-1r4olxje7knuxzxetkds]    (0.1ms)  ROLLBACK
#<ActiveRecord::RecordInvalid: Validation failed: Group class value must be one of 'project' or 'role', was ''>
["Group class value must be one of 'project' or 'role', was ''"]
Error 1614715403+9e6228d9: 422
{"method":"POST","path":"/arvados/v1/groups","format":"json","controller":"Arvados::V1::GroupsController","action":"create","status":422,"duration":8.12,"view":0.17,"db":0.77,"request_id":"req-1r4olxje7knuxzxetkds","client_ipaddr":"192.168.48.5","client_auth":"z1119-gj3su-rkahytczn9o7wf1","exception":"#\u003cActiveRecord::RecordInvalid: Validation failed: Group class value must be one of 'project' or 'role', was ''\u003e","exception_backtrace":"/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/validations.rb:80:in `raise_validation_error'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/validations.rb:52:in `save!'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/transactions.rb:315:in `block in save!'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/transactions.rb:387:in `block in with_transaction_returning_status'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/connection_adapters/abstract/database_statements.rb:267:in `block in transaction'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/connection_adapters/abstract/transaction.rb:239:in `block in within_new_transaction'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/connection_adapters/abstract/transaction.rb:236:in `synchronize'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/connection_adapters/abstract/transaction.rb:236:in `within_new_transaction'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/connection_adapters/abstract/database_statements.rb:267:in `transaction'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/transactions.rb:212:in `transaction'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/transactions.rb:385:in `with_transaction_returning_status'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/transactions.rb:315:in `save!'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/suppressor.rb:48:in `save!'\n/arvados/services/api/app/controllers/application_controller.rb:112:in `create'\n/arvados/services/api/app/controllers/arvados/v1/groups_controller.rb:85:in `create'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/abstract_controller/base.rb:194:in `process_action'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_controller/metal/rendering.rb:30:in `process_action'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/abstract_controller/callbacks.rb:42:in `block in process_action'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/callbacks.rb:109:in `block in run_callbacks'\n/arvados/services/api/app/controllers/application_controller.rb:431:in `block in set_current_request_id'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/tagged_logging.rb:71:in `block in tagged'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/tagged_logging.rb:28:in `tagged'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/tagged_logging.rb:71:in `tagged'\n/arvados/services/api/app/controllers/application_controller.rb:430:in `set_current_request_id'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/callbacks.rb:118:in `block in run_callbacks'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/callbacks.rb:136:in `run_callbacks'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/abstract_controller/callbacks.rb:41:in `process_action'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_controller/metal/rescue.rb:22:in `process_action'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/notifications.rb:168:in `block in instrument'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/notifications/instrumenter.rb:23:in `instrument'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/notifications.rb:168:in `instrument'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_controller/metal/instrumentation.rb:32:in `process_action'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_controller/metal/params_wrapper.rb:256:in `process_action'\n/cache/gem/ruby/2.7.0/gems/activerecord-5.2.4.3/lib/active_record/railties/controller_runtime.rb:24:in `process_action'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/abstract_controller/base.rb:134:in `process'\n/cache/gem/ruby/2.7.0/gems/actionview-5.2.4.3/lib/action_view/rendering.rb:32:in `process'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_controller/metal.rb:191:in `dispatch'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_controller/metal.rb:252:in `dispatch'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/routing/route_set.rb:52:in `dispatch'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/routing/route_set.rb:34:in `serve'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/journey/router.rb:52:in `block in serve'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/journey/router.rb:35:in `each'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/journey/router.rb:35:in `serve'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/routing/route_set.rb:840:in `call'\n/cache/gem/ruby/2.7.0/gems/omniauth-1.4.3/lib/omniauth/strategy.rb:186:in `call!'\n/cache/gem/ruby/2.7.0/gems/omniauth-1.4.3/lib/omniauth/strategy.rb:164:in `call'\n/cache/gem/ruby/2.7.0/gems/omniauth-1.4.3/lib/omniauth/builder.rb:63:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/conditional_get.rb:40:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/http/content_security_policy.rb:18:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/cookies.rb:670:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/callbacks.rb:28:in `block in call'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/callbacks.rb:98:in `run_callbacks'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/callbacks.rb:26:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/executor.rb:14:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/debug_exceptions.rb:61:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'\n/cache/gem/ruby/2.7.0/gems/lograge-0.10.0/lib/lograge/rails_ext/rack/logger.rb:15:in `call_app'\n/cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/rack/logger.rb:26:in `block in call'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/tagged_logging.rb:71:in `block in tagged'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/tagged_logging.rb:28:in `tagged'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/tagged_logging.rb:71:in `tagged'\n/cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/rack/logger.rb:26:in `call'\n/cache/gem/ruby/2.7.0/gems/request_store-1.4.1/lib/request_store/middleware.rb:19:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/request_id.rb:27:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call'\n/cache/gem/ruby/2.7.0/gems/activesupport-5.2.4.3/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/executor.rb:14:in `call'\n/cache/gem/ruby/2.7.0/gems/actionpack-5.2.4.3/lib/action_dispatch/middleware/static.rb:127:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call'\n/arvados/services/api/app/middlewares/arvados_api_token.rb:66:in `call'\n/cache/gem/ruby/2.7.0/gems/railties-5.2.4.3/lib/rails/engine.rb:524:in `call'\n/cache/gem/ruby/2.7.0/gems/rack-2.2.3/lib/rack/handler/webrick.rb:95:in `service'\n/usr/local/lib/ruby/2.7.0/webrick/httpserver.rb:140:in `service'\n/usr/local/lib/ruby/2.7.0/webrick/httpserver.rb:96:in `run'\n/usr/local/lib/ruby/2.7.0/webrick/server.rb:307:in `block in start_thread'\n","params":{"_profile":"true","async":"false","cluster_id":"","ensure_unique_name":"false","group_given":"true","help":"false","group":{}},"@timestamp":"2021-03-02T20:03:23.211772104Z","@version":"1","message":"[422] POST /arvados/v1/groups (Arvados::V1::GroupsController#create)"}
diff.txt (10.9 KB) diff.txt Nico César, 03/02/2021 08:15 PM

Subtasks

Task #17547: ReviewClosedTom Clegg

Associated revisions

Revision 45e77184
Added by Tom Clegg about 16 hours ago

Merge branch '17437-drop-content-length-header'

refs #17437

Arvados-DCO-1.1-Signed-off-by: Tom Clegg <>

History

#1 Updated by Nico César about 2 months ago

from the diff.txt you can see some difference. I think the relevant one are:

(note that "-" is via nginx and the other one isn't)

-[req-9tfluusd20d015sgr5uf] {"CONTENT_LENGTH"=>"130" 
- "CONTENT_TYPE"=>"application/json" 
+[req-1r4olxje7knuxzxetkds] {"CONTENT_TYPE"=>"application/json" 
- "HTTP_CONNECTION"=>"close" 
+ "HTTP_TRANSFER_ENCODING"=>"chunked" 


- @_request=#<ActionDispatch::Request:0x00007f8460530a98 @env={...}
- @filtered_parameters={"group"=>"{\"owner_uuid\":\"z1119-tpzed-000000000000000\" 
- \"group_class\":\"project\" 
- \"name\":\"Arvados Standard Docker 10\"}" 
- "_profile"=>"true" 
+ @_request=#<ActionDispatch::Request:0x00007f84606ee6f0 @env={...}
+ @filtered_parameters={"_profile"=>"true" 
  "async"=>"false" 
  "cluster_id"=>"" 
  "ensure_unique_name"=>"false" 
  "group_given"=>"true" 
  "help"=>"false" 
  "controller"=>"arvados/v1/groups" 
- "action"=>"create"}
+ "action"=>"create" 
+ "group"=>{}}

#2 Updated by Nico César about 2 months ago

Interesting, If I add

diff --git a/lib/controller/proxy.go b/lib/controller/proxy.go
index d7381860e..61a5a3070 100644

--- a/lib/controller/proxy.go
+++ b/lib/controller/proxy.go
@@ -77,6 +77,8 @@ func (p *proxy) Do(
                Header: hdrOut,
                Body:   reqIn.Body,
        }).WithContext(reqIn.Context())
+
+       reqOut.TransferEncoding = []string{"identity"}
        return client.Do(reqOut)
 }

I get this back:

arv --format=uuid group create --group '{"owner_uuid":"z1119-tpzed-000000000000000", "group_class":"project", "name":"Arvados Standard Docker 11"}'
Failed to parse server response:
765: unexpected token at '<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0//EN">
<HTML>
  <HEAD><TITLE>Length Required</TITLE></HEAD>
  <BODY>
    <H1>Length Required</H1>
    WEBrick::HTTPStatus::LengthRequired
    <HR>
    <ADDRESS>
     WEBrick/1.6.0 (Ruby/2.7.2/2020-10-01) at
     z1119.arv.local:8000
    </ADDRESS>
  </BODY>
</HTML>
'

refs: https://stackoverflow.com/questions/47275291/go-http-client-adds-chunked-encoding-which-is-not-support-by-service/47275961

#3 Updated by Nico César about 2 months ago

I think this solved it:

diff --git a/lib/controller/proxy.go b/lib/controller/proxy.go
index d7381860e..eda96cca5 100644
--- a/lib/controller/proxy.go
+++ b/lib/controller/proxy.go
@@ -71,11 +71,12 @@ func (p *proxy) Do(
        hdrOut.Add("Via", reqIn.Proto+" arvados-controller")

        reqOut := (&http.Request{
-               Method: reqIn.Method,
-               URL:    urlOut,
-               Host:   reqIn.Host,
-               Header: hdrOut,
-               Body:   reqIn.Body,
+               Method:        reqIn.Method,
+               URL:           urlOut,
+               Host:          reqIn.Host,
+               Header:        hdrOut,
+               Body:          reqIn.Body,
+               ContentLength: reqIn.ContentLength,
        }).WithContext(reqIn.Context())
        return client.Do(reqOut)
 }

#5 Updated by Tom Clegg about 2 months ago

Copying Content-Length from the incoming request doesn't feel right. We should be able to let Go handle this sort of thing.

It looks like we're copying the "Content-Length" header from the incoming request, which doesn't seem right: if Go chooses to use chunked encoding, it's incorrect to send a Content-Length header. Maybe we just need to add "Content-Length" to the dropHeaders map in proxy.go, and Go will handle it automatically.

#6 Updated by Nico César about 2 months ago

Tom Clegg wrote:

Copying Content-Length from the incoming request doesn't feel right. We should be able to let Go handle this sort of thing.

It looks like we're copying the "Content-Length" header from the incoming request, which doesn't seem right: if Go chooses to use chunked encoding, it's incorrect to send a Content-Length header. Maybe we just need to add "Content-Length" to the dropHeaders map in proxy.go, and Go will handle it automatically.

we need to add Content-Length to the call we do to railsapi. I did this change:

diff --git a/lib/controller/proxy.go b/lib/controller/proxy.go
index eda96cca5..0fa58b54f 100644
--- a/lib/controller/proxy.go
+++ b/lib/controller/proxy.go
@@ -42,6 +42,7 @@ var dropHeaders = map[string]bool{
        "Accept-Encoding":   true,
        "Content-Encoding":  true,
        "Transfer-Encoding": true,
+       "Content-Length":    true,
 }
@@ -71,12 +72,11 @@ func (p *proxy) Do(
        hdrOut.Add("Via", reqIn.Proto+" arvados-controller")

        reqOut := (&http.Request{
-               Method:        reqIn.Method,
-               URL:           urlOut,
-               Host:          reqIn.Host,
-               Header:        hdrOut,
-               Body:          reqIn.Body,
-               ContentLength: reqIn.ContentLength,
+               Method: reqIn.Method,
+               URL:    urlOut,
+               Host:   reqIn.Host,
+               Header: hdrOut,
+               Body:   reqIn.Body,
        }).WithContext(reqIn.Context())
        return client.Do(reqOut)
 }

and I get the same error as before:

root@cb8f04a38d5e:/# arv --format=uuid group create --group '{"owner_uuid":"z1119-tpzed-000000000000000", "group_class":"project", "name":"Arvados Standard Docker 10"}'
Error: Group class value must be one of 'project' or 'role', was '' (req-2vad9hf7hxuy5421v3sb)

#8 Updated by Tom Clegg about 1 month ago

Aha! If the problem is that Rails can't handle a chunked request body (ouch, rfc2616 says "All HTTP/1.1 applications MUST be able to receive and decode the "chunked" transfer-coding") ... the documented way to avoid sending one is to set TransferEncoding:

--- a/lib/controller/proxy.go
+++ b/lib/controller/proxy.go
@@ -76,6 +76,7 @@ func (p *proxy) Do(
                Host:             reqIn.Host,
                Header:           hdrOut,
                Body:             reqIn.Body,
+               TransferEncoding: []string{"identity"},
        }).WithContext(reqIn.Context())
        return client.Do(reqOut)
 }

This should avoid chunked even when the incoming request body size is unknown (e.g., incoming request uses chunked encoding itself).

#10 Updated by Nico César about 1 month ago

  • Status changed from New to In Progress

#11 Updated by Nico César about 1 month ago

An interesting side effect of ca7c5048e807fd22b62e7144c44de3805ecf7ce4 is that it will make it fail in all our test suite, see https://ci.arvados.org/view/Developer/job/developer-run-tests/2376/. when I set TransferEncoding up in #note-2 I got an error about con Content-Lenght.

I didn't deep dive in this one today but seems that "passenger" and "rails server" are mutually exclusive when it comes to rfc2616-wise behaviour? Or is there a setup that will make both happy?

#12 Updated by Tom Clegg about 1 month ago

Perhaps if we do note-8 plus note-5?

#13 Updated by Peter Amstutz 29 days ago

  • Target version set to 2021-03-31 sprint

#15 Updated by Peter Amstutz 21 days ago

  • Target version changed from 2021-03-31 sprint to 2021-04-14 sprint

#16 Updated by Peter Amstutz 21 days ago

  • Target version changed from 2021-04-14 sprint to 2021-04-28 bughunt sprint

#17 Updated by Peter Amstutz 7 days ago

  • Assigned To set to Nico César

#18 Updated by Nico César 2 days ago

474571865953620708d03b7d9467d3e3f59b863c 17437-Transfer-Encoding-fix,

https://ci.arvados.org/view/Developer/job/developer-run-tests/2427/

trying a combination of Note-5 and Note-8

#19 Updated by Nico César about 19 hours ago

After seeing

https://ci.arvados.org/view/Developer/job/developer-run-tests/2427/
https://ci.arvados.org/view/Developer/job/developer-run-tests/2428/

fail quite loudly, we had a conversation with Tom Clegg at standup today and arrived to the concluision

1) This happens with WebBrick because is not HTTP1.1 complient (but HTTP1.0),
2) we don't use WebBrick in production nor development

We decided that is better not to do anything at the moment,

possible workaround/fixes:

1) make controller talk HTTP1.0 with upstream
2) wait for a version of rails that fixes https://github.com/rails/rails/issues/15079
3) recommend users to use passenger in a standalone version instead of rails server

#20 Updated by Nico César about 19 hours ago

  • Status changed from In Progress to Rejected

"wontfix"

#22 Updated by Tom Clegg about 16 hours ago

  • Description updated (diff)

Also available in: Atom PDF