opentelemetry_finch: "key :status not found in: {...}"

[DaemonSnake]

Describe the bug
We recently added sentry to our project and are seeing, from time to time,
these exceptions popping up that seem to be a bug inside opentelemetry_finch.

key :status not found in: {{[
    [""] |
    "{\n  \"error\": {\n    \"code\": 403,\n    \"message\": \"Export only supports Docs Editors files.\",\n    \"errors\": [\n      {\n        \"message\": \"Export only supports Docs Editors files.\",\n        \"domain\": \"global\",\n        \"reason\": \"fileNotExportable\"\n      }\n    ]\n  }\n}\n"
  ], #Function<0.77863640/2 in Collectable.BitString.into/1>},
 %Req.Request{...}, %Req.Response{...}}
If you are using the dot syntax, such as map.field, make sure the left-hand side of the dot is a map

Expected behavior
Shouldn't cause an exception

Additional context

The call stack I found with this issues:

lib/opentelemetry_finch.ex in OpentelemetryFinch.handle_request_stop/4 at line 44
/app/deps/telemetry/src/telemetry.erl in anonymous fn/4 in :telemetry.execute/3 at line 167
lists.erl in :lists.foreach_1/2 at line 2310
/app/deps/telemetry/src/telemetry.erl in :telemetry.span/3 at line 327
lib/req/finch.ex in Req.Finch.finch_stream_into_collectable/5 at line 155
lib/req/request.ex in Req.Request.run_request/1 at line 1118
lib/req/request.ex in Req.Request.run/1 at line 1062
lib/req.ex in Req.request!/2 at line 1119

[tsloughter]

I've never seen such a wild error message. Is it, as it mentions at the end, a common way things get displayed in a mess when a non-map is used with dot syntax?

[tsloughter]

Maybe running an old version or the latest code not being released? The line number of 44 doesn't match up with where the key status is used https://github.com/open-telemetry/opentelemetry-erlang-contrib/blob/main/instrumentation/opentelemetry_finch/lib/opentelemetry_finch.ex#L47

Can you try referencing main in your dep and seeing if it happens again?

[tsloughter]

Weird, a git blame tells me the latest code, with that being on line 47 is in the latest release on hex, 0.2.0.

[DaemonSnake]

Maybe running an old version or the latest code not being released? The line number of 44 doesn't match up with where the key status is used https://github.com/open-telemetry/opentelemetry-erlang-contrib/blob/main/instrumentation/opentelemetry_finch/lib/opentelemetry_finch.ex#L47

Can you try referencing main in your dep and seeing if it happens again?

will try, FYI currently our dependences are as follows:

      {:opentelemetry_finch, "~> 0.2.0"},
      {:finch, "~> 0.13"},
      {:req, "~> 0.5.12"},

[DaemonSnake]

the 44th line mentioned look like so in my deps/ folder

[DaemonSnake]

and the code in req/finch.ex that create that weird tuple looks to be

[DaemonSnake]

found this issues that looks to be related
#398

[tsloughter]

@DaemonSnake thanks! Are you able to test that PR? I'll merge it, but would be good to know before hand if it resolves this issue.

[DaemonSnake]

applied the change locally but not sure how to reproduce, will look

[tsloughter]

Well at least it didn't break anything :), so maybe that is good enough

[tsloughter]

It has a test too, so should be fine.