praxis / attributor

A powerful attribute and type management library for Ruby
MIT License
13 stars 16 forks source link

Intermittent Attributor::InvalidDefinition when running multi-threaded app under rainbows #174

Open justingaylor opened 8 years ago

justingaylor commented 8 years ago

When running under rainbows in multi-threaded mode (50 workers, 2 threads/worker) to investigate another issue, I've encountered the following intermittent errors.

Type: Attributor::InvalidDefinition, Message: Structure definition for type #<Class:0x00000004241fb8> is invalid. The following exception has occurred: #<RuntimeError: can't add a new key into hash during iteration>, Backtrace: 
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/attributor-5.0.2/lib/attributor/types/hash.rb:84:in `attributes'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/attributor-5.0.2/lib/attributor/types/model.rb:180:in `method_missing'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/attributor-5.0.2/lib/attributor/types/model.rb:139:in `block in validate'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/attributor-5.0.2/lib/attributor/types/model.rb:136:in `each'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/attributor-5.0.2/lib/attributor/types/model.rb:136:in `validate'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/attributor-5.0.2/lib/attributor/types/hash.rb:430:in `validate'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/attributor-5.0.2/lib/attributor/attribute.rb:215:in `validate'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request.rb:151:in `validate_params'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request_stages/validate_params_and_headers.rb:48:in `execute'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request_stages/request_stage.rb:83:in `execute_with_around'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request_stages/request_stage.rb:61:in `run'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request_stages/request_stage.rb:111:in `block in execute'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request_stages/request_stage.rb:110:in `each'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request_stages/request_stage.rb:110:in `execute'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request_stages/request_stage.rb:83:in `execute_with_around'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/request_stages/request_stage.rb:61:in `run'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/dispatcher.rb:87:in `block (2 levels) in dispatch'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/dispatcher.rb:86:in `each'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/dispatcher.rb:86:in `block in dispatch'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/notifications.rb:164:in `block in instrument'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/notifications.rb:164:in `instrument'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/notifications.rb:24:in `instrument'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/dispatcher.rb:81:in `dispatch'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/bootloader_stages/routing.rb:19:in `call'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/router.rb:17:in `call'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/router.rb:35:in `invoke'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/router/simple.rb:129:in `block (2 levels) in call'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/router/simple.rb:127:in `catch'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/router/simple.rb:127:in `block in call'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/router/simple.rb:126:in `each'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/router/simple.rb:126:in `call'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/router.rb:77:in `call'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/application.rb:115:in `block in call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/notifications.rb:164:in `block in instrument'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/notifications.rb:164:in `instrument'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/notifications.rb:24:in `instrument'
  <APP_ROOT>/vendor/cache/praxis-ca6f964fc155/lib/praxis/application.rb:114:in `call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/stalin-0.2.0/lib/stalin/adapter/rack.rb:30:in `call'
  <APP_ROOT>/vendor/cache/global_session-66c8bdcf73b8/lib/global_session/rack.rb:146:in `call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rack-contrib-1.4.0/lib/rack/contrib/cookies.rb:44:in `call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/right_support-2.11.3/lib/right_support/rack/request_logger.rb:129:in `call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/right_support-2.11.3/lib/right_support/rack/request_tracker.rb:78:in `call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rack_injection-0.2.0/lib/rack_injection.rb:12:in `call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rack-contrib-1.4.0/lib/rack/contrib/runtime.rb:18:in `call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rainbows-4.7.0/lib/rainbows/max_body.rb:66:in `block in call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rainbows-4.7.0/lib/rainbows/max_body.rb:59:in `catch'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rainbows-4.7.0/lib/rainbows/max_body.rb:59:in `call'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rainbows-4.7.0/lib/rainbows/process_client.rb:44:in `process_loop'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rainbows-4.7.0/lib/rainbows/thread_pool.rb:41:in `sync_worker'
  <APP_ROOT>/vendor/bundle/ruby/2.1.0/gems/rainbows-4.7.0/lib/rainbows/thread_pool.rb:25:in `block (2 levels) in worker_loop'

My test sends 100 concurrent requests to the service, all the same exact request format. Of the 100 requests, 2 or 3 return "400 Bad Request" with the above validation error, while the rest of the requests return 200 OK.

Here's the response body for the failures:

{
  "name": "ValidationError",
  "summary": "Error loading params.",
  "errors": [
    "Error loading attribute $.params of type  from value {\"limit\"=>\"1\"}\nStructure definition for type #<Class:0x00000004241fb8> is invalid. The following exception has occurred: #<RuntimeError: can't add a new key into hash during iteration>"
  ],
  "cause": {
    "name": "Attributor::InvalidDefinition",
    "message": "Structure definition for type #<Class:0x00000004241fb8> is invalid. The following exception has occurred: #<RuntimeError: can't add a new key into hash during iteration>"
  }
}

It feels like this could be a problem with thread safety in the params hash processing in praxis/attributor, so I thought I would report here.

Please let me know if I should report this under praxis or here and how I can help. Cheers.

justingaylor commented 8 years ago

I looked a bit into the code and found this is where the error is raised: https://github.com/rightscale/attributor/blob/fbaae0a4fccd8ab04761ac1784eeae55eb7c01dc/lib/attributor/types/hash.rb#L83

And it appears @errors is only set here: https://github.com/rightscale/attributor/blob/fbaae0a4fccd8ab04761ac1784eeae55eb7c01dc/lib/attributor/types/hash.rb#L116