fix(log-serializer) log correct request properties on NGINX-produced errors #5073
Conversation
This ensures we can call functions such as `kong.request.*` from the unit tests suite.
…errors This commit fixes the outstanding caveat of using logging plugins to log NGINX-produced errors. The caveat - described in e709c95 - causes some request properties (i.e. method and uri args) to be incorrectly logged. Since e709c95, Kong executes plugins on NGINX-produced errors. However, as described in the mentioned commit's message, a caveat with the approach (note: the sanest one) is that the request method is overridden by the `error_page` directive during the internal redirect (and the uri args do not survive the redirect either). This commit chooses to rely on the PDK to fix this limitation, and manually parses the request headers when necessary (and possible). Fix #4025 Fix #4751
|
On this change, been playing with it in my dev env, on this line: https://github.com/Kong/kong/pull/5073/files#diff-ffbe4a2029a35f89cb0c13a63b8b5d35R15 Was the intent to go into that if check every time during normal execution(not redirect error handler situations)? Because thats currently what happens in my testing of it. Does the http-log plugin need to pass kong since its method input now(even though its global) to avoid needing to go into the if check every time? https://github.com/Kong/kong/blob/master/kong/plugins/http-log/handler.lua#L144 to ? Edit - Ooops, never mind. I was testing on Kong 1.3.0! I need to upgrade to get a few of the other adjustments made in this PR. Ahh 1.3.1 was never released though, just gonna get bundled into 1.4.0 for a release it seems: https://luarocks.org/modules/kong/kong |
|
Jut got around to testing this on Kong 1.4 now still seeing the issue, by taking the basic.lua file and applying it to my splunk logger like so: I am seeing in stdout print statements for any proxy call going in this if check, I kinda expected the if check to only go inside when the redirect occurs on things like L4 failure and the tx context is lost? Hence the assignment of kong to gkong(global kong right)? My first thoughts were maybe this is because a need to pass kong to the serialize like in the unit tests(but maybe thats a special case though because of how the unit tests are setup)? https://github.com/Kong/kong/pull/5073/files#diff-8d9f4f306e97af31cee0e21cdb1a8c39R110 Because plugins right now do not pass kong around for the functions local arg: I am going to try passing (ngx, kong) now into the handler of the logger plugin and see if that helps. If going inside the if check every proxy was intentional let me know and I will quit digging and accept thats the way its supposed to be 😆. But then I wonder why make the if check at all if the behavior is kong will always be nil in this situation(because the serialize method does not get kong passed currently). Edit - Yep passing kong into the serializer call of the log plugin handlers fixed my print statements from always firing off. Time to see what happens on a L4 call to see if that is when it goes inside the if not kong check(which seemed to me to be the intended impl). |
|
Hi @jeremyjpj0916, How are you testing this? What kind of error are you trying to trigger? It's fine if the |
|
@thibaultcha , hope you are well! Functional testing in a dev real environment(not unit tests). By passing (ngx, kong) in the handler of the various logging plugins it no longer goes inside the if not kong check and seems to also achieve saving the various http methods/queries etc. on proxy L4 failure or success: It would work without even needing the gkong assignment or if check at all is my current theory: But that would mean editing all the logging plugins to pass kong to basic_serializer.serialize(). Maybe your reason for gkong assignment was to not have to pass kong and then the kong inside the function is always nil so its always getting set(but then why the if check)? Seems it would be more performant to have the logging plugins pass (ngx, kong) and avoid the gkong assignment and if check in the hotpath all together? Sorry if my rambles make no sense, could be both patterns work but it was just a design choice, testing your OG code of this patch now too to ensure parity in functionality(going inside the if statement every time made me question the point of the if and raised some alarms in my head, hence the post 😄 ). I could PR what I mean in code in 5-10 min if that would clarify things. Edit - PR did work too for me for maintaining http method! So false alarm on any problems, but I am missing the point of the gkong and if check stuff when passing kong in the plugin handlers would have worked too? |
|
The point of the patch is to not have to update every logging plugin's code (including third party ones). Requiring users to do so would be a breaking change. Add to this the unit testing requirements, and thus an optional second argument becomes needed, at least under the current approach. An |
|
AHH avoiding the breaking change was where I wasn't going in my thoughts. Smarter minds prevail 😆 ! Your logic works in all cases, expected behavior no worries there. Sorry for the bother, thought I was onto something and I was not. Enjoy your Tues evening. |
|
No worries; if you see the logging plugins not properly reporting the request properties on such NGINX-produced errors, please let us know! :) |
This PR fixes the outstanding caveat of using logging plugins to log NGINX-produced errors. The caveat - described in e709c95 - causes some request properties (i.e. method and uri args) to be incorrectly logged.
Since e709c95, Kong executes plugins on NGINX-produced errors. However, as described in the mentioned commit's message, a caveat with the approach (note: the sanest one) is that the request method is overridden by the
error_pagedirective during the internal redirect (and the uri args do not survive the redirect either).This approach chooses to rely on the PDK to fix this limitation, and manually parses the request headers when necessary (and possible).
Fix #4025
Fix #4751