Hi Dk Jack, On Sun, Jul 15, 2018 at 06:09:24PM -0700, Dk Jack wrote: > Hi Roman, > Sorry, it took a while for me to test the debug build. Since my module was > using timers, the debug logs in ngx_event_timer.{c,h} were causing a crash > (see end of email for details about the crash). Anyways, the debug log > attached at the end of the email. > > Looking at the debug logs, it looks like the ngx_http_finalize_request is > calling ngx_http_special_response_handler for any 'rc >= > NGX_HTTP_SPECIAL_RESPONSE (300)'. Since I was passing a 403 for the rc > value, it was calling the special_response_handler function which in turn > calls the send_header function. Since I had already called the send_header > function before calling the finalize_request, it generates the 'header > already sent' message.
Yes, you should either produce output by yourself by calling ngx_http_send_header/ngx_http_output_filter, or finalize the request with a code >= 300. In the latter case nginx will output a standard response for this code. But you should never do both. > After going over the ngx_http_finalize_request code, I realized, if I > invoked the ngx_http_finalize_request function with 'rc = NGX_HTTP_CLOSE', > the finalize_request function will terminate the request and will not call > the ngx_http_special_response_handler which was causing the problem. I > tried it and it seems to work. Not sure if this the correct approach. Finalizing a request with NGX_HTTP_CLOSE is probably not a very good idea, unless you are absolutely sure you want to close the client connection for some reason. Normally you should finalize it with NGX_OK after you are done with sending response header and body. A standard approach here is finalizing the response with the result of ngx_http_output_filter(). Keep in mind that if you're doing all this in an access phase handler, the response code from your handler may or may not be passed to ngx_http_finalize_request(). See ngx_http_core_access_phase() function for details. > Please let me know. > > Thanks for your help. Greatly appreciate it. > ./D > > --------------------------------------------------------------------------------------------------------------- > event_timer crash when debug enabled: > #define ngx_event_ident(p) ((ngx_connection_t *) (p))->fd > > ngx_log_debug2(NGX_LOG_DEBUG_EVENT, ev->log, 0, > "event timer del: %d: %M", > ngx_event_ident(ev->data), ev->timer.key); > > event_timer.{c,h} files have these sort of debug statements sprinkled all > over these two files. The ngx_event_ident macro seems to treat the data > pointer as a ngx_connection_t pointer and is attempting to dereference it > which causes the crash. In my case, the ev->data was NULL. Yes, event is supposed to always point to a connection object. However, if you have a different object referenced by ev->data, just make sure it has a properly sized value at offsetof(ngx_connection_t, fd). Having NULL in ev->data is not allowed. > ------------------------------------------------------------------------------------------------------------------- > > 2018/07/15 23:28:58 [error] 12381#12381: *2 ngx_http_request_handler: rc = > 403, uri:"/a/b/c", client: 10.3.28.146, server: live.testdomain.com, > request: "GET /a/b/c HTTP/1.1", host: "live.testdomain.com" > 2018/07/15 23:28:58 [error] 12381#12381: *2 ngx_http_request_handler: > finalize_req rc = 403, uri:"/a/b/c", client: 10.3.28.146, server: > live.testdomain.com, request: "GET /a/b/c HTTP/1.1", host: " > live.testdomain.com" > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http finalize request: 403, > "/a/b/c?" a:1, c:1 > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http special response: 403, > "/a/b/c?" > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http set discard body > 2018/07/15 23:28:58 [alert] 12381#12381: *2 header already sent, client: > 10.3.28.146, server: live.testdomain.com, request: "GET /a/b/c HTTP/1.1", > host: "live.testdomain.com" > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http finalize request: -1, > "/a/b/c?" a:1, c:1 > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http terminate request count:1 > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http terminate cleanup count:1 > blk:0 > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http posted request: "/a/b/c?" > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http terminate handler count:1 > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http request count:1 blk:0 > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http close request > 2018/07/15 23:28:58 [debug] 12381#12381: *2 http log handler > > > On Sat, Jul 14, 2018 at 10:26 PM Roman Arutyunyan <a...@nginx.com> wrote: > > > Hi, > > > > On Sat, Jul 14, 2018 at 05:21:02PM -0700, Dk Jack wrote: > > > Hi Roman, > > > Thanks for taking the time to respond to my question. > > > > > > I've tried your suggestion. I've done a finalize_req and tried > > > NGX_DONE/OK/... All give me the same result. I get the same result with > > or > > > without the finalize_req i.e. I still see the 'header already sent' > > > message. I've experimented with the different 'rc' values for the > > > finalize_req i.e. 'rc = NGX_DONE/OK/ERROR' as well. I still see the same > > > result. Please let me know if you have any other suggestions you'd like > > me > > > to try. Thanks. > > > > Can you show your debug log? > > > > https://nginx.org/en/docs/debugging_log.html > > > > > On Sat, Jul 14, 2018 at 2:37 PM Roman Arutyunyan <a...@nginx.com> wrote: > > > > > > > Hi Dk Jack, > > > > > > > > On Fri, Jul 13, 2018 at 01:18:40PM -0700, Dk Jack wrote: > > > > > Sorry, I made a typo in my earlier email. Please read the following > > > > > sentence: > > > > > > > > > > "When I send the response in the *content* phase handler, I am am > > seeing > > > > > 'header already sent' messages in the error log." > > > > > > > > > > as > > > > > > > > > > "When I send the response in the *access* phase handler, I am am > > seeing > > > > > 'header already sent' messages in the error log." > > > > > > > > That's because you do not finalize the request after you send a > > response in > > > > the access handler. A content handler (standard static or another > > one) is > > > > still called at the content phase. It tries to send a second response > > and > > > > obviously gets this error. > > > > > > > > Finalize the request in the access phase after you send the response > > with > > > > this call: > > > > > > > > ngx_http_finalize_request(r, rc) > > > > > > > > where rc is what ngx_http_output_filter() returned. Then return > > NGX_DONE > > > > from the access handler to prevent further request processing. > > > > > > > > If you want to return a standard error page, simply return its HTTP > > status > > > > code > > > > from your access handler instead. > > > > > > > > > On Thu, Jul 12, 2018 at 1:29 PM Dk Jack <dnj0...@gmail.com> wrote: > > > > > > > > > > > Hi, > > > > > > Sorry for sending this again. I haven't been able to resolve my > > issue. > > > > > > I've read several modules for example and gone over several docs > > etc. > > > > but > > > > > > with no success so far. > > > > > > > > > > > > In my module, I need to either drop the request or allow the > > request. > > > > When > > > > > > I drop the request, I need to send custom response and status. The > > > > custom > > > > > > response and status don't come from the config file. When I send > > the > > > > > > response in the content phase handler, I am am seeing 'header > > already > > > > sent' > > > > > > messages in the error log. How can prevent further processing of > > the > > > > > > request after my handler is called for the terminal case? > > > > > > > > > > > > Since my module needs to examine all requests irrespective of the > > uri, > > > > I > > > > > > tried registering a content phase handler and send the custom > > response > > > > in > > > > > > that handler. However, my content phase handler is never invoked. I > > > > suspect > > > > > > some other content handler is overriding my content handler. Is > > there > > > > a > > > > > > way I can prevent that i.e. for a request, can I force only my > > content > > > > > > handler to be called. > > > > > > > > > > > > Please let me know what I am doing wrong? I just need to > > send/perform > > > > > > custom response/actions when a request matches my criteria. I've > > > > include a > > > > > > skeleton of my code. > > > > > > Any inputs are greatly appreciated. Thanks. > > > > > > > > > > > > regards, > > > > > > Dk. > > > > > > > > > > > > http_mod_send_response(ngx_http_request_t *r, ngx_uint_t > > custom_status, > > > > > > char *body, ngx_int_t blen) > > > > > > { > > > > > > ngx_int_t rc; > > > > > > ngx_log_t *log = r->connection->log; > > > > > > ngx_buf_t *buf = ngx_create_temp_buf(r->pool, (blen+16)); // pad. > > > > > > > > > > > > if (NULL == buf) { > > > > > > ngx_log_error(NGX_LOG_ERR, log, 0, "%s: Failed to allocate > > buffer", > > > > > > __FUNCTION__); > > > > > > return NGX_ERROR; > > > > > > } > > > > > > > > > > > > buf->last = ngx_copy(buf->start, (unsigned char*) data, dlen); > > > > > > rc = ngx_http_discard_request_body(r); > > > > > > if (rc != NGX_OK) { > > > > > > ngx_log_error(NGX_LOG_ERR, log, 0, "%s: Discard req. body > > failed. > > > > > > rc=%i", __FUNCTION__, rc); > > > > > > return rc; > > > > > > } > > > > > > > > > > > > r->headers_out.status = custom_status; > > > > > > r->headers_out.content_length_n = buf->last - buf->pos; > > > > > > r->headers_out.content_type.len = sizeof("text/plain") - 1; > > > > > > r->headers_out.content_type.data = (u_char *) "text/plain"; > > > > > > > > > > > > rc = ngx_http_send_header(r); > > > > > > if (rc == NGX_ERROR || rc > NGX_OK || r->header_only) { > > > > > > ngx_log_error(NGX_LOG_ERR, log, 0, "%s: Send header failed. > > rc=%i", > > > > > > __FUNCTION__, rc); > > > > > > return rc; > > > > > > } > > > > > > > > > > > > ngx_chain_t *out_chain = ngx_alloc_chain_link(r->pool); > > > > > > if (NULL == out_chain) { > > > > > > ngx_log_error(NGX_LOG_ERR, log, 0, "%s: Buffer chain alloc > > failed", > > > > > > __FUNCTION__); > > > > > > return NGX_ERROR; > > > > > > } > > > > > > > > > > > > out_chain->buf = buf; > > > > > > out_chain->next = NULL; > > > > > > buf->last_buf = 1; > > > > > > buf->last_in_chain = 1; > > > > > > > > > > > > return ngx_http_output_filter(r, out_chain); > > > > > > } > > > > > > > > > > > > typedef struct { > > > > > > unsigned done:1; > > > > > > } ngx_http_mod_ctx_t; > > > > > > > > > > > > int > > > > > > http_module_process_request(ngx_http_request_t *r, ngx_uint_t > > *status, > > > > > > char *body, ngx_uint_t *blen) > > > > > > { > > > > > > if (/* request matches criteria */) { > > > > > > /* other boiler plate code */ > > > > > > *status = get_custom_status(); > > > > > > *body = get_custom_body(); > > > > > > *blen = ngx_strlen(body); > > > > > > return *status; // this can be different from custom status. > > > > > > } > > > > > > > > > > > > return NGX_DECLINED; > > > > > > } > > > > > > > > > > > > static ngx_int_t > > > > > > ngx_http_request_handler(ngx_http_request_t *r) > > > > > > { > > > > > > ngx_http_mod_ctx_t *ctx = ngx_http_get_module_ctx(r, > > > > nginx_http_module); > > > > > > > > > > > > if (ctx) { > > > > > > ngx_log_error(NGX_LOG_DEBUG, r->connection->log, 0, "duplicate > > > > > > invokation"); > > > > > > return NGX_DECLINED; > > > > > > } else { > > > > > > ctx = ngx_palloc(r->connection->pool, > > sizeof(ngx_http_mod_ctx_t)); > > > > > > if (ctx == NULL) { > > > > > > ngx_log_error(NGX_LOG_ERR, r->connection->log, 0, > > > > > > "Out of memory. Cannot allocate context"); > > > > > > return NGX_ERROR; > > > > > > } > > > > > > > > > > > > ctx->done = 0; > > > > > > ngx_http_set_ctx(r, ctx, nginx_http_module); > > > > > > } > > > > > > > > > > > > ngx_int_t rc = 0; > > > > > > char custom_body[512]; > > > > > > ngx_uint_t blen; > > > > > > ngx_uint_t custom_status; > > > > > > if (!ctx->done) { > > > > > > rc = http_module_process_request(r, &custom_status, > > custom_body, > > > > > > &blen); > > > > > > } > > > > > > > > > > > > ctx->done = 1; > > > > > > if ((rc != 0) && (rc != NGX_DECLINED)) { > > > > > > return http_mod_send_response(r, custom_status, custom_body, > > blen); > > > > > > /* alternate implementation, send response in content handler. > > > > > > ngx_buf_t *buf = ngx_create_temp_buf(r->pool, blen); > > > > > > buf->last = ngx_copy(buf->start, (unsigned char*) data, > > dlen); > > > > > > ctx->custom_body = buf; > > > > > > ctx->rcode = custom_status; > > > > > > */ > > > > > > } > > > > > > > > > > > > return NGX_DECLINED; > > > > > > } > > > > > > > > > > > > static ngx_int_t > > > > > > http_module_content_handler(ngx_http_request_t *r) > > > > > > { > > > > > > ngx_log_error(NGX_LOG_ERR, r->connection->log, 0, "%s: invoked", > > > > > > __FUNCTION__); > > > > > > ngx_http_ss_ctx_t *ctx = ngx_http_get_module_ctx(r, > > > > > > nginx_mitigator_module); > > > > > > > > > > > > if (ctx && ctx->content) { > > > > > > ctx->content = 0; > > > > > > return http_mod_send_response(r, ctx->rcode, ctx->custom_body); > > > > > > } else { > > > > > > ngx_log_error(NGX_LOG_ERR, r->connection->log, 0, > > > > > > "%s: ctx = %p, content = %d", __FUNCTION__, ctx, > > ctx > > > > ? > > > > > > ctx->content : -1); > > > > > > } > > > > > > > > > > > > return NGX_DECLINED; > > > > > > } > > > > > > > > > > > > static ngx_int_t > > > > > > ngx_http_module_init (ngx_conf_t *cf) > > > > > > { > > > > > > ngx_http_core_main_conf_t *cmcf = > > > > ngx_http_conf_get_module_main_conf(cf, > > > > > > ngx_http_core_module); > > > > > > > > > > > > if (!cmcf) { > > > > > > ngx_log_error(NGX_LOG_ERR, cf->log, 0, "Failed to retrieve > > module > > > > main > > > > > > conf"); > > > > > > return NGX_ERROR; > > > > > > } > > > > > > > > > > > > ngx_http_handler_pt *hptr = > > > > > > ngx_array_push(&cmcf->phases[NGX_HTTP_ACCESS_PHASE].handlers); > > > > > > if (hptr == NULL) { > > > > > > ngx_log_error(NGX_LOG_ERR, cf->log, 0, "Could not retrieve > > access > > > > > > phase handler"); > > > > > > return NGX_ERROR; > > > > > > } > > > > > > > > > > > > *hptr = ngx_http_request_handler; > > > > > > ngx_log_error(NGX_LOG_INFO, cf->log, 0, "[init] Installed request > > > > > > handler"); > > > > > > > > > > > > ngx_http_handler_pt *cptr = > > > > > > ngx_array_push(&cmcf->phases[NGX_HTTP_CONTENT_PHASE].handlers); > > > > > > if (cptr == NULL) { > > > > > > ngx_log_error(NGX_LOG_ERR, cf->log, 0, "Could not retrieve > > access > > > > > > phase handler"); > > > > > > return NGX_ERROR; > > > > > > } > > > > > > > > > > > > *cptr = ngx_http_request_handler; > > > > > > ngx_log_error(NGX_LOG_INFO, cf->log, 0, "[init] Installed request > > > > > > handler"); > > > > > > > > > > > > return NGX_OK; > > > > > > } > > > > > > > > > > > > > > > > > > > > > > > > > > > _______________________________________________ > > > > > nginx-devel mailing list > > > > > nginx-devel@nginx.org > > > > > http://mailman.nginx.org/mailman/listinfo/nginx-devel > > > > > > > > > > > > -- > > > > Roman Arutyunyan > > > > _______________________________________________ > > > > nginx-devel mailing list > > > > nginx-devel@nginx.org > > > > http://mailman.nginx.org/mailman/listinfo/nginx-devel > > > > > > > > > _______________________________________________ > > > nginx-devel mailing list > > > nginx-devel@nginx.org > > > http://mailman.nginx.org/mailman/listinfo/nginx-devel > > > > > > -- > > Roman Arutyunyan > > _______________________________________________ > > nginx-devel mailing list > > nginx-devel@nginx.org > > http://mailman.nginx.org/mailman/listinfo/nginx-devel > > > _______________________________________________ > nginx-devel mailing list > nginx-devel@nginx.org > http://mailman.nginx.org/mailman/listinfo/nginx-devel -- Roman Arutyunyan _______________________________________________ nginx-devel mailing list nginx-devel@nginx.org http://mailman.nginx.org/mailman/listinfo/nginx-devel