search

jnunemaker / httparty

:tada: Makes http fun again!
MIT License
5.79k stars 967 forks source link

httparty trying to json parse string w/ invalid byte sequence #541

Open jaypatrickhoward opened 7 years ago

jaypatrickhoward commented 7 years ago

Previously we were experiencing the issue in #533, so I had us pinned to 0.14.0. Since that was fixed, I removed the pin and tested with 0.15.5. Now I'm getting:

Exception Backtrace: 822: unexpected token at '^_�^H'

/usr/local/rvm/gems/ruby-2.2.4/gems/json-1.8.6/lib/json/common.rb:155:in parse' /usr/local/rvm/gems/ruby-2.2.4/gems/json-1.8.6/lib/json/common.rb:155:inparse' /usr/local/rvm/gems/ruby-2.2.4/gems/httparty-0.15.5/lib/httparty/parser.rb:123:in json' /usr/local/rvm/gems/ruby-2.2.4/gems/httparty-0.15.5/lib/httparty/parser.rb:143:inparse_supported_format' /usr/local/rvm/gems/ruby-2.2.4/gems/httparty-0.15.5/lib/httparty/parser.rb:108:in parse' /usr/local/rvm/gems/ruby-2.2.4/gems/httparty-0.15.5/lib/httparty/parser.rb:67:incall' /usr/local/rvm/gems/ruby-2.2.4/gems/httparty-0.15.5/lib/httparty/request.rb:383:in parse_response' /usr/local/rvm/gems/ruby-2.2.4/gems/httparty-0.15.5/lib/httparty/request.rb:351:inblock in handle_response' /usr/local/rvm/gems/ruby-2.2.4/gems/httparty-0.15.5/lib/httparty/response.rb:25:in call' /usr/local/rvm/gems/ruby-2.2.4/gems/httparty-0.15.5/lib/httparty/response.rb:25:inparsed_response'

When I revert to 0.14.0 this same call works. I'll try to dig up the raw response we get, but it will take some work.

jnunemaker commented 7 years ago

Any more info you can provide would be helpful. Without some idea of the raw response I'm not sure how to fix it.

jaypatrickhoward commented 7 years ago

It may have been fixed with the fixes for #542 and #543. Will test again with latest and report back.

jaypatrickhoward commented 7 years ago

Or, since 0.15.5 is still latest, I'll wait for the next release and test with that.

jnunemaker commented 7 years ago

0.15.6 is out. Please try and let me know.

deep-spaced commented 6 years ago

Unfortunately, I'm seeing this issue on 0.15.6. I'm not able to figure out the exact piece of data causing issues, but here's a partial stack trace in case that might help. 

