403 error along with CSRF token warning


(Scott Smith) #1

I have one user regularly getting a 403 error when trying to post a new topic or reply to a post. At the point of the error there is also a CSRF warning in the log file. He is using the latest IE (11.0.17). Here is the log env at the point of the warning (“Can’t verify CSRF token authenticity”):

HTTP_HOST: www.growingfruit.org
REQUEST_URI: /draft.json
REQUEST_METHOD: POST
HTTP_USER_AGENT: Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; rv:11.0) like Gecko
HTTP_ACCEPT: */*
HTTP_REFERER: http://www.growingfruit.org/t/scott-can-you-help-forestandfarm-with-issue-on-reply-of-posting/656/3
HTTP_X_FORWARDED_FOR: 108.56.173.122, 172.17.42.1
HTTP_X_REAL_IP: 172.17.42.1

params:
  draft_key: topic_656
  data: {"reply":"I just tested trying to post to the Roger Meyers Jujubes thread and got the 403 error.","ac
  sequence: 1

Note this reply didn’t show up on the thread, this issue is often (but not always) preventing this user from posting.

Here is the log backtrace for what its worth:

/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/logster-0.1.8/lib/logster/logger.rb:47:in `add'
/usr/local/lib/ruby/2.0.0/logger.rb:445:in `warn'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_controller/metal/request_forgery_protection.rb:196:in `verify_authenticity_token'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/callbacks.rb:424:in `block in make_lambda'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/callbacks.rb:160:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/callbacks.rb:160:in `block in halting'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/callbacks.rb:86:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/callbacks.rb:86:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/abstract_controller/callbacks.rb:19:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_controller/metal/rescue.rb:29:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_controller/metal/instrumentation.rb:31:in `block in process_action'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/notifications.rb:159:in `block in instrument'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/notifications.rb:159:in `instrument'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_controller/metal/params_wrapper.rb:250:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.1.9/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/abstract_controller/base.rb:136:in `process'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionview-4.1.9/lib/action_view/rendering.rb:30:in `process'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-mini-profiler-0.9.3/lib/mini_profiler/profiling_methods.rb:106:in `block in profile_method'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_controller/metal.rb:196:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_controller/metal.rb:232:in `block in action'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/routing/route_set.rb:82:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/routing/route_set.rb:82:in `dispatch'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/routing/route_set.rb:50:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/journey/router.rb:73:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/journey/router.rb:59:in `each'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/journey/router.rb:59:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/routing/route_set.rb:685:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-protection-1.5.3/lib/rack/protection/frame_options.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:186:in `call!'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/strategy.rb:164:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/omniauth-1.2.2/lib/omniauth/builder.rb:59:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/conditionalget.rb:35:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/head.rb:11:in `call'
/var/www/discourse/lib/middleware/anonymous_cache.rb:123:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/params_parser.rb:27:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/flash.rb:254:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/message_bus-1.0.6/lib/message_bus/rack/middleware.rb:55:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/session/abstract/id.rb:225:in `context'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/session/abstract/id.rb:220:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/cookies.rb:562:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.1.9/lib/active_record/query_cache.rb:36:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activerecord-4.1.9/lib/active_record/connection_adapters/abstract/connection_pool.rb:621:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/activesupport-4.1.9/lib/active_support/callbacks.rb:82:in `run_callbacks'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/remote_ip.rb:76:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/logster-0.1.8/lib/logster/middleware/reporter.rb:31:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/railties-4.1.9/lib/rails/rack/logger.rb:38:in `call_app'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/railties-4.1.9/lib/rails/rack/logger.rb:22:in `call'
/var/www/discourse/config/initializers/quiet_logger.rb:10:in `call_with_quiet_assets'
/var/www/discourse/config/initializers/silence_logger.rb:26:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/actionpack-4.1.9/lib/action_dispatch/middleware/request_id.rb:21:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/methodoverride.rb:21:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/runtime.rb:17:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/sendfile.rb:112:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-mini-profiler-0.9.3/lib/mini_profiler/profiler.rb:276:in `call'
/var/www/discourse/lib/middleware/request_tracker.rb:70:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/railties-4.1.9/lib/rails/engine.rb:514:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/railties-4.1.9/lib/rails/application.rb:144:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/railties-4.1.9/lib/rails/railtie.rb:194:in `public_send'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/railties-4.1.9/lib/rails/railtie.rb:194:in `method_missing'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/builder.rb:138:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/urlmap.rb:65:in `block in call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/urlmap.rb:50:in `each'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/rack-1.5.2/lib/rack/urlmap.rb:50:in `call'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/unicorn-4.8.3/lib/unicorn/http_server.rb:576:in `process_client'
/var/www/discourse/lib/scheduler/defer.rb:85: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.8.3/lib/unicorn/http_server.rb:670:in `worker_loop'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/unicorn-4.8.3/lib/unicorn/http_server.rb:525:in `spawn_missing_workers'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/unicorn-4.8.3/lib/unicorn/http_server.rb:140:in `start'
/var/www/discourse/vendor/bundle/ruby/2.0.0/gems/unicorn-4.8.3/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>'

(Jeff Atwood) #2

Are you on the latest Discourse? Is this behind CloudFlare or any other weird proxy?

I have no issues reading or posting in IE11 from my Surface Pro 3. So I suspect this is specific to your site’s config or possibly that user.


(Scott Smith) #3

Everything is pretty generic on both sides as far as I can tell. Well, I use Apache’s mod_proxy on the server since the machine running discourse is also running its own web server for other stuff.

Its only this user so maybe there is something corrupted on his machine.


(Kane York) #4

Does mod_proxy do any rewriting of the page? Why aren’t you using nginx for this?


(Scott Smith) #5

mod_proxy should be just passing through all the data. There may be a few cases when it does some conversions, e.g. if its not unicode it may convert.

I can’t run nginx outside the docker container as the host I am on already has an Apache server on port 80 with some custom plugins.

The proxy is just forwarding to another port so I will ask the guy to connect directly to that port to take the proxy out of the equation and see if that helps.

Scott


(Kane York) #6

Wait, if it’s only happening to one person, then it’s not a server issue.

You need to ask the USER if he’s behind any weird proxies.


(Scott Smith) #7

I asked the user and he said he had a vanilla home internet setup.

Oddly enough he was unable to log in at all after some point, but now the port 8000 page lets him log in. And, he is not getting errors anymore, from either page. Given how the user is happy and there is nothing reproducible here it seems time to declare victory. If it comes up again I will work on my proxy to make sure its not part of the problem.

Scott


(Jeff Atwood) #8

Some other possibilities:

  • upstream proxy interfering with or rewriting pages (yes, we have seen this with some ISPs)

  • local “anti-virus” software interfering with HTTP data as it comes down in the name of “protection”

  • weird local browser settings; test in a clean browser or a different browser than the one they usually browse with


(Scott Smith) #9

I did have him clear cache/cookies and no difference there. With Chrome all was fine, so some aspect of the issue is specific to IE.

Scott


(Jens Maier) #10

You are running Apache with mpm_event, right? :smile:


(Scott Smith) #11

I should be; its a standard install on the latest Ubuntu LTS.

Note the user is now telling me he thinks clearing the cookies helped… also he says he had many windows open at the same time on the site. The Apache proxy logs have some timeout errors in them so maybe his stale windows were timing out and getting into a bad state.