Ruby SDK reject_params throws JSON parsing error

[EOengineer]

Description

When I use the reject_params configuration option I get the following error:

WARN -- : The following error occured when trying to log to the ReadMe metrics API: 783: unexpected token at ''. Request not logged.

To Reproduce

Clone my test/reproduction app here

install

# install deps
bundle install

# create a .env file at project root with README_API_KEY=your-valid-api-key

# start the server
rails s

Fire off a JSON API GET request to localhost:3000/api/participants - error should be visible in console
Remove reject_params config option, the code works as expected.

Additional details

Config looks like

Rails.application.config.middleware.use Readme::Metrics, {
  api_key: ENV['README_API_KEY'],
  reject_params: ['data'],
} do |env|
  {
    api_key: 'key',
    label: 'name,
    email: '[email protected]',
  }
end

System details:

Ruby v2.7.6
Rails v6.0.6.1

[domharrington]

Hello again! Happy to carry on the discussion here or on intercom. Up to you! Mind making your repo public so i can check it out? 🙏

[EOengineer]

Hi @domharrington thank you again for your time. I thought this might be easier to track. I've updated my test repo to make it public.

[domharrington]

Hey! Sorry for the delay... still trying to get your demo repo up and running. In the mean time, i've pushed my repo up as well: https://github.com/domharrington/ruby-reject-params-metrics-demo

You should be able to add your API key here to get it running: https://github.com/domharrington/ruby-reject-params-metrics-demo/blob/b4420ee12b48cfabb681a4f27ab723c765489c1a/config/environments/development.rb#L5

I am continuing to try and get yours running, but I didnt have rbenv installed and my system ruby is 3.2.1. Now i'm getting a compilation error when installing the pg gem 😭

I will update you with any progress, if you wanna check out my demo as well that may be helpful.

[domharrington]

Hey! I managed to get it running after installing and running postgres, and it seems to be working as intended:

$ curl http://localhost:3000/api/participants -i
HTTP/1.1 200 OK
X-Frame-Options: SAMEORIGIN
X-XSS-Protection: 1; mode=block
X-Content-Type-Options: nosniff
X-Download-Options: noopen
X-Permitted-Cross-Domain-Policies: none
Referrer-Policy: strict-origin-when-cross-origin
Content-Type: application/json; charset=utf-8
ETag: W/"4022a1a46e01af68a53eede300bcffdf"
Cache-Control: max-age=0, private, must-revalidate
X-Request-Id: 09e3b75a-0eef-4a98-ad59-2a11f7913e28
X-Runtime: 0.001879
Transfer-Encoding: chunked

{"data":[{"attributes":{"id":"testeid","email":"[email protected]","firstName":"first","lastName":"last"}}]}%

Then it came through into Metrics like this:

I have made no changes to your repo, apart from replacing api_key: ENV['README_API_KEY'] with my api key inline, and setting check_yarn_integrity: false in webpacker.yaml to stop yarn complaining about missing deps.

Is there anything else that may be different about your system or setup? I'm using the Ruby version that's defined in your Gemfile too. Really appreciate your patience on this and you helping me to debug this! I hope we can get to the bottom of it.

[domharrington]

@EOengineer Hey! Did you manage to take a look at this yet? Very happy to jump on a call to help debug if you're willing. Looking forward to hearing from you!

[EOengineer]

@domharrington Thank you for your patience. My apologies, I must have made a mistake troubleshooting - the reject_params option is actually working for me in the repo I provided. This issue appears to be limited to instances when we invoke the SDK with the reject_params option in our codebase. I'm not exactly sure why that is yet, but Im reasonably confident that this is not an SDK bug. My best guess right now is that perhaps we are going something non standard with our logging and it may not be compatible with the SDK for some reason.

[domharrington]

Thank you! Please do let me know if there's anything we can do here to assist, I'm more than happy to make changes if something we're doing is incompatible and there's something we can reasonably tackle. Let me know!

[EOengineer]

