Hi Maxim, I've verified that even with "curl -X POST http://localhost/proxy/profile/alice/comment" works. as below debug logs.
2024/01/13 15:19:44 [debug] 2452969#0: *20 rewrite phase: 0 2024/01/13 15:19:44 [debug] 2452969#0: *20 test location: "/" 2024/01/13 15:19:44 [debug] 2452969#0: *20 test location: "proxy/health" 2024/01/13 15:19:44 [debug] 2452969#0: *20 test location: "proxy/unhealthy" 2024/01/13 15:19:44 [debug] 2452969#0: *20 test location: "proxy/profile/alice/comment" 2024/01/13 15:19:44 [debug] 2452969#0: *20 using configuration "/proxy/profile/alice/comment" 2024/01/13 15:19:44 [debug] 2452969#0: *20 http cl:-1 max:1048576 2024/01/13 15:19:44 [debug] 2452969#0: *20 rewrite phase: 2 2024/01/13 15:19:44 [debug] 2452969#0: *20 post rewrite phase: 3 2024/01/13 15:19:44 [debug] 2452969#0: *20 generic phase: 4 2024/01/13 15:19:44 [debug] 2452969#0: *20 malloc: 000055ADC47961F0:16634 2024/01/13 15:19:44 Hello from Go's ValidateRequestBody! 2024/01/13 15:19:44 RequestValidation is running... 2024/01/13 15:19:44 Request body length: 0 2024/01/13 15:19:44 Request body in Go: 2024/01/13 15:19:44 Middleware altered response body, original: , new: {"code":400,"title":"something's wrong with your request body","detail":"the request's body did not match your appspec: request body has an error: value is required but missing"} 2024/01/13 15:19:44 [debug] 2452969#0: *20 http output filter "/proxy/profile/alice/comment?" 2024/01/13 15:19:44 [debug] 2452969#0: *20 http copy filter: "/proxy/profile/alice/comment?" 2024/01/13 15:19:44 [debug] 2452969#0: *20 { "version":"1.0.0-alpha", "dateCreated":1705130384398, "executionTime":123456789, "request":{ "ip":"127.0.0.1", "httpProtocol":"HTTP\/1.1", "uri":"http:\/\/localhost\/proxy\/profile\/alice\/comment", "resource":"\/proxy\/profile\/alice\/comment", "method":"POST", "body":"", "headers":{ "Host":[ "localhost" ], "User-Agent":[ "curl\/7.81.0" ], "Accept":[ "*\/*" ] } }, "response":{ "statusCode":400, "body":"{\"code\":400,\"title\":\"something's wrong with your request body\",\"detail\":\"the request's body did not match your appspec: request body has an error: value is required but missing\"}", "headers":{} } } 2024/01/13 15:19:44 [debug] 2452969#0: *20 Buffer is successful 2024/01/13 15:19:44 [debug] 2452969#0: *20 Start of firetail send 2024/01/13 15:19:44 [debug] 2452969#0: *20 Sending next RESPONSE body 2024/01/13 15:19:44 [debug] 2452969#0: *20 Sending next REQUEST body 2024/01/13 15:19:44 [debug] 2452969#0: *20 Buffer is successful 2024/01/13 15:19:44 [debug] 2452969#0: *20 INCOMING Request Body: , json {} 2024/01/13 15:19:44 [debug] 2452969#0: *20 Sending next REQUEST body 2024/01/13 15:19:44 [alert] 2452969#0: *20 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:19:44 [notice] 2452668#0: signal 17 (SIGCHLD) received from 2452969 2024/01/13 15:19:44 [alert] 2452668#0: worker process 2452969 exited on signal 11 (core dumped) 2024/01/13 15:19:44 [debug] 2452668#0: shmtx forced unlock 2024/01/13 15:19:44 [debug] 2452668#0: wake up, sigio 0 2024/01/13 15:19:44 [debug] 2452668#0: reap children 2024/01/13 15:19:44 [debug] 2452668#0: child: 0 2452969 e:0 t:1 d:0 r:1 j:0 2024/01/13 15:19:44 [debug] 2452668#0: channel 3:7 2024/01/13 15:19:44 [notice] 2452668#0: start worker process 2516641 2024/01/13 15:19:44 [debug] 2452668#0: sigsuspend 2024/01/13 15:19:44 [debug] 2516641#0: add cleanup: 000055ADC472CEC8 2024/01/13 15:19:44 [debug] 2516641#0: malloc: 000055ADC46D9520:8 2024/01/13 15:19:44 [debug] 2516641#0: notify eventfd: 9 2024/01/13 15:19:44 [debug] 2516641#0: testing the EPOLLRDHUP flag: success 2024/01/13 15:19:44 [debug] 2516641#0: malloc: 000055ADC47073D0:6144 2024/01/13 15:19:44 [debug] 2516641#0: malloc: 00007F4DF059E010:253952 2024/01/13 15:19:44 [debug] 2516641#0: malloc: 000055ADC4730510:98304 2024/01/13 15:19:44 [debug] 2516641#0: malloc: 000055ADC4748520:98304 2024/01/13 15:19:44 [debug] 2516641#0: epoll add event: fd:6 op:1 ev:00002001 only with an empty payload like this: curl -X POST http://localhost/proxy/profile/alice/comment -d '' -H 'Content-Type: application/json' it doesn't execute. On Sat, Jan 13, 2024 at 3:14 PM Muhammad Nuzaihan <zai...@unrealasia.net> wrote: > > 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