Undefined method `each_pair' for nil:NilClass - DynamoDB

[karlfreeman]

I keep seeing this sporadically happening when using batch_get. It looks like it stems from when each_attributes calls each which sometimes returns nil. Is this the desired affect?

[karlfreeman]

I'm using it roughly like so:

dynamodb_query = dynamodb_table.batch_get(:all, feed)

unless dynamodb_query.nil?
  dynamodb_query.each { | activity |
    parse_activity(activity)
  }
end

[lsegal]

Can you provide a backtrace for the above exception?

[karlfreeman]

Sure, not much to the back trace though. Thanks for the quick reply!

gems/aws-sdk-1.8.0/lib/aws/dynamo_db/batch_get.rb:150 • each
gems/aws-sdk-1.8.0/lib/aws/dynamo_db/batch_get.rb:169 • each_attributes
/usr/local/api/releases/20130124112142/lib/unmagnify/me/activity/index.rb:51 • each
/usr/local/api/releases/20130124112142/lib/unmagnify/me/activity/index.rb:51 • response
bundler/gems/goliath-ea70864f86a9/lib/goliath/api.rb:227 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/async_middleware.rb:73 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/async_middleware.rb:73 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/simple_aroundware_factory.rb:77 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/validation/default_params.rb:39 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/validation/default_params.rb:39 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/params.rb:66 • block in call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/validator.rb:40 • safely
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/params.rb:64 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/default_mime_type.rb:26 • call
/usr/local/api/releases/20130124112142/lib/unmagnify/middleware/path_params.rb:18 • block in call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/validator.rb:40 • safely
/usr/local/api/releases/20130124112142/lib/unmagnify/middleware/path_params.rb:15 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/validation/request_method.rb:29 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/async_middleware.rb:73 • call
/usr/local/api/releases/20130124112142/lib/unmagnify/middleware/cors.rb:23 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/async_middleware.rb:73 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/async_middleware.rb:73 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/async_middleware.rb:73 • call
gems/rack-1.4.3/lib/rack/content_length.rb:14 • call
gems/async-rack-0.5.1/lib/async_rack/async_callback.rb:114 • call
gems/async-rack-0.5.1/lib/async_rack/async_callback.rb:91 • block in new
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/builder.rb:56 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/builder.rb:56 • block (3 levels) in build
gems/http_router-0.9.7/lib/http_router.rb:165 • call
gems/http_router-0.9.7/lib/http_router.rb:165 • process_destination_path
(eval):178 • block (2 levels) in inject_root_methods
(eval):168 • catch
(eval):168 • block in inject_root_methods
(eval):107 • block in inject_root_methods
gems/http_router-0.9.7/lib/http_router/node/root.rb:68 • []
gems/http_router-0.9.7/lib/http_router.rb:118 • block in call
gems/http_router-0.9.7/lib/http_router.rb:118 • catch
gems/http_router-0.9.7/lib/http_router.rb:118 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/async_middleware.rb:73 • call
/usr/local/api/releases/20130124112142/lib/unmagnify/middleware/cors.rb:23 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/favicon.rb:26 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/rack/async_middleware.rb:73 • call
gems/rack-1.4.3/lib/rack/content_length.rb:14 • call
gems/async-rack-0.5.1/lib/async_rack/async_callback.rb:114 • call
gems/async-rack-0.5.1/lib/async_rack/async_callback.rb:91 • block in new
bundler/gems/goliath-ea70864f86a9/lib/goliath/request.rb:163 • call
bundler/gems/goliath-ea70864f86a9/lib/goliath/request.rb:163 • block in process

[karlfreeman]

I thought perhaps #161 might fix this, however its close but no cigar. Still having

NoMethodError: undefined method 'each_pair' for nil:NilClass

at https://github.com/aws/aws-sdk-ruby/blob/master/lib/aws/dynamo_db/batch_get.rb#L150 sporadically.

[jmclachlan]

I wonder if this is all related. I randomly get this error quite a bit when using DynoDB with threads.

undefined method tables' for <AWS::DynamoDB>:AWS::DynamoDB /task/__gems__/gems/aws-sdk-1.8.5/lib/aws/record/hash_model.rb:86:indynamo_db_table'
/task/gems/gems/aws-sdk-1.8.5/lib/aws/record/hash_model/finder_methods.rb:28:in find_by_id' /task/__gems__/gems/aws-sdk-1.8.5/lib/aws/record/scope.rb:97:infind'
/task/gems/gems/aws-sdk-1.8.5/lib/aws/record/hash_model/finder_methods.rb:77:in `find'

[karlfreeman]

Looking at that stack trace it doesn't appear to be related. However don't hold me to it 😉

[trevorrowe]

@jmclachlan Are you calling AWS.eager_autoload! before you start your concurrency? The SDK makes heavy use of autoload, which is not thread-safe. The AWS.eager_autoload! method forcibly loads all library files across the SDK (this can be slow when they are not cached). This generally clears up threading issues though.

[jmclachlan]

Nope. You are right. I think this is just a more general issue with the base client initialization and threads. My bad.

#90

[jmclachlan]

@trevorrowe Awesome. That fixes everything. Thanks a bunch.

[karlfreeman]

@trevorrowe Is there anything more I can do to help figure out why these nil's keep cropping in response.data['Responses']

[trevorrowe]

I can not verify this yet (I will though), but it looks like DynamoDB is not returning the data at 'Responses'. My guess is the response is returned with no data, and ALL of the request items are returned as unprocessed keys. If this is the case, the fix is a one-liner ((response.data['Responses'] || {}).each_pair).

[trevorrowe]

I should also add, this could be happening if you are getting throttled.

[karlfreeman]

There's a good chance that we're getting throttled every now and again so that could be the cause.

[karlfreeman]

I'll also add I've just seen this happen on response.data["Items"] too

[trevorrowe]

@karlfreeman Sorry for the long absence on this issue. In both cases, it would be possible to coerce the nil value to an empty array. I'm afraid by doing this, we could mask some other issue.

If you are able to reproduce this issue somewhat reliably it would be SUPER helpful if you could enable http wire logging. This would dump the entire http response body (that is getting JSON parsed) and would answer the question if the key is missing from the source, or if there is some issue in the SDK causing this buggy behavior.

You can enable http wire logging like so:

# send the log output somewhere more useful than stdout, like a file
require 'logger'
AWS.config(:http_wire_trace => true, :logger => Logger.new($stdout))

You can reduce the scope of what requests get wire-logged by creating a ddb instance that logs instead:

ddb_without_wire_trace = AWS::DynamoDB.new
ddb_with_wire_trace = AWS::DynamoDB.new(:http_wire_trace => true, :logger => Logger.new(...))

Thanks!

[lsegal]

I'm going to close this issue since there has been no feedback in the last few months. @karlfreeman, if you are still having problems with DynamoDB in your application, please follow @trevorrowe's instructions and provide some more detailed logging of your requests so we can narrow down the problem. Thanks!