methodoverride does not appear anywhere in logs about rails

[josevalim]

When "Started POST" is logged, we still haven't passed through the method override middleware. I think the sanest fix is to include _method in the Parameters. That is handled here:

https://github.com/rails/rails/blob/master/actionpack/lib/action_controller/log_subscriber.rb#L5

What do you think?

[dlee]

Sounds good to me. I'll cook up a patch.

[dhh]

We need to fix the "Started POST" part. Whatever is outputting that needs to look at _method. This used to work, so let's not go backwards.

[dlee]

Alright, so this is a regression.
I think we should indicate somewhere in the logs both the original method and the overridden method.

josevalim's suggestion does this the easy way by showing the original method in the "Started ..." part and the overridden method in the params.

If you think that that's backwards, we can do something like "Started PUT (overrides POST)". What do you think?

[dhh]

When will the "(overrides POST)" be a valuable piece of information? By the time Rails sees the request, Rails won't be able to tell whether it's a real PUT or an artificial PUT.

[dlee]

I'd argue that showing the overrides would be useful in various debugging and analytic situations. Also, it could be useful in distinguishing whether or not the request was made by a browser. Rails certainly has the internal ability to differentiate between real and artificial put requests, and applications built on Rails should have the ability as well if they can access the rack env.

[dhh]

I don't think it's a valuable enough piece of information to log with every request in the log. If you need it, you can always get at it directly via code. Or if you need it temporarily for debugging, you can do logger.info and output it yourself.

But let's definitely fix the core issue as described at the top of this ticket.

[dlee]

Sounds like a plan.

[josevalim]

@dlee so it is just a matter of removing the started part from here:

https://github.com/rails/rails/blob/master/railties/lib/rails/rack/logger.rb#L24

To here:

https://github.com/rails/rails/blob/master/actionpack/lib/action_controller/log_subscriber.rb#L7

The parameters available in the latter is defined here:

https://github.com/rails/rails/blob/master/actionpack/lib/action_controller/metal/instrumentation.rb#L18

[dlee]

I actually went with a different approach since I assumed there was a reason the "Started ..." log was separated into railties/lib/rails/rack/logger.rb in the first place. Expect a pull request soon...

[josevalim]

Ok, but if the another approach is including a new middleware, I would say it is a no-go. :) Our middleware stack is already too long, which leads to a long call stack that Ruby 1.8.x doesn't like at all. Maybe we could log at the router level? Thanks for your time in this.

[josevalim]

Closing this one in favor of #430.