logstash-input-azureblob - Oh My, An error occurred. execution expired

[AshKapow]

Recently we've started to see a large number of constant timeouts that continue until Logstash is restarted.

Example of log file: Oh My, An error occurred. execution expired: ["org/jruby/ext/openssl/SSLSocket.java:217:in connect'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:800:inconnect'", "org/jruby/ext/timeout/Timeout.java:115:in timeout'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:800:inconnect'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:756:in do_start'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:745:instart'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:744:in start'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:1293:inrequest'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:1035:in get'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:80:inperform_request'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:40:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:87:inwith_net_http_connection'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:32:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday_middleware-0.12.2/lib/faraday_middleware/response/follow_redirects.rb:78:inperform_with_redirection'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday_middleware-0.12.2/lib/faraday_middleware/response/follow_redirects.rb:66:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/rack_builder.rb:139:inbuild_response'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/connection.rb:377:in run_request'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/http_response_helper.rb:27:inset_up_response'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/http_request.rb:149:in call'", "org/jruby/RubyMethod.java:116:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/retry_policy.rb:45:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/http_request.rb:110:inwith_filter'", "org/jruby/RubyMethod.java:116:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/signer_filter.rb:28:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/http_request.rb:110:in with_filter'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/service.rb:36:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/filtered_service.rb:34:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/signed_service.rb:41:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-storage-0.12.3.preview/lib/azure/storage/service/storage_service.rb:53:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-storage-0.12.3.preview/lib/azure/storage/blob/blob_service.rb:59:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-storage-0.12.3.preview/lib/azure/storage/blob/blob.rb:91:in get_blob'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:450:inload_registry'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:347:in register_for_read'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:327:inregister_for_read'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:155:in process'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:141:inrun'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:470:in inputworker'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:463:instart_input'"] {:exception=>#}

Example of log file: Oh My, An error occurred. Timeout::Error: ["/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/protocol.rb:146:in rbuf_fill'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/protocol.rb:141:inrbuf_fill'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/protocol.rb:122:in readuntil'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/protocol.rb:132:inreadline'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:2571:in read_status_line'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:2560:inread_new'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:1328:in transport_request'", "org/jruby/RubyKernel.java:1242:incatch'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:1325:in transport_request'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:1302:inrequest'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:1295:in request'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:746:instart'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:744:in start'", "/usr/share/logstash/vendor/jruby/lib/ruby/1.9/net/http.rb:1293:inrequest'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:82:in perform_request'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:40:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:87:in with_net_http_connection'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/adapter/net_http.rb:32:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday_middleware-0.12.2/lib/faraday_middleware/response/follow_redirects.rb:78:in perform_with_redirection'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday_middleware-0.12.2/lib/faraday_middleware/response/follow_redirects.rb:66:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/rack_builder.rb:139:in build_response'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/faraday-0.9.2/lib/faraday/connection.rb:377:inrun_request'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/http_response_helper.rb:27:in set_up_response'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/http_request.rb:149:incall'", "org/jruby/RubyMethod.java:116:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/retry_policy.rb:45:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/http_request.rb:110:in with_filter'", "org/jruby/RubyMethod.java:116:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/signer_filter.rb:28:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/http/http_request.rb:110:inwith_filter'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/service.rb:36:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/filtered_service.rb:34:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-core-0.1.13/lib/azure/core/signed_service.rb:41:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-storage-0.12.3.preview/lib/azure/storage/service/storage_service.rb:53:incall'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-storage-0.12.3.preview/lib/azure/storage/blob/blob_service.rb:59:in call'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-storage-0.12.3.preview/lib/azure/storage/blob/blob_service.rb:190:inacquire_lease'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/azure-storage-0.12.3.preview/lib/azure/storage/blob/blob.rb:413:in acquire_blob_lease'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:307:inacquire_lease'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:399:in update_registry'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:397:inupdate_registry'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:246:in request_registry_update'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:209:inprocess'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:158:in process'", "/usr/share/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-azureblob-0.9.12-java/lib/logstash/inputs/azureblob.rb:141:inrun'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:470:in inputworker'", "/usr/share/logstash/logstash-core/lib/logstash/pipeline.rb:463:instart_input'"] {:exception=>#}

[brahmnes]

Is there a consistent pattern in when the timeout problem starting to exhibit? eg. It starts after some constant number of hours. In both of your cases, the problem lies in some operation of the azure storage library. Have you tried a newer version of this library?

[AshKapow]

How do I try a newer version of the library?

[brahmnes]

Change the gemspec file on the azureblob plugin and restart logstash?

[brahmnes]

Hi @AshKapow

Did you try a newer azure storage library?