822: unexpected token at '\u001F\x8B\b'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/json-1.8.6/lib/json/common.rb:155:in  `parse'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/json-1.8.6/lib/json/common.rb:155:in  `parse'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/parser.rb:123:in  `json'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/parser.rb:143:in  `parse_supported_format'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/parser.rb:108:in  `parse'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/parser.rb:67:in  `call'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/request.rb:382:in  `parse_response'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/request.rb:350:in  `block in handle_response'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/response.rb:25:in  `call'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/response.rb:25:in  `parsed_response'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/httparty-0.15.6/lib/httparty/response.rb:88:in  `method_missing'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/hashie-3.5.5/lib/hashie/mash.rb:210:in  `deep_update'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/hashie-3.5.5/lib/hashie/mash.rb:124:in  `initialize'
/Users/andrew/.rbenv/versions/2.1.10/lib/ruby/gems/2.1.0/gems/createsend-4.1.1/lib/createsend/subscriber.rb:63

Here's a VCR recording of this type of interaction: 

- request:
    method: post
    uri: https://xxx:x@api.createsend.com/api/v3.1/subscribers/000/import.json
    body:
      encoding: UTF-8
      string: '{"Subscribers":[{"Name":"Andrew Greene ","EmailAddress":"mk@mailinator.com","CustomFields":[{"Key":"CMPERSONID","Value":"00000"}]},
      {"Name":"David White ","EmailAddress":"whiteblarghhur@dbtestcolorado.edu","CustomFields":[{"Key":"CMPERSONID","Value":"00001"}]},
      {"Name":"Melissa White ","EmailAddress":"someemail@_d_address.com","CustomFields":[{"Key":"CMPERSONID","Value":"00002"}]}],
      "Resubscribe":false,"QueueSubscriptionBasedAutoresponders":false,"RestartSubscriptionBasedAutoresponders":false}'
    headers:
      User-Agent:
      - createsend-ruby-4.0.1-2.1.2-p95-x86_64-darwin13.0
      Content-Type:
      - application/json; charset=utf-8
      Accept-Encoding:
      - gzip, deflate
  response:
    status:
      code: 201
      message: Created
    headers:
      Server:
      - csw
      Cache-Control:
      - private, s-maxage=0
      Content-Type:
      - application/json; charset=utf-8
      P3p:
      - CP="OTI DSP COR CUR IVD CONi OTPi OUR IND UNI STA PRE"
      Date:
      - Wed, 10 Sep 2014 01:46:10 GMT
      Content-Length:
      - '138'
    body:
      encoding: UTF-8
      string: '{"TotalUniqueEmailsSubmitted":3,"TotalExistingSubscribers":0,"TotalNewSubscribers":3,"DuplicateEmailsInSubmission":[],"FailureDetails":[]}'
    http_version:

Thank you for your work on httparty!

jnunemaker commented 6 years ago

I'd like to state my lack of knowledge in this area for the record. 😄 This feels like a different problem than the BOM stuff. I googled "\u001F\x8B\b" and it made me wonder if this is somehow related to gzipping.

If anyone could get me something repeatable, I'd be happy to dig in.

jnunemaker commented 6 years ago

@deep-spaced any chance you tried updating the vcr recording? Just curious if that makes a difference.

jaypatrickhoward commented 6 years ago

I've verified that my issue is still present in 0.15.6. I've also narrowed down what's going on. Here is some debug, with sensitive data removed:

App 21647 stdout: opening connection to mobileapi.ourpartner.com:443...
App 21647 stdout: 
App 21647 stdout: opened
App 21647 stdout: 
App 21647 stdout: starting SSL for mobileapi.ourpartner.com:443...
App 21647 stdout: 
App 21647 stdout: SSL established
App 21647 stdout: 
App 21647 stdout: <- 
App 21647 stdout: "GET /somepath HTTP/1.1\r\nAccept: application/json, application/xml, text/json, text/x-json, text/javascript, text/xml, application/json\r\nAccept-Encoding: gzip, deflate\r\nUser-Agent: MyCompany Test Harness\r\nContent-Type: application/json\r\nConnection: close\r\nHost: mobileapi.ourpartner.com\r\n\r\n"
App 21647 stdout: 
App 21647 stdout: -> "HTTP/1.1 200 OK\r\n"
App 21647 stdout: -> "Access-Control-Allow-Headers: Content-Type, Accept, Authorization\r\n"
App 21647 stdout: -> "Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS, PATCH\r\n"
App 21647 stdout: -> "Access-Control-Allow-Origin: *\r\n"
App 21647 stdout: -> "Cache-Control: private\r\n"
App 21647 stdout: -> "Content-Encoding: gzip\r\n"
App 21647 stdout: -> "Content-Type: application/json\r\n"
App 21647 stdout: -> "Date: Thu, 01 Feb 2018 19:54:01 GMT\r\n"
App 21647 stdout: -> "Set-Cookie: SERVERID=; Expires=Thu, 01-Jan-1970 00:00:01 GMT; path=/; Secure; HttpOnly\r\n"
App 21647 stdout: -> "X-Performance: 70.005 ms\r\n"
App 21647 stdout: -> "X-RequestId: 9c7b0a2d-38fe-40cd-a3af-48bbb1b7a592\r\n"
App 21647 stdout: -> "X-Robots-Tag: none\r\n"
App 21647 stdout: -> "X-Robots-Tag: none\r\n"
App 21647 stdout: -> "Content-Length: 673\r\n"
App 21647 stdout: -> "Connection: Close\r\n"
App 21647 stdout: -> "\r\n"
App 21647 stdout: reading 673 bytes...
{673 bytes of binary gzipped content}

And here's the back trace:

Exception Backtrace:  765: unexpected token at '^_<8b>^H'
/usr/local/rvm/gems/ruby-2.4.3/gems/json-2.1.0/lib/json/common.rb:156:in `parse'
/usr/local/rvm/gems/ruby-2.4.3/gems/json-2.1.0/lib/json/common.rb:156:in `parse'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/parser.rb:123:in `json'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/parser.rb:143:in `parse_supported_format'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/parser.rb:108:in `parse'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/parser.rb:67:in `call'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/request.rb:382:in `parse_response'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/request.rb:350:in `block in handle_response'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/response.rb:25:in `parsed_response'
{our classes}