@domharrington I wanted to follow up with some findings after doing some debugging against my application. What I discovered was that, at least in my case, the @request.body in the Readme::Har::RequestSerializer is an empty string, which is causing a JSON parsing error here.

This issue was only present when passing the reject_params option because of the logical branch happening here that sends unfiltered requests through a chain that does not attempt to parse the body. I was able to get the expected reject_params behavior by changing this method to:

def request_body
    if @filter.pass_through?
      pass_through_body
    elsif form_urlencoded?
      form_urlencoded_body
    elsif json? && @request.body.present?
      json_body
    else
      @request.body
    end
end

I'm wondering you have thoughts or concerns around guarding against json requests with empty bodies, or why that condition might cause problems. I assume this may be by design since the code seems to rely on lower level errors bubbling up and being caught top level here but I thought I would at least alert you to the possibility that an issue exists that could potentially be circumvented with a seemingly minimal code change.

[domharrington]

Would you mind sending me a curl command (with -i enabled) that demonstrates the problem when reject_params is enabled? 🙏 Is it just a completely empty body, like:

$ curl -X POST https://httpbin.org/post -i
HTTP/2 200 
date: Wed, 15 Mar 2023 15:42:14 GMT
content-type: application/json
content-length: 318
server: gunicorn/19.9.0
access-control-allow-origin: *
access-control-allow-credentials: true

{
  "args": {}, 
  "data": "", 
  "files": {}, 
  "form": {}, 
  "headers": {
    "Accept": "*/*", 
    "Host": "httpbin.org", 
    "User-Agent": "curl/7.86.0", 
    "X-Amzn-Trace-Id": "Root=1-6411e756-5b861309443a7cdb57baab4c"
  }, 
  "json": null, 
  "origin": "82.5.182.239", 
  "url": "https://httpbin.org/post"
}

Or something else? When I can repro, I can add a test case and hopefully get this fixed up.

[EOengineer]

The body is evaluating as an empty string in code, postman (my testing client right now) is sending requests with no body (the none option selected). The problem is that this issue is not present against the test repository I created earlier in this ticket. These findings were via troubleshooting with a real application in development, so there isn't much I can provide publicly.

I'm not sure how much this helps, but this is what my request object looks like for a request WITHOUT reject_params being passed:

[EOengineer]

@domharrington following up...these requests are against the test app linked earlier in this thread. The JSON parsing error is occurring when provided a request body as an empty string.

This works as expected:

But if I change the body to an empty string like so:

You will see the parsing error thrown:

An interesting note - the parsing error only occurs when the reject_params option is declared in the initializer. If I remove that option, the body with the empty string does not throw an error. So in so many words, I believe the curl command you are looking for (with the reject_params option declared in the initializer) is as follows:

curl -i --location --request GET 'localhost:3000/api/participants' \
--header 'Content-Type: application/json' \
--data ''

[domharrington]

Thanks for following up, and thanks for the curl command! I think this may be us making an (incorrect, but almost always okay) assumption that GET requests dont have bodies.

I will dig into this and get back to you! Should be pretty easy to write a test case for this!

[EOengineer]

@domharrington Did you have any luck reproducing this error?

[domharrington]

I have not tried just yet, but I think it's to do with the GET method sending a body. Can you configure postman to omit the body completely, not just send an empty body?

[EOengineer]

I've configured postman to not send string bodies. At least within our application, I don't believe the string is originating from the requests. I'm noticing our body shows as this Puma::NullIO object which seems to produce the empty string when read. I've confirmed there is no body in the originating request. The docs also seem to indicate that these requests do not have a body, as that is what that object represents

Provides an IO-like object that always appears to contain no data. Used as the value for rack.input when the request has no body.

I've now forked the SDK and am investigating whether this is something I can fix before we move on to explore other options.

[domharrington]

Hey @EOengineer, really appreciate the patience on this. I'm currently up against it on another project, but I should be able to dedicate some time to reproducing and fixing this in the next 3/4 weeks. If you can reproduce and send a PR through, that would be fantastic! I should be able to review anything you put together. Let me know if I can help!