Hi Maxim, (added some info about URL) I did enable debug logs before i posted the question.
With json payload, my code is executed right after doing malloc and "http request body content length filter". Without a json payload, it doesn't execute my request validation.That's why i thought it might be due to content length is 0. Here is the debug log when i curl with an empty payload: curl -X POST http://localhost/proxy/profile/alice/comment -d '' -H 'Content-Type: application/json' 2024/01/13 15:01:19 [debug] 2452969#0: *11 rewrite phase: 0 2024/01/13 15:01:19 [debug] 2452969#0: *11 test location: "/" 2024/01/13 15:01:19 [debug] 2452969#0: *11 test location: "proxy/health" 2024/01/13 15:01:19 [debug] 2452969#0: *11 test location: "proxy/unhealthy" 2024/01/13 15:01:19 [debug] 2452969#0: *11 test location: "proxy/profile/alice/comment" 2024/01/13 15:01:19 [debug] 2452969#0: *11 using configuration "/proxy/profile/alice/comment" 2024/01/13 15:01:19 [debug] 2452969#0: *11 http cl:0 max:1048576 2024/01/13 15:01:19 [debug] 2452969#0: *11 rewrite phase: 2 2024/01/13 15:01:19 [debug] 2452969#0: *11 post rewrite phase: 3 2024/01/13 15:01:19 [debug] 2452969#0: *11 generic phase: 4 2024/01/13 15:01:19 [debug] 2452969#0: *11 http request body content length filter 2024/01/13 15:01:19 [debug] 2452969#0: *11 http read client request body 2024/01/13 15:01:19 [debug] 2452969#0: *11 recv: eof:0, avail:0 2024/01/13 15:01:19 [debug] 2452969#0: *11 http client request body recv -2 2024/01/13 15:01:19 [debug] 2452969#0: *11 http client request body rest 1 2024/01/13 15:01:19 [debug] 2452969#0: *11 event timer add: 3: 60000:183385517 2024/01/13 15:01:19 [debug] 2452969#0: *11 http finalize request: -4, "/proxy/profile/alice/comment?" a:1, c:2 2024/01/13 15:01:19 [debug] 2452969#0: *11 http request count:2 blk:0 2024/01/13 15:01:19 [debug] 2452969#0: *11 access phase: 7 2024/01/13 15:01:19 [debug] 2452969#0: *11 access phase: 8 2024/01/13 15:01:19 [debug] 2452969#0: *11 post access phase: 9 2024/01/13 15:01:19 [debug] 2452969#0: *11 generic phase: 10 2024/01/13 15:01:19 [debug] 2452969#0: *11 generic phase: 11 2024/01/13 15:01:19 [debug] 2452969#0: *11 http init upstream, client timer: 1 2024/01/13 15:01:19 [debug] 2452969#0: *11 event timer del: 3: 183385517 2024/01/13 15:01:19 [debug] 2452969#0: *11 epoll add event: fd:3 op:3 ev:80002005 Here is the expected debug logs when i curl with a json payload: `curl -X POST http://localhost/proxy/profile/alice/comment -d '{"comment":"test"}' -H 'Content-Type: application/json'` 2024/01/13 15:05:59 [debug] 2452969#0: *17 rewrite phase: 0 2024/01/13 15:05:59 [debug] 2452969#0: *17 test location: "/" 2024/01/13 15:05:59 [debug] 2452969#0: *17 test location: "proxy/health" 2024/01/13 15:05:59 [debug] 2452969#0: *17 test location: "proxy/unhealthy" 2024/01/13 15:05:59 [debug] 2452969#0: *17 test location: "proxy/profile/alice/comment" 2024/01/13 15:05:59 [debug] 2452969#0: *17 using configuration "/proxy/profile/alice/comment" 2024/01/13 15:05:59 [debug] 2452969#0: *17 http cl:18 max:1048576 2024/01/13 15:05:59 [debug] 2452969#0: *17 rewrite phase: 2 2024/01/13 15:05:59 [debug] 2452969#0: *17 post rewrite phase: 3 2024/01/13 15:05:59 [debug] 2452969#0: *17 generic phase: 4 2024/01/13 15:05:59 [debug] 2452969#0: *17 http client request body preread 18 2024/01/13 15:05:59 [debug] 2452969#0: *17 http request body content length filter 2024/01/13 15:05:59 [debug] 2452969#0: *17 malloc: 000055ADC47961F0:16634 2024/01/13 15:05:59 Hello from Go's ValidateRequestBody! 2024/01/13 15:05:59 RequestValidation is running... 2024/01/13 15:05:59 Request body length: 18 2024/01/13 15:05:59 Request body in Go: {"comment":"test"} 2024/01/13 15:05:59 [debug] 2452969#0: *17 http body new buf t:0 f:0 0000000000000000, pos 000055ADC478F300, size: 0 file: 0, size: 0 2024/01/13 15:05:59 [debug] 2452969#0: *17 malloc: 000055ADC479A300:16634 2024/01/13 15:05:59 Hello from Go's ValidateRequestBody! 2024/01/13 15:05:59 RequestValidation is running... 2024/01/13 15:05:59 Request body length: 18 2024/01/13 15:05:59 Request body in Go: {"comment":"test"} 2024/01/13 15:05:59 [debug] 2452969#0: *17 http body new buf t:0 f:0 0000000000000000, pos 000055ADC478F780, size: 0 file: 0, size: 0 2024/01/13 15:05:59 [alert] 2452969#0: *17 duplicate last buf in save filter, client: 127.0.0.1, server: localhost, request: "POST /proxy/profile/alice/comment HTTP/1.1", host: "localhost" 2024/01/13 15:05:59 [debug] 2452969#0: *17 free: 000055ADC479A300 2024/01/13 15:05:59 [debug] 2452969#0: *17 http finalize request: -4, "/proxy/profile/alice/comment?" a:1, c:2 2024/01/13 15:05:59 [debug] 2452969#0: *17 http request count:2 blk:0 2024/01/13 15:05:59 [debug] 2452969#0: *17 access phase: 7 2024/01/13 15:05:59 [debug] 2452969#0: *17 access phase: 8 2024/01/13 15:05:59 [debug] 2452969#0: *17 post access phase: 9 2024/01/13 15:05:59 [debug] 2452969#0: *17 generic phase: 10 2024/01/13 15:05:59 [debug] 2452969#0: *17 generic phase: 11 2024/01/13 15:05:59 [debug] 2452969#0: *17 http init upstream, client timer: 0 2024/01/13 15:05:59 [debug] 2452969#0: *17 epoll add event: fd:3 op:3 ev:80002005 On Sat, Jan 13, 2024 at 3:11 PM Muhammad Nuzaihan <zai...@unrealasia.net> wrote: > > Hi Maxim, > > I did enable debug logs before i posted the question. > > With json payload, my code is executed right after doing malloc and > "http request body content length filter". > > Without a json payload, it doesn't execute my request > validation.That's why i thought it might be due to content length is > 0. > > Here is the debug log when i curl with an empty payload: > > 2024/01/13 15:01:19 [debug] 2452969#0: *11 rewrite phase: 0 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 test location: "/" > 2024/01/13 15:01:19 [debug] 2452969#0: *11 test location: "proxy/health" > 2024/01/13 15:01:19 [debug] 2452969#0: *11 test location: "proxy/unhealthy" > 2024/01/13 15:01:19 [debug] 2452969#0: *11 test location: > "proxy/profile/alice/comment" > 2024/01/13 15:01:19 [debug] 2452969#0: *11 using configuration > "/proxy/profile/alice/comment" > 2024/01/13 15:01:19 [debug] 2452969#0: *11 http cl:0 max:1048576 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 rewrite phase: 2 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 post rewrite phase: 3 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 generic phase: 4 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 http request body content > length filter > 2024/01/13 15:01:19 [debug] 2452969#0: *11 http read client request body > 2024/01/13 15:01:19 [debug] 2452969#0: *11 recv: eof:0, avail:0 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 http client request body recv -2 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 http client request body rest 1 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 event timer add: 3: 60000:183385517 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 http finalize request: -4, > "/proxy/profile/alice/comment?" a:1, c:2 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 http request count:2 blk:0 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 access phase: 7 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 access phase: 8 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 post access phase: 9 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 generic phase: 10 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 generic phase: 11 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 http init upstream, client timer: 1 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 event timer del: 3: 183385517 > 2024/01/13 15:01:19 [debug] 2452969#0: *11 epoll add event: fd:3 op:3 > ev:80002005 > > Here is the expected debug logs when i curl with a json payload: `curl > -X POST http://localhost/proxy/profile/alice/comment -d > '{"comment":"test"}' -H 'Content-Type: application/json'` > > 2024/01/13 15:05:59 [debug] 2452969#0: *17 rewrite phase: 0 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 test location: "/" > 2024/01/13 15:05:59 [debug] 2452969#0: *17 test location: "proxy/health" > 2024/01/13 15:05:59 [debug] 2452969#0: *17 test location: "proxy/unhealthy" > 2024/01/13 15:05:59 [debug] 2452969#0: *17 test location: > "proxy/profile/alice/comment" > 2024/01/13 15:05:59 [debug] 2452969#0: *17 using configuration > "/proxy/profile/alice/comment" > 2024/01/13 15:05:59 [debug] 2452969#0: *17 http cl:18 max:1048576 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 rewrite phase: 2 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 post rewrite phase: 3 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 generic phase: 4 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 http client request body preread 18 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 http request body content > length filter > 2024/01/13 15:05:59 [debug] 2452969#0: *17 malloc: 000055ADC47961F0:16634 > 2024/01/13 15:05:59 Hello from Go's ValidateRequestBody! > 2024/01/13 15:05:59 RequestValidation is running... > 2024/01/13 15:05:59 Request body length: 18 > 2024/01/13 15:05:59 Request body in Go: {"comment":"test"} > 2024/01/13 15:05:59 [debug] 2452969#0: *17 http body new buf t:0 f:0 > 0000000000000000, pos 000055ADC478F300, size: 0 file: 0, size: 0 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 malloc: 000055ADC479A300:16634 > 2024/01/13 15:05:59 Hello from Go's ValidateRequestBody! > 2024/01/13 15:05:59 RequestValidation is running... > 2024/01/13 15:05:59 Request body length: 18 > 2024/01/13 15:05:59 Request body in Go: {"comment":"test"} > 2024/01/13 15:05:59 [debug] 2452969#0: *17 http body new buf t:0 f:0 > 0000000000000000, pos 000055ADC478F780, size: 0 file: 0, size: 0 > 2024/01/13 15:05:59 [alert] 2452969#0: *17 duplicate last buf in save > filter, client: 127.0.0.1, server: localhost, request: "POST > /proxy/profile/alice/comment HTTP/1.1", host: "localhost" > 2024/01/13 15:05:59 [debug] 2452969#0: *17 free: 000055ADC479A300 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 http finalize request: -4, > "/proxy/profile/alice/comment?" a:1, c:2 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 http request count:2 blk:0 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 access phase: 7 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 access phase: 8 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 post access phase: 9 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 generic phase: 10 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 generic phase: 11 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 http init upstream, client timer: 0 > 2024/01/13 15:05:59 [debug] 2452969#0: *17 epoll add event: fd:3 op:3 > ev:80002005 > > Thank you Maxim for answering my questions! > > On Sat, Jan 13, 2024 at 6:23 AM Maxim Dounin <mdou...@mdounin.ru> wrote: > > > > Hello! > > > > On Fri, Jan 12, 2024 at 10:17:42PM +0800, Muhammad Nuzaihan wrote: > > > > > Hi Maxim, > > > > > > Thank you so much for your explaination. > > > > > > I have another question. If i have an empty string in my payload, it > > > skips the phase handler completely. > > > > > > Example: curl -X POST http://localhost/proxy/profile/alice/comment -d > > > '' -H 'Content-Type: application/json' > > > > > > the flag "-d ''" > > > > > > I do doing it at NGX_HTTP_ACCESS_PHASE in the handler. It seems that > > > if "content_length = 0", it skips the access phase handler as well? > > > > Access phase handlers are called for all requests (unless these > > are rejected at earlier stages). If in doubt, consider configuring > > debug logging and add appropriate debug logging to your module, it > > should make things obvious enough. > > > > -- > > Maxim Dounin > > http://mdounin.ru/ > > _______________________________________________ > > nginx-devel mailing list > > nginx-devel@nginx.org > > https://mailman.nginx.org/mailman/listinfo/nginx-devel _______________________________________________ nginx-devel mailing list nginx-devel@nginx.org https://mailman.nginx.org/mailman/listinfo/nginx-devel
