azuretopicthreadable: NoMethodError "reason_phrase" with wrong credentials

[gsalsero]

I'm using azuretopicthreadable 0.9.8 and logstash 6.1.1

I accidentally setup azuretopicthreadable (also a problem with azuretopic) with the wrong access_key. I got the following error:

[2018-01-15T11:11:23,199][ERROR][logstash.inputs.azuretopicthreadable] Oh My, An error occurred. Thread id:10 {:exception=>#<NoMethodError: undefined method `reason_phrase' for #>}

[brahmnes]

Do you have a callstack for that error? It would help if you have a callstack. This looks like a problem inside azure-sdk-for-ruby https://github.com/Azure/azure-sdk-for-ruby/search?utf8=%E2%9C%93&q=reason_phrase&type=

[gsalsero]

I don't, but I can easily reproduce the issue. Would you direct me on how to configure logstash so I can get a callstack? I didn't see any in logstash-plain.log or logstash-slowlog-plain.log.

[brahmnes]

You can modify the plugin code directly on your install to print the stack trace. https://stackoverflow.com/questions/376513/how-do-i-get-ruby-to-print-a-full-backtrace-instead-of-a-truncated-one

[gsalsero]

Here you go:

[2018-01-18T11:52:44,498][ERROR][logstash.inputs.azuretopicthreadable] Oh My, An error occurred. Thread id:0 {:exception=>#<NoMethodError: undefined method reason_phrase' for #<Faraday::Response:0x231da517>>} *****/logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/http/http_response.rb:50:inreason_phrase' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/http/http_error.rb:76:in `initialize' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/http/http_response.rb:74:in exception' *****/logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/http/http_request.rb:153:incall' org/jruby/RubyMethod.java:127:in call' *****/logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-0.7.10/lib/azure/service_bus/service_bus_service.rb:41:inblock in initialize' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/http/http_request.rb:110:in block in with_filter' org/jruby/RubyMethod.java:127:incall' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/http/signer_filter.rb:28:in call' *****/logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/http/http_request.rb:110:inblock in with_filter' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/service.rb:36:in `call' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/filtered_service.rb:34:in call' *****/logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/signed_service.rb:41:incall' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-0.7.10/lib/azure/service_bus/service_bus_service.rb:662:in `_retrieve_message' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-0.7.10/lib/azure/service_bus/service_bus_service.rb:656:in _peek_lock_message' *****/logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-0.7.10/lib/azure/service_bus/service_bus_service.rb:424:inpeek_lock_subscription_message' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-0.7.10/lib/azure/service_bus/service_bus_service.rb:601:in `receive_subscription_message' /logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/logstash-input-azuretopicthreadable-0.9.8/lib/logstash/inputs/azuretopicthreadable.rb:54:in process' *****/logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/logstash-input-azuretopicthreadable-0.9.8/lib/logstash/inputs/azuretopicthreadable.rb:83:inblock in run'

[brahmnes]

Thanks, the stack is very helpful. The link I gave you earlier to locations inside azure-sdk-for-ruby was incorrect. The problem apparently happens deep inside the lower layers of sdks.

Take a look at this: https://github.com/Azure/azure-ruby-asm-core/blob/master/azure-core.gemspec

it requires only 0.9 or all minor revisions of Faraday. However, the reason_phrase was added only in version Faraday 0.10.0 https://github.com/lostisland/faraday/releases/tag/v0.10.0

Please try modifying the gemspec file directly in your install and see if it fixes the problem. If it does, we should file an issue against azure-ruby-asm-core repo.

[gsalsero]

I changed it from '~> 0.9' to '~> 0.10'. I get the same stack. I also tried: '> 0.10' and '= 0.10' to no avail. Just to test it i tried something ridiculous '> 100'. Still no changes or warnings/errors that the version doesn't exist. Finally I put a syntax error in the file. I changed that line and removed the closing ' and the closing paren:

s.add_runtime_dependency('faraday', '= 100

Still nothing changed.

I'm modifying:

logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/azure-core.gemspec

I'm not a ruby developer so I don't really know if that's all I needed to do. According to 'locate', that's the only azure-core.gemspec on my system.

[brahmnes]

That's really strange, it should work. Do you see it download the new Faraday 0.10 gem? Have you restarted Logstash?

[gsalsero]

I don't see it do anything different. I stopped logstash before modifying the file, then restarted it. I just tried it again to be sure here is the log output:

[2018-01-22T14:22:18,891][INFO ][logstash.modules.scaffold] Initializing module {:module_name=>"netflow", :directory=>"/logstash-6.1.1/modules/netflow/configuration"} [2018-01-22T14:22:18,905][INFO ][logstash.modules.scaffold] Initializing module {:module_name=>"fb_apache", :directory=>"/logstash-6.1.1/modules/fb_apache/configuration"} [2018-01-22T14:22:19,111][WARN ][logstash.config.source.multilocal] Ignoring the 'pipelines.yml' file because modules or command line options are specified [2018-01-22T14:22:19,591][INFO ][logstash.runner ] Starting Logstash {"logstash.version"=>"6.1.1"} [2018-01-22T14:22:20,025][INFO ][logstash.agent ] Successfully started Logstash API endpoint {:port=>9600} [2018-01-22T14:22:22,425][INFO ][logstash.inputs.azuretopicthreadable] Using version 0.9.x input plugin 'azuretopicthreadable'. This plugin should work but would benefit from use by folks like you. Please let us know if you find bugs or have suggestions on how to improve this plugin. [2018-01-22T14:22:22,650][INFO ][logstash.pipeline ] Starting pipeline {:pipeline_id=>"main", "pipeline.workers"=>8, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>5, "pipeline.max_inflight"=>1000, :thread=>"#"} [2018-01-22T14:22:22,721][INFO ][logstash.pipeline ] Pipeline started {"pipeline.id"=>"main"} [2018-01-22T14:22:22,832][INFO ][logstash.agent ] Pipelines running {:count=>1, :pipelines=>["main"]} [2018-01-22T14:22:25,217][ERROR][logstash.inputs.azuretopicthreadable] Oh My, An error occurred. Thread id:0 {:exception=>#<NoMethodError: undefined method `reason_phrase' for #>}

[brahmnes]

@gsalsero Sorry for the delay. I also tried experiments with changing the gemspec file, but I also can't get it to work.

There are two ways to do it. One is add reason_phrase to your copy of faraday, the other is to add a check in azure-core before calling reason_phrase. The second option may be easier. So go into

logstash-6.1.1/vendor/bundle/jruby/2.3.0/gems/azure-core-0.1.14/lib/azure/core/http/http_response.rb and change the implementation to look like this:

def reason_phrase @http_response.reason_phrase unless @http_response.reason_phrase.nil? end

Let me know if that unblocks you. If it does, we should add an issue to the azure-core repo.

[gsalsero]

Sorry for implying that I was blocked. I got around this by using the correct credentials to the service bus. It would have been easier to figure this out of I had received a proper error message.

At any rate, I tried modifying http_response.rb as you suggested but I encountered the same error.

[brahmnes]

@gsalsero It's good that you found and fixed the problem that was causing the request to be rejected. It seems like what happened was, it was trying to get the reason why it failed, which would give you a better error message, but it failed due to a method missing error.

Since this happens deep within the azure core gem, I don't see much this plugin can do differently here. I am going to close this issue, and feel free to fire an issue agains the azure core repo.