phoenixframework/phoenix_ecto

Log response for Ecto.CastError & friends

Closed this issue · 3 comments

PragTob commented

Hey there,

I'm not sure where to file this (my internal candidate list phoenix, plug and this) but for our phoenix application when the request fails due to an Ecto.CastError or similiar then nothing is put in the log, as opposed to when things went well. I.e.

2017-02-03 16:08:18.993 request_id=iaii05j9d9oq826v34ob52rbfvf9b4d6 [info] GET /api/resource/946
2017-02-03 16:08:19.007 request_id=iaii05j9d9oq826v34ob52rbfvf9b4d6 [info] Sent 200 in 13ms
2017-02-03 16:08:57.679 request_id=ck7hpthcp6drk347c537c9l48fhdm10r [info] GET /api/resource/946
2017-02-03 16:09:44.994 request_id=4ehom7l2k2g5nmonjioj5fr1v96eeume [info] GET /api/resource/946

The first request is successful, and nicely tells me that it was successful. The next 2 requests I altered the data to be garbage (text instead of a time) and then we don't see what answer was sent back to the client.

I think the definition of the status codes happens here in plug.ex while the error_handler in plug captures it and I guess the skipping might happen for the non 500 status in the translator - but I'm not sure.

Also I believe the logging happens in the Plug.Logger which is then skipped or something.

So I guess questions are:

  • Should this rather be filed over at plug?
  • Can I configure phoenix/plug to log these requests?
  • Is it a genuine oversight and can I supply a patch at the appropriate place to fix this? :)

Thanks for all your work and heart 🎉 ❤️

edit: I had seen elixir-plug/plug#365 but to my understanding that is more focused on that it's hard to actually catch the error from cowboy

josevalim commented

We should log it somewhere. You are correct that we have removed it from the translator, because those are about processes crashes, but we have added it here: elixir-plug/plug@980ee5e#diff-fe7642be3a5c6d1ca8939d45d9c7e82fR130

I think the mistake is that we should have added something similar to above to Phoenix.RenderErrors here: https://github.com/phoenixframework/phoenix/blob/master/lib/phoenix/endpoint/render_errors.ex

Can you please investigate and:

  1. likely add a warning for < 500 to phoenix.render_errors
  2. make sure the warning is not going to appear twice in development nor prod

Thank you!

PragTob commented

I'll see what I can do, thanks for the explanation and the pointers! :)