Our application code looks like:

        headers = {}
        headers['Accept']             = 'application/json, application/xml, text/json, text/x-json, text/javascript, text/xml, application/json'
        headers['Accept-Encoding']    = 'gzip, deflate'
        headers['User-Agent']         = 'MyCompany Test Harness'
        headers['Content-Type']       = 'application/json'
        options = { :headers => headers, :verify => false, :debug_output => $stdout }

        base_uri url

        result = get("/somepath", options)
        if result.response.class == Net::HTTPOK
          userid = result.parsed_response['CustomerId']
        end

Our versions:

Ruby 2.4.3 Rails 4.2.10 httparty 0.15.6 CentOS 6.9

It's possible this is a duplicate of issue #562.

I haven't gone back and tested the other 0.15.x releases, but I can tell you we don't run into this with 0.14.0.

To test whether gzip was the problem, I commented out the line in our code where we set the "Accept-Encoding" header and re-tested. Still broke. New back trace:

Exception Backtrace:  765: unexpected token at ''
/usr/local/rvm/gems/ruby-2.4.3/gems/json-2.1.0/lib/json/common.rb:156:in `parse'
/usr/local/rvm/gems/ruby-2.4.3/gems/json-2.1.0/lib/json/common.rb:156:in `parse'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/parser.rb:123:in `json'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/parser.rb:143:in `parse_supported_format'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/parser.rb:108:in `parse'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/parser.rb:67:in `call'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/request.rb:382:in `parse_response'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/request.rb:350:in `block in handle_response'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/response.rb:25:in `parsed_response'
/usr/local/rvm/gems/ruby-2.4.3/gems/httparty-0.15.6/lib/httparty/response.rb:39:in `inspect'
{our classes}

The debug written to stdout:

App 35820 stdout: opening connection to mobileapi.ourpartner.com:443...
App 35820 stdout: 
App 35820 stdout: opened
App 35820 stdout: 
App 35820 stdout: starting SSL for mobileapi.ourpartner.com:443...
App 35820 stdout: 
App 35820 stdout: SSL established
App 35820 stdout: 
App 35820 stdout: <- 
App 35820 stdout: "GET /somepath HTTP/1.1\r\nAccept: application/json, application/xml, text/json, text/x-json, text/javascript, text/xml, application/json\r\nUser-Agent: MyCompany Test Harness\r\nContent-Type: application/json\r\nConnection: close\r\nHost: mobileapi.ourpartner.com\r\n\r\n"
App 35820 stdout: 
App 35820 stdout: -> "HTTP/1.1 200 OK\r\n"
App 35820 stdout: -> "Access-Control-Allow-Headers: Content-Type, Accept, Authorization\r\n"
App 35820 stdout: -> "Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS, PATCH\r\n"
App 35820 stdout: -> "Access-Control-Allow-Origin: *\r\n"
App 35820 stdout: -> "Cache-Control: private\r\n"
App 35820 stdout: -> "Content-Type: application/json\r\n"
App 35820 stdout: -> "Date: Thu, 01 Feb 2018 20:25:11 GMT\r\n"
App 35820 stdout: -> "Set-Cookie: SERVERID=; Expires=Thu, 01-Jan-1970 00:00:01 GMT; path=/; Secure; HttpOnly\r\n"
App 35820 stdout: -> "X-Performance: 49.9983 ms\r\n"
App 35820 stdout: -> "X-RequestId: 93793311-b1b4-42eb-a310-a2f3fe561c3a\r\n"
App 35820 stdout: -> "X-Robots-Tag: none\r\n"
App 35820 stdout: -> "X-Robots-Tag: none\r\n"
App 35820 stdout: -> "Content-Length: 1938\r\n"
App 35820 stdout: -> "Connection: Close\r\n"
App 35820 stdout: -> "\r\n"
App 35820 stdout: reading 1938 bytes...
App 35820 stdout: -> "some valid json"
App 35820 stdout: read 1938 bytes
App 35820 stdout: Conn close
App 35820 stdout: