Search API v1.1 with max_id parameter failing at very low level (Short gzip encoded response corruption)

[waynep]

Some acknowledgement from the Twitter team would be nice here. Either it’s a known issue and won’t be fixing it on their side OR they’re working on it so we know how to proceed.

[daixque]

I have same problem. I’ve found some issues about this problem on github.

• https://github.com/sferik/twitter/issues/354
• https://github.com/sferik/twitter/issues/369
• https://github.com/sferik/twitter/issues/370
  Now I’m trying to access against HTTP endpoint (see #354).
  
client = Twitter::Client.new(:endpoint => “http://api.twitter.com”)

  Indeed this should be temporary solution, but it currently works fine.

[kurrik]

I don’t think this is a good solution. I was able to connect from Ruby using an explicit SSL setup, see https://gist.github.com/sferik/5208022 for more information.

Ultimately, I don’t know why the behavior of net/http changed, but it’s flat-out sending the wrong type of request (a http request to a https endpoint) and I don’t consider this a bug on Twitter’s end.

[kurrik]

We have been seeing some “end of file” issues with Ruby which appear to be related to SSL, but not really related to gzip (they’re issues if you connect with or without gzip). My feeling is that maybe some server on Twitter’s end has started being more strict about SSL connections and the gzip switch may be routing your request slightly differently.

If you do identify a gzip issue, please start a new thread - I’m going to treat this one primarily as dealing with SSL.

[kurrik]

From what I’m seeing, request from Ruby are malformed. It may be possible that we’ve started being more strict about what we accept, but ultimately changes need to occur in Ruby code to send the request correctly, specifically setting up SSL explicitly:

http.use_ssl = true
http.verify_mode = OpenSSL::SSL::VERIFY_PEER

You can see the tests I’ve been running in this gist:

https://gist.github.com/kurrik/5214671

Regarding bugs and escalations, this is the correct place to surface API issues. We have an issue tracker as well, but in cases like this it’s nice to have a discussion thread so that we can collect more information.

[kurrik]

If someone could verify whether explicitly setting up SSL fixes the gem, I’d really appreciate it. This would look something like this:

http.use_ssl = true http.verify_mode = OpenSSL::SSL::VERIFY_PEER

Longer example: https://gist.github.com/kurrik/5214671

The header fix is a hack. This would be a rational solution.

[waynep]

Looks like the twitter gem internally uses the Faraday gem for networking. Explicitly setting Faraday gem to SSL and verify seems to fail also?

1.9.3p194 :203 > f = Faraday.new "https://api.twitter.com/1.1/users/show.json?user_id=33978", ssl: {verify: true} do |c| 1.9.3p194 :204 > c.use Faraday::Adapter::NetHttp 1.9.3p194 :205?> end => #"33978"}, @options={}, @ssl={:verify=>true}, @parallel_manager=nil, @default_parallel_manager=nil, @builder=#, @url_prefix=#, @proxy=nil> 1.9.3p194 :206 > f.get Faraday::Error::ConnectionFailed: end of file reached ...

[kurrik]

Thanks, this gives me another avenue to go down. I’ll see what kind of request this issues.

[kurrik]

Weirdly I’m not able to reproduce, even if I don’t set Faraday’s ssl options explicitly:

require 'rubygems' require 'faraday' url = "https://api.twitter.com/1.1/users/show.json?user_id=33978" conn = Faraday.new(:url => url, :proxy => "http://localhost:8080") do |faraday| faraday.adapter :net_http end response = conn.get puts "Faraday: #{response.body}"

yields

Faraday: {"errors":[{"message":"Bad Authentication data","code":215}]}

The proxied request appears to be formatted correctly (sending https request):

GET https://api.twitter.com/1.1/users/show.json?user_id=33978 ← 400 application/json 61B

[JustinSPowers]

@kurrik fwiw I was able to reproduce the EOF error using that same code in a brand new irb session. Not sure if there is some environmental difference that could be causing it.

[waynep]

tl;dr Temp solution for Twitter gem https://gist.github.com/waynepan/5218264

Details:

Solved the mystery, but I’ve reached my limits of network knowledge so need some help here. SSL seems to be a red herring.

Faraday sends “Connection: close” header by default and Twitter echoes this.

Setup

url = "http://api.twitter.com/1.1/users/show.json?user_id=33978"
conn = Faraday.new(:url => url) do |faraday|
faraday.adapter :net_http
end

Normal Faraday request

1.9.3p194 :256 > conn.get
Faraday::Error::ConnectionFailed: end of file reached

and TCP stream:

GET /1.1/users/show.json?user_id=33978 HTTP/1.1
User-Agent: Faraday v0.8.6
Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
Accept: /
Connection: close
Host: api.twitter.com

HTTP/1.1 400 Bad Request
content-type: application/json; charset=utf-8
date: Fri, 22 Mar 2013 01:03:27 UTC
server: tfe
set-cookie: guest_id=v1%3A136391420724649092; Domain=.twitter.com; Path=/; Expires=Sun, 22-Mar-2015 01:03:27 UTC
Transfer-Encoding: chunked
Content-Encoding: gzip
Connection: close

Now, leaving Connection header empty

conn.headers = { ‘Connection’ => “” }
conn.get

TCP Stream:

GET /1.1/users/show.json?user_id=33978 HTTP/1.1
Connection:
Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
Accept: /
User-Agent: Ruby
Host: api.twitter.com

HTTP/1.1 400 Bad Request
content-type: application/json; charset=utf-8
date: Fri, 22 Mar 2013 01:13:57 UTC
server: tfe
set-cookie: guest_id=v1%3A136391483755534473; Domain=.twitter.com; Path=/; Expires=Sun, 22-Mar-2015 01:13:57 UTC
Transfer-Encoding: chunked
Content-Encoding: gzip

CURL even returns 18 error code (w/ Connection: close)

wp$ curl -v --compressed --header “Connection: close” http://api.twitter.com/1.1/users/show.json?user_id=33978

• About to connect() to api.twitter.com port 80 (#0)
• Trying 199.59.148.87…
• connected
• Connected to api.twitter.com (199.59.148.87) port 80 (#0)

GET /1.1/users/show.json?user_id=33978 HTTP/1.1
User-Agent: curl/7.24.0 (x86_64-apple-darwin12.0) libcurl/7.24.0 OpenSSL/0.9.8r zlib/1.2.5
Host: api.twitter.com
Accept: /
Accept-Encoding: deflate, gzip
Connection: close

< HTTP/1.1 400 Bad Request
< content-type: application/json; charset=utf-8
< date: Fri, 22 Mar 2013 01:19:38 UTC
< server: tfe
< set-cookie: guest_id=v1%3A136391517818400799; Domain=.twitter.com; Path=/; Expires=Sun, 22-Mar-2015 01:19:38 UTC
< Transfer-Encoding: chunked
< Content-Encoding: gzip
< Connection: close
<

• transfer closed with outstanding read data remaining
• Closing connection #0
  curl: (18) transfer closed with outstanding read data remaining
  {“errors”:[{“message”:“Bad Authentication data”,“code”:215}]}
  

w/o any Connection header

wp$ curl -v --compressed http://api.twitter.com/1.1/users/show.json?user_id=33978

• About to connect() to api.twitter.com port 80 (#0)
• Trying 199.59.148.87…
• connected
• Connected to api.twitter.com (199.59.148.87) port 80 (#0)

GET /1.1/users/show.json?user_id=33978 HTTP/1.1
User-Agent: curl/7.24.0 (x86_64-apple-darwin12.0) libcurl/7.24.0 OpenSSL/0.9.8r zlib/1.2.5
Host: api.twitter.com
Accept: /
Accept-Encoding: deflate, gzip

< HTTP/1.1 400 Bad Request
< content-type: application/json; charset=utf-8
< date: Fri, 22 Mar 2013 01:20:45 UTC
< server: tfe
< set-cookie: guest_id=v1%3A136391524591891982; Domain=.twitter.com; Path=/; Expires=Sun, 22-Mar-2015 01:20:45 UTC
< Transfer-Encoding: chunked
< Content-Encoding: gzip
<

• Connection #0 to host api.twitter.com left intact
  {“errors”:[{“message”:“Bad Authentication data”,“code”:215}]}* Closing connection #0
  

At this point, my knowledge of what’s the proper behavior for Connection: close is supposed to be. CURL reporting error 18 (transfer closed) is troubling though.

[johnbarratt]

That looks like you are using ruby 1.8 there, while I don’t get exactly the same response with REE 1.8.7 (get 500 reported), I don’t get the EOF error. However in ruby 1.9 it fails exactly as it does for @waynep.

Looking at your gist, I can reproduce the same results as you on that, but note that they aren’t ‘proper’ (authenticated) requests, so perhaps are behaving differently due to that.

[johnbarratt]

I’ve narrowed this down to only being a problem for chunked responses (not those with a content length). It seems that Twitter is no longer sending the final ‘0’ chunk (See http://en.wikipedia.org/wiki/Chunked_transfer_encoding for the spec), and ruby is getting unhappy about that. Other clients on other platforms may be happy to just figure ‘that was all then’ and say all was OK.

Anyway, to work around this missing ‘0’ from the end, you can patch Net::HTTPResposne::get_chunked using the code below (include it in your script after loading ‘net/http’. I am not an expert on this code, and it may well have serious unintended consequences, so use at your own risk! That said, it seems to work great for us, and allows us to once again get gzipped content from the API reliably.

@kurrik, given this info, can you confirm this from your end?

The specific bit that is patched below is :

line = @socket.readline

To :

begin line = @socket.readline rescue EOFError return ## PATCH: Ignore EOF Errors here end

Full method is below. You may need to adjust it if you are using a different version. This was from 1.9.3p194 source.

## From lib/ruby/1.9.1/net/http.rb module Net class HTTPResponse def read_chunked(dest) len = nil total = 0 while true begin line = @socket.readline rescue EOFError return ## PATCH: Ignore EOF Errors here end

    hexlen = line.slice(/[0-9a-fA-F]+/) or
      raise HTTPBadResponse, "wrong chunk size line: #{line}"
    len = hexlen.hex
    break if len == 0
    begin
      @socket.read len, dest
    ensure
      total += len
      @socket.read 2   # \r\n
    end
  end
  until @socket.readline.empty?
    # none
  end
end

end
end

[kurrik]

This looks more likely. I’ll dig in further today. Thanks for looking into it!

[VintageandGem]

Hopefully I am not getting in the way here, as I am very new to RUBY and this gem, but here is a little more info…
If you are using RUBY 2.0, this lives in net/http/response.rb
The patch worked flawlessly… Since I am not in a production environment, I can live with it.

[mikepstanley]

FWIW - we’ve been experiencing this exact issue since 3/18. (ruby library). We use max_id and since_id in our search routines. we’ve found that if the result count is <= 1 then we get the EOF error. Changing the request header to so Accept-Encoding = “”, worked around this issue for us. I couldn’t get any other of the Net HTTP patches to work.

[kurrik]

So unfortunately I haven’t been able to verify the missing 0. I see it happily transmitted.

Had to write a custom piece of code to dump the exact hex being transmitted over the socket. Here’s my request:

47 45 54 20 2F 31 2E 31 2F 75 GET /1.1/u 73 65 72 73 2F 73 68 6F 77 2E sers/show. 6A 73 6F 6E 3F 75 73 65 72 5F json?user_ 69 64 3D 33 33 39 37 38 20 48 id=33978 H 54 54 50 2F 31 2E 31 0D 0A TTP/1.1.. 48 6F 73 74 3A 20 61 70 69 2E Host: api. 74 77 69 74 74 65 72 2E 63 6F twitter.co 6D 0D 0A m.. 55 73 65 72 2D 41 67 65 6E 74 User-Agent 3A 20 47 6F 20 68 74 74 70 20 : Go http 70 61 63 6B 61 67 65 0D 0A package.. 41 63 63 65 70 74 2D 45 6E 63 Accept-Enc 6F 64 69 6E 67 3A 20 67 7A 69 oding: gzi 70 0D 0A p.. ...

Here’s the response:

... 54 72 61 6E 73 66 65 72 2D 45 Transfer-E 6E 63 6F 64 69 6E 67 3A 20 63 ncoding: c 68 75 6E 6B 65 64 0D 0A hunked.. 43 6F 6E 74 65 6E 74 2D 45 6E Content-En 63 6F 64 69 6E 67 3A 20 67 7A coding: gz 69 70 0D 0A ip.. 0D 0A .. 35 32 0D 0A 52.. 1F 8B 08 00 00 00 00 00 00 00 � AA 56 4A 2D 2A CA 2F 2A 56 B2 �VJ-*�/*V� 8A AE 56 CA 4D 2D 2E 4E 4C 4F ��V�M-.NLO 55 B2 52 0A U�R. CE 2F 2A AA D4 51 28 C9 48 2C �/*��Q(�H, 51 28 00 0A Q(. 29 A4 E4 A7 16 2B E4 E5 97 28 )��+��( A4 56 64 16 97 28 E9 28 25 E7 �Vd�(�(%� A7 00 15 1A 9B D4 C6 D6 02 00 ����� 00 00 FF FF 0D 0A ��.. 61 0D 0A a.. 03 00 91 ED 59 70 44 00 00 00 ��YpD 0D 0A .. 30 0D 0A 0.. 0D 0A ..

You can see that 52 is the first chunk size, which is 82 bytes. This corresponds with

1F 8B 08 00 00 00 00 00 00 00 � AA 56 4A 2D 2A CA 2F 2A 56 B2 �VJ-*�/*V� 8A AE 56 CA 4D 2D 2E 4E 4C 4F ��V�M-.NLO 55 B2 52 0A U�R. CE 2F 2A AA D4 51 28 C9 48 2C �/*��Q(�H, 51 28 00 0A Q(. 29 A4 E4 A7 16 2B E4 E5 97 28 )��+��( A4 56 64 16 97 28 E9 28 25 E7 �Vd�(�(%� A7 00 15 1A 9B D4 C6 D6 02 00 ����� 00 00 FF FF 0D 0A ��..

which is 84 bytes including the final 0D 0A. Then comes a chunk size of A, 10 bytes. This corresponds with:

03 00 91 ED 59 70 44 00 00 00 ��YpD 0D 0A ..

Then finally:

30 0D 0A 0.. 0D 0A ..

The connection is therefore finished.

One thing I did notice was that Twitter isn’t closing the socket - it’s happy to leave the socket open at this point, which is perfectly valid HTTP 1.1 as long as you’re not sending “Connection: close”. It’s up to the client to read the content length (or determine the end of a chunked transfer encoding session) and close the connection if nothing else will be sent.

If you send Connection: close, the socket is closed as soon as the response is finished.

My feeling is that Net::HTTP is not reading the appropriate length and expecting the server to close the connection.

Does that sound reasonable to you?

[waynep]

What about curl returning w/ error code 18?

$ curl -v --compressed --header "Connection: close" http://api.twitter.com/1.1/users/show.json?user_id=33978 * About to connect() to api.twitter.com port 80 (#0) * Trying 199.16.156.104... * connected * Connected to api.twitter.com (199.16.156.104) port 80 (#0) > GET /1.1/users/show.json?user_id=33978 HTTP/1.1 > User-Agent: curl/7.24.0 (x86_64-redhat-linux-gnu) libcurl/7.24.0 NSS/3.12.10.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2 > Host: api.twitter.com > Accept: */* > Accept-Encoding: deflate, gzip > Connection: close > < HTTP/1.1 400 Bad Request < content-type: application/json; charset=utf-8 < date: Mon, 25 Mar 2013 21:06:39 UTC < server: tfe < set-cookie: guest_id=v1%3A136424559987068545; Domain=.twitter.com; Path=/; Expires=Wed, 25-Mar-2015 21:06:39 UTC < Transfer-Encoding: chunked < Content-Encoding: gzip < Connection: close < * transfer closed with outstanding read data remaining * Closing connection #0 curl: (18) transfer closed with outstanding read data remaining {"errors":[{"message":"Bad Authentication data","code":215}]}

[johnbarratt]

Thanks @kurrik for the detailed investigation. I did something very similar, dumping the data coming in on the socket in ruby. I could see it reading each chunk, including the length, without any problem right up until the ‘end’ when the EOFError was raised rather than it getting the 0 chunk. So it isn’t a problem with it reading the wrong length, just that the end comes to soon for it.

It could be that ruby is having some issues in buffering with these responses. But given this is a cross platform (at least OSX & Linux), cross server issue, and in client code that hasn’t been changed in a very long time, I would be surprised if this sort of bug exists in ruby, as it would have surely shown up in other projects accessing other servers. The fact that so many of us were independently hit with the problem all at once is also an indicator that the problem at least originated with a change in the responses coming from Twitter’s servers.

The only other thing I could think of is that the Twitter servers are doing something completely unique, that is still within the bounds of the standard or that is being ‘withstood’ by other clients (eg ignoring premature EOF).

@kurrik Can you check with the ops/server guys to see what changes were made to the system at the time this started? That may well help lead us to a clearer understanding as to what can be done to properly mitigate this issue.

Thanks!

[johnbarratt]

Sorry Wayne, I missed your response yesterday! This seems to show exactly the same problem, but outside of ruby, the connection being closed prematurely. Would be great to verify this further with a fully authenticated request as well, though it seems this helps to confirm the problem on the Twitter servers end, as even with a ‘bad’ request like this, the server should not close the connection early.