JSON Parse Error for AWS ES Clusters

[faraazkhan]

Environment:

AWS ES Version: 1.5
ElasticSearch Ruby Client Gem Version: elasticsearch (1.0.14)
      elasticsearch-api (= 1.0.14)
      elasticsearch-transport (= 1.0.14)
    elasticsearch-api (1.0.14)
    elasticsearch-transport (1.0.14)

Demo client:

require 'elasticsearch'
require 'faraday_middleware'
require 'faraday_middleware/aws_signers_v4'

signing_options = {
        credentials: Aws::InstanceProfileCredentials.new,
        service_name: 'es',
        region: 'us-west-1'
       }


client = Elasticsearch::Client.new log:true, url: ENV['ES_URL']  do |f|
          f.request :aws_signers_v4, signing_options
         end
client.cluster.health

Response

/home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/2.2.0/json/common.rb:155:in `parse': 814: unexpected token at '' (MultiJson::ParseError)
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/2.2.0/json/common.rb:155:in `parse'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/multi_json-1.12.1/lib/multi_json/adapters/json_common.rb:14:in `load'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/multi_json-1.12.1/lib/multi_json/adapter.rb:21:in `load'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/multi_json-1.12.1/lib/multi_json.rb:122:in `load'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/elasticsearch-transport-1.1.3/lib/elasticsearch/transport/transport/serializer/multi_json.rb:24:in `load'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/elasticsearch-transport-1.1.3/lib/elasticsearch/transport/transport/base.rb:315:in `perform_request'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/elasticsearch-transport-1.1.3/lib/elasticsearch/transport/transport/http/faraday.rb:20:in `perform_request'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/elasticsearch-transport-1.1.3/lib/elasticsearch/transport/client.rb:128:in `perform_request'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/elasticsearch-api-1.1.3/lib/elasticsearch/api/namespace/common.rb:21:in `perform_request'
	from /home/ubuntu/.rbenv/versions/2.2.3/lib/ruby/gems/2.2.0/gems/elasticsearch-api-1.1.3/lib/elasticsearch/api/actions/cluster/health.rb:52:in `health'
	from client.rb:16:in `<main>'

[theschoolmaster]

I've been seeing a similar error since a little before noon MST also using AWS ES.

irb(main):007:0> Searchkick.client.cluster.health
MultiJson::ParseError: 822: unexpected token at '

I get the same ParseError when attempting any search or reindex via Searchkick. I was able to successfully delete an index, but everything else produces this error.

Environment:

AWS ES Version 5.3

    searchkick (2.3.0)
    elasticsearch (5.0.4)                                                                                                                                                                                                                      
      elasticsearch-api (= 5.0.4)                                                                                                                                                                                                              
      elasticsearch-transport (= 5.0.4)                                                                                                                                                                                                        
    elasticsearch-api (5.0.4)                                                                                                                                                                                                                  
      multi_json                                                                                                                                                                                                                               
    elasticsearch-transport (5.0.4) 

ruby 2.3.3p222 (2016-11-21) [x86_64-linux-gnu]

[faraazkhan]

In our case as well, this only started happening about 18 hours or so ago. Before that it was working fine, at the surface it seems that something changed on the AWS side and the gem may need to be updated. Is your cluster an AWS cluster as well @theschoolmaster

[theschoolmaster]

@faraazkhan yes indeed. updated my previous comment with some more detail.

[faraazkhan]

Just to add in the actual service we have running, we see the following error:

2017-08-29 23:14:22 +0000: Rack app error: #<Encoding::UndefinedConversionError: "\x8B" from ASCII-8BIT to UTF-8>
/home/app/.gems/gems/activesupport-4.2.3/lib/active_support/core_ext/object/json.rb:34:in `encode'
/home/app/.gems/gems/activesupport-4.2.3/lib/active_support/core_ext/object/json.rb:34:in `to_json'
/home/app/.gems/gems/activesupport-4.2.3/lib/active_support/core_ext/object/json.rb:34:in `to_json_with_active_support_encoder'
/home/app/.gems/gems/activesupport-4.2.3/lib/active_support/json/encoding.rb:57:in `to_json'
/home/app/.gems/gems/json-1.8.3/lib/json/common.rb:223:in `generate'
/home/app/.gems/gems/json-1.8.3/lib/json/common.rb:223:in `generate'
/home/app/.gems/gems/activesupport-4.2.3/lib/active_support/json/encoding.rb:101:in `stringify'
/home/app/.gems/gems/activesupport-4.2.3/lib/active_support/json/encoding.rb:35:in `encode'
/home/app/.gems/gems/activesupport-4.2.3/lib/active_support/json/encoding.rb:22:in `encode'
/home/app/.gems/gems/activesupport-4.2.3/lib/active_support/core_ext/object/json.rb:37:in `to_json_with_active_support_encoder'
/home/app/.gems/gems/multi_json-1.11.2/lib/multi_json/adapters/json_common.rb:19:in `dump'
/home/app/.gems/gems/multi_json-1.11.2/lib/multi_json/adapter.rb:25:in `dump'
/home/app/.gems/gems/multi_json-1.11.2/lib/multi_json.rb:136:in `dump'
/home/app/.gems/gems/grape-0.12.0/lib/grape/error_formatter/json.rb:12:in `call'
/home/app/.gems/gems/grape-0.12.0/lib/grape/middleware/error.rb:88:in `format_message'
/home/app/.gems/gems/grape-0.12.0/lib/grape/middleware/error.rb:77:in `error_response'
/home/app/.gems/gems/grape-0.12.0/lib/grape/middleware/error.rb:26:in `call!'
/home/app/.gems/gems/grape-0.12.0/lib/grape/middleware/base.rb:18:in `call'
/home/app/.gems/gems/newrelic_rpm-3.12.1.298/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/home/app/.gems/gems/rack-1.6.4/lib/rack/head.rb:13:in `call'
/home/app/.gems/gems/newrelic_rpm-3.12.1.298/lib/new_relic/agent/instrumentation/middleware_tracing.rb:67:in `call'
/home/app/.gems/gems/rack-1.6.4/lib/rack/builder.rb:153:in `call'
/home/app/.gems/gems/grape-0.12.0/lib/grape/endpoint.rb:196:in `call!'
/home/app/.gems/gems/grape-0.12.0/lib/grape/endpoint.rb:184:in `call'
/home/app/.gems/gems/rack-mount-0.8.3/lib/rack/mount/route_set.rb:152:in `block in call'
/home/app/.gems/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:96:in `block in recognize'
/home/app/.gems/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:68:in `optimized_each'
/home/app/.gems/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:95:in `recognize'
/home/app/.gems/gems/rack-mount-0.8.3/lib/rack/mount/route_set.rb:141:in `call'
/home/app/.gems/gems/grape-0.12.0/lib/grape/api.rb:98:in `call'
/home/app/.gems/gems/grape-0.12.0/lib/grape/api.rb:33:in `call!'
/home/app/.gems/gems/grape-0.12.0/lib/grape/api.rb:29:in `call'
/home/app/.gems/gems/rack-ssl-enforcer-0.2.9/lib/rack/ssl-enforcer.rb:52:in `call'
/home/app/.gems/gems/rack-cors-0.4.0/lib/rack/cors.rb:80:in `call'
/home/app/.gems/gems/rack-1.6.4/lib/rack/config.rb:17:in `call'
/home/app/.gems/gems/puma-2.12.2/lib/puma/configuration.rb:53:in `call'
/home/app/.gems/gems/puma-2.12.2/lib/puma/server.rb:539:in `handle_request'
/home/app/.gems/gems/puma-2.12.2/lib/puma/server.rb:386:in `process_client'
/home/app/.gems/gems/puma-2.12.2/lib/puma/server.rb:269:in `block in run'
/home/app/.gems/gems/puma-2.12.2/lib/puma/thread_pool.rb:106:in `call'
/home/app/.gems/gems/puma-2.12.2/lib/puma/thread_pool.rb:106:in `block in spawn_thread'```

