lundi 29 janvier 2018

How to find/fix a "stackoverflow exception in /action_dispatch/middleware/reloader"?

I get this Exception sporadic on my production debian / rails 3.2.22.5

It feels that it has something to do with caching.

I have a "permission_checker" that is called width almost every call on the server. It checks permission of the object requested - going down all records/models till it finds the final owner of this object/record, and then decides:

when no owner found then 404
when owner found same as logged in user then process page
when owner found is the public owner then process page read only
else raise permission exception

so far so good

The code looks like that (the 'aaa' so on and level error just for debugging)

# some processing to find the owner
# id_val is a hash holding the result of this

logger.error "needed owner id :#{id_val}".yellow

logger.error "aaa".yellow
needed_owner_id=id_val[:person_id]
if needed_owner_id
    logger.error "bbb  #{needed_owner_id}".yellow
    needed_owner=Person.find(needed_owner_id)  #<----- here is the crash
    logger.error "ccc".yellow
    logger.error "needed owner id :#{needed_owner_id} (#{needed_owner.owner_type}".red.on_white
    logger.error "ddd".yellow
    logger.error "current person id :#{@current_person ? @current_person.id : nil}".red.on_white
else
    logger.error "no needed owner found"
end

# further processing

if i don't get the stackoverflow, the output looks like this:

Started GET "/ldc/order_forms/ec0a08a6-8525-4c6e-9056-d387e7ad3b9c/edit" 
Processing by Ldc::OrderFormsController#edit as HTML
  Parameters: {"id"=>"ec0a08a6-8525-4c6e-9056-d387e7ad3b9c"}
  LoginData Load (0.1ms)  SELECT `login_data`.* FROM `login_data` WHERE `login_data`.`id` = '083a684f-db0e-4c87-a44e-d434d3334289' LIMIT 1
  Ldc::Person Load (0.1ms)  SELECT `ldc_people`.* FROM `ldc_people` WHERE `ldc_people`.`ustate` = 'A' AND `ldc_people`.`login_data_id` = '083a684f-db0e-4c87-a44e-d434d3334289' LIMIT 1
check in: {:order_form_id=>"ec0a08a6-8525-4c6e-9056-d387e7ad3b9c", :person_id=>nil}
  Ldc::OrderForm Load (0.1ms)  SELECT `ldc_order_forms`.* FROM `ldc_order_forms` WHERE `ldc_order_forms`.`ustate` = 'A' AND `ldc_order_forms`.`id` = 'ec0a08a6-8525-4c6e-9056-d387e7ad3b9c' LIMIT 1
  CACHE (0.0ms)  SELECT `ldc_order_forms`.* FROM `ldc_order_forms` WHERE `ldc_order_forms`.`ustate` = 'A' AND `ldc_order_forms`.`id` = 'ec0a08a6-8525-4c6e-9056-d387e7ad3b9c' LIMIT 1
needed owner id :{:person_id=>"c7285c28-0906-4592-bbd7-3fbe164a337e"}
aaa
bbb  c7285c28-0906-4592-bbd7-3fbe164a337e
  Ldc::Person Load (0.1ms)  SELECT `ldc_people`.* FROM `ldc_people` WHERE `ldc_people`.`ustate` = 'A' AND `ldc_people`.`id` = 'c7285c28-0906-4592-bbd7-3fbe164a337e' LIMIT 1
ccc
needed owner id :c7285c28-0906-4592-bbd7-3fbe164a337e
ddd
current person id :c7285c28-0906-4592-bbd7-3fbe164a337e
--------- permission check done ---------

If it fails then its all the same until the crash:

check in: {:order_form_id=>"ec0a08a6-8525-4c6e-9056-d387e7ad3b9c", :person_id=>nil}
  Ldc::OrderForm Load (3.2ms)  SELECT `ldc_order_forms`.* FROM `ldc_order_forms` WHERE `ldc_order_forms`.`ustate` = 'A' AND `ldc_order_forms`.`id` = 'ec0a08a6-8525-4c6e-9056-d387e7ad3b9c' LIMIT 1
  CACHE (0.0ms)  SELECT `ldc_order_forms`.* FROM `ldc_order_forms` WHERE `ldc_order_forms`.`ustate` = 'A' AND `ldc_order_forms`.`id` = 'ec0a08a6-8525-4c6e-9056-d387e7ad3b9c' LIMIT 1
needed owner id :{:person_id=>"c7285c28-0906-4592-bbd7-3fbe164a337e"}
aaa
bbb  c7285c28-0906-4592-bbd7-3fbe164a337e
Completed 500 Internal Server Error in 223.8ms

SystemStackError (stack level too deep):
  actionpack (3.2.22.5) lib/action_dispatch/middleware/reloader.rb:70

The code for lib/action_dispatch/middleware/reloader.rb:70 is a raise:

def call(env)
  @validated = @condition.call
  prepare!
  response = @app.call(env)
  response[2] = ActionDispatch::BodyProxy.new(response[2]) { cleanup! }
  response
rescue Exception
  cleanup!
  raise
end

Any ideas what these lines do, so I can search further?

Aucun commentaire:

Enregistrer un commentaire