amazon-archives / aws-sdk-core-ruby

This repository has moved to the master branch of aws/aws-sdk-ruby
https://github.com/aws/aws-sdk-ruby
243 stars 57 forks source link

XML parsing error on values #177

Closed amedeiros closed 9 years ago

amedeiros commented 9 years ago

https://github.com/aws/aws-sdk-core-ruby/blob/master/aws-sdk-core/lib/aws-sdk-core/xml/parser.rb#L18 is getting back a nil object.

NoMethodError undefined methodvalues' for nil:NilClass vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/aws-sdk-core/xml/parser.rb:18parse vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/aws-sdk-core/plugins/protocols/ec2.rb:14parse_xml vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/aws-sdk-core/query/handler.rb:13block in call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/response.rb:34on vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/response.rb:41on_success vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/aws-sdk-core/query/handler.rb:11call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/aws-sdk-core/plugins/user_agent.rb:12call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/plugins/restful_bindings.rb:13call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/plugins/endpoint.rb:35call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/plugins/param_validation.rb:22call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/plugins/raise_response_errors.rb:14call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/plugins/param_conversion.rb:22call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/aws-sdk-core/plugins/response_paging.rb:10call vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/request.rb:70send_request vendor/bundle/ruby/2.1.0/gems/aws-sdk-core-2.0.11/lib/seahorse/client/base.rb:215block (2 levels) in define_operation_methods vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/tools/retry_proxy.rb:23block (2 levels) in define_methods vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/source_proxy.rb:26get_data vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/source_proxy.rb:51method_missing vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/signatures/aws_ec2_001.rb:29perform vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/dsl/internal_dsl.rb:35alert vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/signature_engine.rb:46block in perform vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/signature_engine.rb:40each vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/signature_engine.rb:40perform vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/signature_engine.rb:30block (2 levels) in single_alert vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/base.rb:14call vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/base.rb:14block in on_regions vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/base.rb:13each vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/base.rb:13on_regions vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/signature_engine.rb:29block in single_alert vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/signature_engine.rb:90alert_helper vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/engines/signature_engine.rb:27single_alert vendor/bundle/ruby/2.1.0/gems/metascrape-1.1.4.rc5/lib/api.rb:44single_alert /home/ubuntu/.rvm/rubies/ruby-2.1.5/lib/ruby/2.1.0/delegate.rb:81method_missing app/workers/report/process_signature.rb:31block in run_metascrape vendor/bundle/ruby/2.1.0/gems/semantic_logger-2.10.0/lib/semantic_logger/base.rb:315call vendor/bundle/ruby/2.1.0/gems/semantic_logger-2.10.0/lib/semantic_logger/base.rb:315benchmark_internal vendor/bundle/ruby/2.1.0/gems/semantic_logger-2.10.0/lib/semantic_logger/base.rb:93benchmark_info app/workers/report/process_signature.rb:30run_metascrape app/workers/report/process_signature.rb:21perform vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/processor.rb:75execute_job vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/processor.rb:52block (2 levels) in process vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:122call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:122block in invoke vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.6.257/lib/new_relic/agent/instrumentation/sidekiq.rb:33block in call vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.6.257/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:365perform_action_with_newrelic_trace vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.6.257/lib/new_relic/agent/instrumentation/sidekiq.rb:29call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:124block in invoke vendor/bundle/ruby/2.1.0/gems/sidetiq-0.6.3/lib/sidetiq/middleware/history.rb:8call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:124block in invoke vendor/bundle/ruby/2.1.0/gems/sidekiq-pro-1.9.1/lib/sidekiq/batch/middleware.rb:26call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:124block in invoke vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/server/active_record.rb:6call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:124block in invoke vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/server/retry_jobs.rb:74call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:124block in invoke vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/server/logging.rb:11block in call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/logging.rb:22with_context vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/server/logging.rb:7call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:124block in invoke vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:127call vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/middleware/chain.rb:127invoke vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/processor.rb:51block in process vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/processor.rb:98stats vendor/bundle/ruby/2.1.0/gems/sidekiq-3.2.6/lib/sidekiq/processor.rb:50process vendor/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25public_send vendor/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25dispatch vendor/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/calls.rb:122dispatch vendor/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:322block in handle_message vendor/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/actor.rb:416block in task vendor/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks.rb:55block in initialize vendor/bundle/ruby/2.1.0/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:13block in create`

trevorrowe commented 9 years ago

I did a little bit of work on my end to reproduce this error. I am unable to reproduce this from my end. When a #describe_snapshots response contains no snapshots, the response XML is still parseable. In theory, this should never happen, and the related pull-request should not be needed.

In practice this looks like another issue that was closed previously, #56. I was unable to reproduce that error as well, and the submitter, @lardcanoe closed the issue because he never ran into it again.

The XML parser is given the data from the HTTP response body to parse. This happens by calling #body_contents on the Seahorse::Client::Http::Response. The #body_contents method rewinds the body IO object and then calls #read on it without any arguments. This should always return a string even if it is an empty string.

This means that MultiXml.parse should always receive a string value. I am only able to cause this failure by passing nil to MultiXml.parse. This tells me that something else is going wrong here.

# this works and does not raise
MultiXml.parse('').values.first 

# oops, triggers the error reported in this issue
MultiXml.parse(nil).values.first

Would you be willing to add some code that watches for this condition, where a nil value is being passed to MultiXml and then cod the http response content?

class Aws::Xml::Query::Handler

  def xml(context)
    xml = context.http_response.body_contents
    if xml.nil?
      # write this output to some file or log, using stderr for an example
      $stderr.puts(context.http_response.inspect)
      $stderr.puts(context.http_response.body.read.inspect)
    end
    xml
  end

end

My biggest concern is that is we merged the pull-request, it will mask a larger error.

amedeiros commented 9 years ago

We have only seen the error twice so far once yesterday and once today. I can add your code and log the results the next time it happens thank you.

trevorrowe commented 9 years ago

Just pinging for updates. Have you run across this issue again?

trevorrowe commented 9 years ago

Closing this stale issue. Please re-open if you encounter this issue again or if you have additional information.