"Zlib::GzipFile::Error: not in gzip format", when using with Google Drive API

[marisveide]

When using Google Drive API gem, for some reason the encoding is set to gzip, but the body is actually text/json.
So the httplog crashes on that:

Zlib::GzipFile::Error: not in gzip format
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httplog-1.0.2/lib/httplog/http_log.rb:83:in `initialize'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httplog-1.0.2/lib/httplog/http_log.rb:83:in `new'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httplog-1.0.2/lib/httplog/http_log.rb:83:in `log_body'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httplog-1.0.2/lib/httplog/adapters/httpclient.rb:31:in `do_get_block'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httpclient-2.8.3/lib/httpclient.rb:1019:in `block in do_request'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httpclient-2.8.3/lib/httpclient.rb:1133:in `protect_keep_alive_disconnected'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httpclient-2.8.3/lib/httpclient.rb:1014:in `do_request'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httpclient-2.8.3/lib/httpclient.rb:1104:in `follow_redirect'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/httpclient-2.8.3/lib/httpclient.rb:854:in `request'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/http_command.rb:291:in `execute_once'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/http_command.rb:104:in `block (2 levels) in execute'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/retriable-3.1.1/lib/retriable.rb:61:in `block in retriable'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/retriable-3.1.1/lib/retriable.rb:57:in `times'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/retriable-3.1.1/lib/retriable.rb:57:in `retriable'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/http_command.rb:101:in `block in execute'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/retriable-3.1.1/lib/retriable.rb:61:in `block in retriable'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/retriable-3.1.1/lib/retriable.rb:57:in `times'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/retriable-3.1.1/lib/retriable.rb:57:in `retriable'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/http_command.rb:93:in `execute'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/base_service.rb:360:in `execute_or_queue_command'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/generated/google/apis/drive_v2/service.rb:1290:in `list_files'
./app/lib/utils/remote_file_system/google_drive.rb:42:in `block in files_in_folder'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/base_service.rb:51:in `block in initialize'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/base_service.rb:53:in `block in initialize'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/base_service.rb:64:in `block in each'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/base_service.rb:63:in `loop'
/Users/maris/.rvm/gems/ruby-2.4.1/gems/google-api-client-0.20.1/lib/google/apis/core/base_service.rb:63:in `each'
./spec/lib/remote_file_system/google_drive_spec.rb:19:in `block (3 levels) in <top (required)>'

I know it may be better to wait for Google to fix the place where it decodes the body earlier, to reset the encoding or something, but it might never happen.

So I suggest to fix this place in code to handle the cases when the encoding is set to "gzip", but body is actually not gzipped anymore.

[marisveide]

I found that it might be unzipped by rspec, so the httplog gets an exception when trying to unzip the content again.

Suggesting the following fix in the http_log.rb file "log_body" method - basically to rescue from the exception of unzipping not zipped body:

      if encoding =~ /gzip/ && body && !body.empty?
        begin
          sio = StringIO.new(body.to_s)
          gz = Zlib::GzipReader.new(sio)
          body = gz.read
        rescue Zlib::GzipFile::Error => e
          log("Error decompressing body: #{e.message}")
        end
      end

[trusche]

Thanks for the detailed report, I'll take a look now.

[trusche]

@marisveide I'm having a hard time reproducing this in test code - if I simply send a text file with a gzip encoding, ruby's net/http raises a Zlib::DataError before httplog ever gets a chance to try its own unzip. Could you provide a test that fails with your particular error, or a code snippet using the Drive API that I can use as a basis to write a failing spec?

[marisveide]

Thank you @trusche for looking into this... I really appreciate that.

Yeah, I tried to make the simple Ruby file that would reproduce that issue, but I also didn't succeed - works like a charm. It looks like there is some gem in the middle that catches it.

Strange is that this error happens only when I run the test code from rspec. When I just run the code even in rails console, it also works fine.
I was hoping it's the rspec, but those guys said it cannot be.

It's happening in my Rails project so it can be anything in the middle, right?
For now, I just edited the http_log.rb file locally to catch that exception, and it works fine now.

But I will try to create a sample that reproduces that issue. I realize how wrong it is to fix an issue that's not reproducible in the first place...

[marisveide]

Whew, got to reproduce that!
Here is the git repo with clean Rails project and just added the Google Cloud API and httplog, and the Rspec test that reproduces that error.
https://github.com/marisveide/reproduce-gzip-error-in-httplog

This is that test to run, to get that error: https://github.com/marisveide/reproduce-gzip-error-in-httplog/blob/master/spec/lib/google_drive_spec.rb

Related issue in google-api-ruby-client repo: googleapis/google-api-ruby-client#661

[trusche]

Got it. I'd suggest to delete that repo immediately unless the private key in there is for a dedicated test account...

[marisveide]

That's ok, I have created the special test key for just this case.
I will delete the key on the Google Cloud side when you will confirm that the root cause is found and fixed.

[trusche]

Found it. The Google API gem uses HTTPClient with the option transparent_gzip_decompression = true. Working on a fix, stay tuned.

[trusche]

Could you please try master, this should no longer throw an error but add a line to the log file stating that gzip decompression failed (same as your solution, really)

[marisveide]

Yey, thanks!
It works, perfect!

Thank you so much for fixing this. Although the root cause is not in httplog - proves the value of "defensive programming" (never trust the input). :)

[trusche]

Well, it kind of is in httplog. Lesson learned (again). 😁

Released v1.0.3. Cheers