helpyio / helpy

Helpy is a modern, open source helpdesk customer support application. Features include knowledgebase, community discussions and support tickets integrated with email.
http://helpy.io/?source=ghh
MIT License
2.38k stars 498 forks source link

Unable to upload files to Minio server, S3 compatible storage. #1262

Open mzch opened 5 years ago

mzch commented 5 years ago

I tried to setting up Helpy to upload files to Minio, but failed.

Helpy reported, "Oops there has been an error... We log all errors and an engineers pager is going off somewhere!"

log/production.log

I, [2019-04-25T10:44:52.227823 #18846]  INFO -- : Started PATCH "/admin/users/1-koichi-matsumoto" for 203.141.134.112 at 2019-04-25 10:44:52 -0700
I, [2019-04-25T10:44:58.945879 #18846]  INFO -- : Processing by Admin::UsersController#update as HTML
I, [2019-04-25T10:44:58.946123 #18846]  INFO -- :   Parameters: {"utf8"=>"✓", "authenticity_token"=>"MSbD25UXaHjDNIN08842E6x2hf1yTQsSXW5HJxTx3N4rrKglsQg1rOSk26T1o4FY3BSVUk+2jWKssIXcFGgOKQ==", "user"=>{"profile_image"=>#<ActionDispatch::Http::UploadedFile:0x0000555f27b50fa0 @tempfile=#<Tempfile:/tmp/RackMultipart20190425-18846-1xgmvht.jpg>, @original_filename="Face of Myself.jpg", @content_type="image/jpeg", @headers="Content-Disposition: form-data; name=\"user[profile_image]\"; filename=\"Face of Myself.jpg\"\r\nContent-Type: image/jpeg\r\n">, "name"=>"Koichi MATSUMOTO", "company"=>"Office LetLive", "city"=>"Amagasaki-shi", "state"=>"Hyogo", "zip"=>"660-0063", "time_zone"=>"Osaka", "password"=>"[FILTERED]", "password_confirmation"=>"[FILTERED]", "work_phone"=>"", "cell_phone"=>"", "email"=>"koichi@letlive.com", "twitter"=>"https://twitter.com/koichimats", "linkedin"=>"", "signature"=>"", "notify_on_private"=>"1", "notify_on_public"=>"1", "notify_on_reply"=>"1"}, "commit"=>"Save", "id"=>"1-koichi-matsumoto"}
D, [2019-04-25T10:44:58.952996 #18846] DEBUG -- :   User Load (2.5ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = $1  ORDER BY "users"."id" ASC LIMIT 1  [["id", 1]]
D, [2019-04-25T10:44:58.996497 #18846] DEBUG -- :    (2.0ms)  SELECT DISTINCT name FROM "taggings" LEFT OUTER JOIN "tags" ON "tags"."id" = "taggings"."tag_id" WHERE "taggings"."context" = $1  [["context", "teams"]]
D, [2019-04-25T10:44:58.998826 #18846] DEBUG -- :   User Load (1.0ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = $1 LIMIT 1  [["id", 1]]
D, [2019-04-25T10:44:59.047366 #18846] DEBUG -- :   ActsAsTaggableOn::Tag Load (1.4ms)  SELECT "tags".* FROM "tags" INNER JOIN "taggings" ON "tags"."id" = "taggings"."tag_id" WHERE "taggings"."taggable_id" = $1 AND "taggings"."taggable_type" = $2 AND (taggings.context = 'teams' AND taggings.tagger_id IS NULL)  [["taggable_id", 1], ["taggable_type", "User"]]
D, [2019-04-25T10:44:59.059796 #18846] DEBUG -- :    (1.0ms)  SELECT COUNT(*) FROM "topics" WHERE (assigned_user_id = NULL OR current_status = 'new') AND ("topics"."current_status" != $1)  [["current_status", "closed"]]
D, [2019-04-25T10:44:59.060795 #18846] DEBUG -- :   CACHE (0.0ms)  SELECT COUNT(*) FROM "topics" WHERE (assigned_user_id = NULL OR current_status = 'new') AND ("topics"."current_status" != $1)  [["current_status", "closed"]]
D, [2019-04-25T10:44:59.063339 #18846] DEBUG -- :    (0.7ms)  SELECT COUNT(*) FROM "topics" WHERE "topics"."assigned_user_id" = $1 AND "topics"."current_status" = $2  [["assigned_user_id", 1], ["current_status", "pending"]]
D, [2019-04-25T10:44:59.065468 #18846] DEBUG -- :    (0.7ms)  SELECT COUNT(*) FROM "topics" WHERE "topics"."current_status" = $1  [["current_status", "open"]]
D, [2019-04-25T10:44:59.067644 #18846] DEBUG -- :    (1.1ms)  SELECT COUNT(*) FROM "topics" WHERE "topics"."current_status" IN ('new', 'open', 'pending')
D, [2019-04-25T10:44:59.070340 #18846] DEBUG -- :    (0.8ms)  SELECT COUNT(*) FROM "topics" WHERE "topics"."current_status" IN ('new', 'open', 'pending') AND "topics"."assigned_user_id" = $1  [["assigned_user_id", 1]]
D, [2019-04-25T10:44:59.072336 #18846] DEBUG -- :    (0.7ms)  BEGIN
D, [2019-04-25T10:45:00.500346 #18846] DEBUG -- :   SQL (1.3ms)  UPDATE "users" SET "profile_image" = $1, "updated_at" = $2 WHERE "users"."id" = $3  [["profile_image", "Face_of_Myself.jpg"], ["updated_at", "2019-04-25 17:45:00.495393"], ["id", 1]]
D, [2019-04-25T10:45:01.349739 #18846] DEBUG -- :    (1.1ms)  ROLLBACK
I, [2019-04-25T10:45:01.350249 #18846]  INFO -- : Completed 500 Internal Server Error in 2404ms (ActiveRecord: 28.6ms)
F, [2019-04-25T10:45:01.351941 #18846] FATAL -- : 
Excon::Error::Socket (getaddrinfo: Name or service not known (SocketError)):
  app/controllers/admin/users_controller.rb:95:in `update'
  app/controllers/application_controller.rb:195:in `set_time_zone'

I, [2019-04-25T10:45:01.352658 #18846]  INFO -- : Processing by ErrorsController#internal_server_error as HTML
I, [2019-04-25T10:45:01.352807 #18846]  INFO -- :   Parameters: {"utf8"=>"✓", "authenticity_token"=>"MSbD25UXaHjDNIN08842E6x2hf1yTQsSXW5HJxTx3N4rrKglsQg1rOSk26T1o4FY3BSVUk+2jWKssIXcFGgOKQ==", "user"=>{"profile_image"=>#<ActionDispatch::Http::UploadedFile:0x0000555f27b50fa0 @tempfile=#<Tempfile:/tmp/RackMultipart20190425-18846-1xgmvht.jpg>, @original_filename="Face of Myself.jpg", @content_type="image/jpeg", @headers="Content-Disposition: form-data; name=\"user[profile_image]\"; filename=\"Face of Myself.jpg\"\r\nContent-Type: image/jpeg\r\n">, "name"=>"Koichi MATSUMOTO", "company"=>"Office LetLive", "city"=>"Amagasaki-shi", "state"=>"Hyogo", "zip"=>"660-0063", "time_zone"=>"Osaka", "password"=>"[FILTERED]", "password_confirmation"=>"[FILTERED]", "work_phone"=>"", "cell_phone"=>"", "email"=>"koichi@letlive.com", "twitter"=>"https://twitter.com/koichimats", "linkedin"=>"", "signature"=>"", "notify_on_private"=>"1", "notify_on_public"=>"1", "notify_on_reply"=>"1"}, "commit"=>"Save", "id"=>"1-koichi-matsumoto"}
D, [2019-04-25T10:45:01.361516 #18846] DEBUG -- :   AppSettings Load (1.0ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "theme.active"]]
D, [2019-04-25T10:45:01.392800 #18846] DEBUG -- :   AppSettings Load (1.0ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "design.header_logo"]]
I, [2019-04-25T10:45:01.394791 #18846]  INFO -- :   Rendered errors/internal_server_error.html.erb within layouts/errors (4.7ms)
I, [2019-04-25T10:45:01.400952 #18846]  INFO -- :   Rendered layouts/_google_analytics.html.erb (0.7ms)
I, [2019-04-25T10:45:01.401103 #18846]  INFO -- :   Rendered app/themes/flat/views/layouts/_head.html.erb (4.7ms)
D, [2019-04-25T10:45:01.402831 #18846] DEBUG -- :   AppSettings Load (0.9ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "css.top_bar"]]
D, [2019-04-25T10:45:01.405337 #18846] DEBUG -- :   AppSettings Load (0.8ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "css.search_background"]]
D, [2019-04-25T10:45:01.407685 #18846] DEBUG -- :   AppSettings Load (0.8ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "css.still_need_help"]]
D, [2019-04-25T10:45:01.410074 #18846] DEBUG -- :   AppSettings Load (0.9ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "css.form_background"]]
D, [2019-04-25T10:45:01.412255 #18846] DEBUG -- :   AppSettings Load (0.7ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "css.link_color"]]
D, [2019-04-25T10:45:01.414472 #18846] DEBUG -- :   AppSettings Load (0.7ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "css.accent_color"]]
D, [2019-04-25T10:45:01.416889 #18846] DEBUG -- :   AppSettings Load (0.7ms)  SELECT  "settings".* FROM "settings" WHERE (thing_type is NULL and thing_id is NULL) AND "settings"."var" = $1  ORDER BY "settings"."id" ASC LIMIT 1  [["var", "css.main_color"]]
I, [2019-04-25T10:45:01.418398 #18846]  INFO -- : Completed 500 Internal Server Error in 65ms (Views: 31.0ms | ActiveRecord: 10.1ms)
I, [2019-04-25T10:45:01.584364 #18846]  INFO -- : Started GET "/uploads/logos/Logo.png" for 203.141.134.112 at 2019-04-25 10:45:01 -0700
F, [2019-04-25T10:45:01.636835 #18846] FATAL -- : 
ActionController::RoutingError (No route matches [GET] "/uploads/logos/Logo.png"):
  actionpack (4.2.11.1) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call'
  actionpack (4.2.11.1) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
  railties (4.2.11.1) lib/rails/rack/logger.rb:38:in `call_app'
  railties (4.2.11.1) lib/rails/rack/logger.rb:20:in `block in call'
  activesupport (4.2.11.1) lib/active_support/tagged_logging.rb:68:in `block in tagged'
  activesupport (4.2.11.1) lib/active_support/tagged_logging.rb:26:in `tagged'
  activesupport (4.2.11.1) lib/active_support/tagged_logging.rb:68:in `tagged'
  railties (4.2.11.1) lib/rails/rack/logger.rb:20:in `call'
  request_store (1.4.1) lib/request_store/middleware.rb:19:in `call'
  actionpack (4.2.11.1) lib/action_dispatch/middleware/request_id.rb:21:in `call'
  rack (1.6.11) lib/rack/methodoverride.rb:22:in `call'
  rack (1.6.11) lib/rack/runtime.rb:18:in `call'
  activesupport (4.2.11.1) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
  rack (1.6.11) lib/rack/sendfile.rb:113:in `call'
  railties (4.2.11.1) lib/rails/engine.rb:518:in `call'
  railties (4.2.11.1) lib/rails/application.rb:165:in `call'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:97:in `process_request'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:149:in `accept_and_process_next_request'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:415:in `block (3 levels) in start_threads'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception'

I, [2019-04-25T10:45:01.637888 #18846]  INFO -- : Processing by ErrorsController#not_found as HTML
D, [2019-04-25T10:45:01.642311 #18846] DEBUG -- :   User Load (1.3ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = $1  ORDER BY "users"."id" ASC LIMIT 1  [["id", 1]]
I, [2019-04-25T10:45:01.652517 #18846]  INFO -- :   Rendered errors/not_found.html.erb within layouts/errors (1.9ms)
I, [2019-04-25T10:45:01.657691 #18846]  INFO -- :   Rendered layouts/_google_analytics.html.erb (0.3ms)
I, [2019-04-25T10:45:01.657810 #18846]  INFO -- :   Rendered app/themes/flat/views/layouts/_head.html.erb (4.1ms)
I, [2019-04-25T10:45:01.659240 #18846]  INFO -- : Completed 404 Not Found in 21ms (Views: 11.2ms | ActiveRecord: 1.3ms)
I, [2019-04-25T10:45:03.910149 #18846]  INFO -- : Started GET "/uploads/logos/Logo.png" for 203.141.134.112 at 2019-04-25 10:45:03 -0700
F, [2019-04-25T10:45:03.911950 #18846] FATAL -- : 
ActionController::RoutingError (No route matches [GET] "/uploads/logos/Logo.png"):
  actionpack (4.2.11.1) lib/action_dispatch/middleware/debug_exceptions.rb:21:in `call'
  actionpack (4.2.11.1) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
  railties (4.2.11.1) lib/rails/rack/logger.rb:38:in `call_app'
  railties (4.2.11.1) lib/rails/rack/logger.rb:20:in `block in call'
  activesupport (4.2.11.1) lib/active_support/tagged_logging.rb:68:in `block in tagged'
  activesupport (4.2.11.1) lib/active_support/tagged_logging.rb:26:in `tagged'
  activesupport (4.2.11.1) lib/active_support/tagged_logging.rb:68:in `tagged'
  railties (4.2.11.1) lib/rails/rack/logger.rb:20:in `call'
  request_store (1.4.1) lib/request_store/middleware.rb:19:in `call'
  actionpack (4.2.11.1) lib/action_dispatch/middleware/request_id.rb:21:in `call'
  rack (1.6.11) lib/rack/methodoverride.rb:22:in `call'
  rack (1.6.11) lib/rack/runtime.rb:18:in `call'
  activesupport (4.2.11.1) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
  rack (1.6.11) lib/rack/sendfile.rb:113:in `call'
  railties (4.2.11.1) lib/rails/engine.rb:518:in `call'
  railties (4.2.11.1) lib/rails/application.rb:165:in `call'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:97:in `process_request'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:149:in `accept_and_process_next_request'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:110:in `main_loop'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:415:in `block (3 levels) in start_threads'
  /usr/lib/ruby/vendor_ruby/phusion_passenger/utils.rb:113:in `block in create_thread_and_abort_on_exception'

I, [2019-04-25T10:45:03.912809 #18846]  INFO -- : Processing by ErrorsController#not_found as HTML
D, [2019-04-25T10:45:03.916619 #18846] DEBUG -- :   User Load (1.3ms)  SELECT  "users".* FROM "users" WHERE "users"."id" = $1  ORDER BY "users"."id" ASC LIMIT 1  [["id", 1]]
I, [2019-04-25T10:45:03.922677 #18846]  INFO -- :   Rendered errors/not_found.html.erb within layouts/errors (0.8ms)
I, [2019-04-25T10:45:03.926851 #18846]  INFO -- :   Rendered layouts/_google_analytics.html.erb (0.3ms)
I, [2019-04-25T10:45:03.926983 #18846]  INFO -- :   Rendered app/themes/flat/views/layouts/_head.html.erb (3.2ms)
I, [2019-04-25T10:45:03.928267 #18846]  INFO -- : Completed 404 Not Found in 15ms (Views: 7.6ms | ActiveRecord: 1.3ms)
scott commented 5 years ago

Hi @mzch thanks for posting this and contacting us on support.helpy.io. Do you know of any easy way to stand up a test instance of Minio?

mzch commented 5 years ago

OK, please access to my Minio.

Endpoint: https://objstr.com Region: us-east-1 Bucket: helpy AccessKey: JIO6XRM9J29K6RBYP1MX SecretKey: hdrHJxMTeJHMJmISOGs8D9M4NvDqrWNZrzresdV9

These keys will keep in this week.

mzch commented 5 years ago

I modified config/initializers/fog-aws.rb as below:

CarrierWave.configure do |config|
  config.fog_provider = 'fog/aws'
  if Rails.env == 'test'
    config.fog_credentials = {
      provider:               'AWS',
      aws_access_key_id:      'secretkeyid',
      aws_secret_access_key:  'secretaccesskey',
      region:                 'abc',
      endpoint:               'ayz'
    }
    config.fog_directory =    'testbucket'

  else
    if ENV['REMOTE_STORAGE'] == "true"
      config.fog_credentials = {
        provider:              'AWS',
        aws_access_key_id:     ENV['S3_KEY'],
        aws_secret_access_key: ENV['S3_SECRET'],
        aws_signature_version: ENV['S3_SIG_VER'],
        region:                ENV['S3_REGION'],
        # host:                's3.amazon.com',
        endpoint:              ENV['S3_ENDPOINT'],
        path_style:            ENV['S3_PATH_STYLE'],
      }
      config.fog_directory  = ENV['S3_BUCKET_NAME']
      config.fog_public     = true
      config.fog_attributes = { cache_control: "public, max-age=#{365.day.to_i}" }
    end
  end
end

besites, set S3_PATH_STYLE=true and S3_SIG_VER=2, then Helpy works correctly, but when setting aws_signature_version to 4, it fails.

mzch commented 5 years ago

When signature 4, error appears in production.log

F, [2019-05-05T07:39:48.339420 #4835] FATAL -- : 
Excon::Error::Forbidden (Expected(200) <=> Actual(403 Forbidden)
excon.error.response
  :body          => "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n<Error><Code>SignatureDoe
sNotMatch</Code><Message>The request signature we calculated does not match the signature 
you provided. Check your key and signing method.</Message><Key>uploads/user/profile_image/
1/Face_of_Myself.jpg</Key><BucketName>helpy</BucketName><Resource>/helpy/uploads/user/prof
ile_image/1/Face_of_Myself.jpg</Resource><RequestId>159BD05BA9F76667</RequestId><HostId>71
e60e4f-556c-4858-bdc6-6cda5d5801fb</HostId></Error>"
  :cookies       => [
  ]
  :headers       => {
    "Accept-Ranges"             => "bytes"
    "Content-Security-Policy"   => "block-all-mixed-content"
    "Content-Type"              => "application/xml"
    "Date"                      => "Sun, 05 May 2019 14:39:48 GMT"
    "Server"                    => "MinIO/RELEASE.2019-05-02T19-07-09Z"
    "Strict-Transport-Security" => "max-age=15552000; includeSubdomains;"
    "Vary"                      => "Origin"
    "X-Amz-Request-Id"          => "159BD05BA9F76667"
    "X-Content-Type-Options"    => "nosniff"
    "X-Frame-Options"           => "SAMEORIGIN"
    "X-Minio-Deployment-Id"     => "71e60e4f-556c-4858-bdc6-6cda5d5801fb"
    "X-Xss-Protection"          => "1; mode=block"
  }
  :host          => "objstr.com"
  :local_address => "148.163.121.238"
  :local_port    => 46094
  :path          => "/helpy/uploads/user/profile_image/1/Face_of_Myself.jpg"
  :port          => 443
  :reason_phrase => "Forbidden"
  :remote_ip     => "192.3.176.179"
  :status        => 403
  :status_line   => "HTTP/1.1 403 Forbidden\r\n"
):
  app/controllers/admin/users_controller.rb:95:in `update'
  app/controllers/application_controller.rb:195:in `set_time_zone'
mzch commented 5 years ago

somehow, signature 4 issue is resolved....But Logo.png and favicon.ico are not loaded from the remote storage, able to be loaded from local. Please fix it.

scott commented 5 years ago

Hey @mzch I am happy to hear you were able to figure out these extra configurations! I will take a look at these settings items to make sure they are set to override to the remote store.