[ricky-f]

We getting the same issue with the same timing

[jiajiawang]

I can see the response is actually gzipped (response header "content-encoding"=>"gzip").
Adding "Accept-Encoding": "" to the request header seems fixes the issue.
If you are using chewy, then

  Chewy.settings = {
    transport_options: {
      headers: { content_type: "application/json", "Accept-Encoding": "" },

[abraham-chan]

Another way to fix it is to add a faraday gzip middleware. https://github.com/lostisland/faraday_middleware/blob/master/lib/faraday_middleware/gzip.rb

  Chewy.settings = {
    transport_options: {
      headers: { content_type: "application/json" },
      proc: ->(f) do
        f.use FaradayMiddleware::Gzip
      end
    }
  }

[mikevm]

Without using Chewy:

  def client                                                                    
    Elasticsearch::Client.new(url: @url) do |f|                                 
      f.use FaradayMiddleware::Gzip                                             
      f.request :aws_signers_v4,                                                
                credentials: @credentials,                                      
                service_name: 'es',                                             
                region: 'us-west-1'                                             
    end                                                                   
  end

[dinusX]

Can this be the reason why compression is enabled by default ?
https://github.com/winebarrel/faraday_middleware-aws-signers-v4/blob/588b8c1086a72e2762ea3834bfff3d9f71b66024/lib/faraday_middleware/request/aws_signers_v4.rb#L70

    if Net::HTTP::HAVE_ZLIB
      env.request_headers['Accept-Encoding'] ||= 'gzip;q=1.0,deflate;q=0.6,identity;q=0.3'
    end

[michiomochi]

My application use httpclient gem, so Elasticsearch::Transport::Clientadapter settting is :httpclient.
see:

elasticsearch-ruby/elasticsearch-transport/lib/elasticsearch/transport/client.rb

Line 199 in 76f8679

def __auto_detect_adapter

In this case, following error occur.

Zlib::GzipFile::Error: not in gzip format

This error doesn't occur, Specify adapter to Faraday.default_adapter(:net_http) by argument.
e.g.

Elasticsearch::Client.new(url: @url, adapter: Faraday.default_adapter) do |f|
  f.use FaradayMiddleware::Gzip
  f.request :aws_signers_v4,
            credentials: @credentials,
            service_name: 'es',
            region: 'us-west-1'
end

For your reference 😉

[dinusX]

@michiomochi
Found something similar reported for gcloud some time ago: googleapis/google-cloud-ruby#367
One explanation there was that content was decompressed twice, and during the second time it was throwing exception Zlib::GzipFile::Error: not in gzip format

Can you paste your original Faraday configuration that is causing this exception and the list of gems that you are using (including version numbers) .
Thanks.

[dinusX]

@michiomochi
Seems that :httpclient has it's own decompression:

https://github.com/lostisland/faraday/blob/master/lib/faraday/adapter/httpclient.rb#L14

and in combination with the following line:

Elasticsearch::Client.new(url: @url, adapter: :httpclient) do |f|
  f.use FaradayMiddleware::Gzip # this line also adds gzip decompression support
  ....
end

This will cause double decompression.
I guess here the solution is to either use Faraday.default_adapter, which is :net_http or to remove line f.use FaradayMiddleware::Gzip