Tempfile is nil on defered uploads


(Rafael dos Santos Silva) #1

Hi,

When a user tries to upload a file in a post, the following errors occurs:

Job exception: no implicit conversion of nil into String

/var/www/discourse/app/controllers/uploads_controller.rb:69:in `size'
/var/www/discourse/app/controllers/uploads_controller.rb:69:in `create_upload'
/var/www/discourse/app/controllers/uploads_controller.rb:20:in `block in create'
/var/www/discourse/lib/scheduler/defer.rb:68:in `call'
/var/www/discourse/lib/scheduler/defer.rb:68:in `do_work'
/var/www/discourse/lib/scheduler/defer.rb:46:in `do_all_work'
/var/www/discourse/lib/scheduler/defer.rb:86:in `process_client'
/var/www/discourse/lib/middleware/unicorn_oobgc.rb:95:in `process_client'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:674:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:529:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/unicorn-4.9.0/lib/unicorn/http_server.rb:140:in `start'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/unicorn-4.9.0/bin/unicorn:126:in `<top (required)>'
/var/www/discourse/vendor/bundle/ruby/2.0.0/bin/unicorn:23:in `load'
/var/www/discourse/vendor/bundle/ruby/2.0.0/bin/unicorn:23:in `<main>'

After digging a bit, looks like that file.tempfile is nil, only on defered uploads.

Forcing it to be sync (uploads_controller line 15) makes the tempfile survive.

Any ideas?


Params[:file] attributes lost within Scheduler::Defer
(Rafael dos Santos Silva) #2

Looks like this is happening:

https://github.com/rack/rack/pull/671

Just doesn’t get why I can’t reproduce this on try.discourse.org


(Rafael dos Santos Silva) #3

Sorry to bump this, but this is really strange.

On my production server everything works smooth, and even upload worked before.

Last week a user said that an upload never complete, and the 100% gets stuck on the composer.

After some debugging I have found that:

  • synchronous uploads works just fine!
  • Until line 15 on the controller the File Object does have a normal tempfile.
  • If the upload isn’t synchronous at line 51 the object File doesn’t have a tempfile anymore. The error is the one on my first post.

  • If I force every upload to be synchronous everything works.

My research pointed to this change on Unicorn that could be the culprit, since I don’t know what keeps a tempfile alive after the request end.

Any points @sam ?


(Rafael dos Santos Silva) #4

Ok, closing topic.

The culprit is indeed the TempfileReaper. He got enabled automatically on Rack 1.6 and Unicorn 4.9.

By monkey patching the call method out, I disabled it and uploads are working again.

Ps.: Someday I’ll discover why this doesn’t happen on Meta/Try :smile:


(Sam Saffron) #5

I still don’t understand this, I can not see this temp file reaper middleware in our containers, are you doing a standard docker based install?


(Rafael dos Santos Silva) #6

When I use the rake taks to list the middlewares it isn’t listed.

But after monkey patching the middleware method to print the stacktrace on call I have found that it was indeed Tempfile Reaper the cause.

I don’t use the stardard install, but I’m still curious why this doesn’t happen on the standard install after unicorn 4.9 and Rack 1.6 are both in use.

BTW, this is a kinda a small race condition, maybe sidekiq can run the job before TempfileReaper runs.


(Louis Rossouw) #7

@Falco how did you fix this? I don’t follow what you mean?


(Rafael dos Santos Silva) #8

Is this happening with you too?

My fix (ugly hack) was this:

# add this to the end of the file /config/initializers/000-rails-master-polyfills.rb
module Rack

  class TempfileReaper
    def initialize(app)
      @app = app
    end

    def call(env)
          status, headers, body = @app.call(env)
          [status, headers, body]
        end
  end
end

(Louis Rossouw) #9

Yes. The dockerless install here has this issue it seems:

Ok I’ve changed something somewhere else.


(Sam Saffron) #10

Hmm … how much of this is still relevant, should I close it?


(Rafael dos Santos Silva) #11

Yep, I was never able to repro this in Docker installs.


(Rafael dos Santos Silva) #12

(Sam Saffron) #13

Turns out this is a legit bug, we luckily avoided due to HTTP header voodoo on the way in, at LAST I have it fixed:

What was happening is that Rack was cleaning up tempfiles under some conditions which we do not hit in our docker install (but I did hit on local)

Had to fix it to unblock fixing another bug…

TLDR;

tempfiles = env[Rack::RACK_TEMPFILES]
env[Rack::RACK_TEMPFILES] = nil

# and after we are done

tempfiles&.each(&:close!)