<div dir="ltr">Hi Roman,<div>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.</div><div><br></div><div>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.</div><div><br></div><div>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. Please let me know.</div><div><br></div><div>Thanks for your help. Greatly appreciate it.</div><div>./D</div><div><br></div><div>---------------------------------------------------------------------------------------------------------------</div><div>event_timer crash when debug enabled:</div><div><font face="monospace, monospace">#define ngx_event_ident(p) ((</font><span style="font-family:monospace,monospace">ngx_connection_t</span><font face="monospace, monospace"> *) (p))->fd<br></font></div><div><font face="monospace, monospace"><br></font></div><div><div><font face="monospace, monospace"> ngx_log_debug2(NGX_LOG_DEBUG_EVENT, ev->log, 0,</font></div><div><font face="monospace, monospace"> "event timer del: %d: %M",</font></div><div><font face="monospace, monospace"> ngx_event_ident(ev->data), ev->timer.key);</font></div></div><div><br></div><div>event_timer.{c,h} files have these sort of debug statements sprinkled all over these two files. The <span style="font-family:monospace,monospace">ngx_event_ident </span>macro seems to treat the data pointer as a <span style="font-family:monospace,monospace">ngx_connection_t </span>pointer and is attempting to dereference it which causes the crash. In my case, the ev->data was NULL.</div><div>-------------------------------------------------------------------------------------------------------------------</div><div><br></div><div><div><font face="monospace, monospace">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: <a href="http://live.testdomain.com">live.testdomain.com</a>, request: "GET /a/b/c HTTP/1.1", host: "<a href="http://live.testdomain.com">live.testdomain.com</a>"</font></div><div><font face="monospace, monospace">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: <a href="http://live.testdomain.com">live.testdomain.com</a>, request: "GET /a/b/c HTTP/1.1", host: "<a href="http://live.testdomain.com">live.testdomain.com</a>"</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http finalize request: 403, "/a/b/c?" a:1, c:1</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http special response: 403, "/a/b/c?"</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http set discard body</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [alert] 12381#12381: *2 header already sent, client: 10.3.28.146, server: <a href="http://live.testdomain.com">live.testdomain.com</a>, request: "GET /a/b/c HTTP/1.1", host: "<a href="http://live.testdomain.com">live.testdomain.com</a>"</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http finalize request: -1, "/a/b/c?" a:1, c:1</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http terminate request count:1</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http terminate cleanup count:1 blk:0</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http posted request: "/a/b/c?"</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http terminate handler count:1</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http request count:1 blk:0</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http close request</font></div><div><font face="monospace, monospace">2018/07/15 23:28:58 [debug] 12381#12381: *2 http log handler</font></div></div><div><br></div></div><br><div class="gmail_quote"><div dir="ltr">On Sat, Jul 14, 2018 at 10:26 PM Roman Arutyunyan <<a href="mailto:arut@nginx.com">arut@nginx.com</a>> wrote:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hi,<br>
<br>
On Sat, Jul 14, 2018 at 05:21:02PM -0700, Dk Jack wrote:<br>
> Hi Roman,<br>
> Thanks for taking the time to respond to my question.<br>
> <br>
> I've tried your suggestion. I've done a finalize_req and tried<br>
> NGX_DONE/OK/... All give me the same result. I get the same result with or<br>
> without the finalize_req i.e. I still see the 'header already sent'<br>
> message. I've experimented with the different 'rc' values for the<br>
> finalize_req i.e. 'rc = NGX_DONE/OK/ERROR' as well. I still see the same<br>
> result. Please let me know if you have any other suggestions you'd like me<br>
> to try. Thanks.<br>
<br>
Can you show your debug log?<br>
<br>
<a href="https://nginx.org/en/docs/debugging_log.html" rel="noreferrer" target="_blank">https://nginx.org/en/docs/debugging_log.html</a><br>
<br>
> On Sat, Jul 14, 2018 at 2:37 PM Roman Arutyunyan <<a href="mailto:arut@nginx.com" target="_blank">arut@nginx.com</a>> wrote:<br>
> <br>
> > Hi Dk Jack,<br>
> ><br>
> > On Fri, Jul 13, 2018 at 01:18:40PM -0700, Dk Jack wrote:<br>
> > > Sorry, I made a typo in my earlier email. Please read the following<br>
> > > sentence:<br>
> > ><br>
> > > "When I send the response in the *content* phase handler, I am am seeing<br>
> > > 'header already sent' messages in the error log."<br>
> > ><br>
> > > as<br>
> > ><br>
> > > "When I send the response in the *access* phase handler, I am am seeing<br>
> > > 'header already sent' messages in the error log."<br>
> ><br>
> > That's because you do not finalize the request after you send a response in<br>
> > the access handler. A content handler (standard static or another one) is<br>
> > still called at the content phase. It tries to send a second response and<br>
> > obviously gets this error.<br>
> ><br>
> > Finalize the request in the access phase after you send the response with<br>
> > this call:<br>
> ><br>
> > ngx_http_finalize_request(r, rc)<br>
> ><br>
> > where rc is what ngx_http_output_filter() returned. Then return NGX_DONE<br>
> > from the access handler to prevent further request processing.<br>
> ><br>
> > If you want to return a standard error page, simply return its HTTP status<br>
> > code<br>
> > from your access handler instead.<br>
> ><br>
> > > On Thu, Jul 12, 2018 at 1:29 PM Dk Jack <<a href="mailto:dnj0496@gmail.com" target="_blank">dnj0496@gmail.com</a>> wrote:<br>
> > ><br>
> > > > Hi,<br>
> > > > Sorry for sending this again. I haven't been able to resolve my issue.<br>
> > > > I've read several modules for example and gone over several docs etc.<br>
> > but<br>
> > > > with no success so far.<br>
> > > ><br>
> > > > In my module, I need to either drop the request or allow the request.<br>
> > When<br>
> > > > I drop the request, I need to send custom response and status. The<br>
> > custom<br>
> > > > response and status don't come from the config file. When I send the<br>
> > > > response in the content phase handler, I am am seeing 'header already<br>
> > sent'<br>
> > > > messages in the error log. How can prevent further processing of the<br>
> > > > request after my handler is called for the terminal case?<br>
> > > ><br>
> > > > Since my module needs to examine all requests irrespective of the uri,<br>
> > I<br>
> > > > tried registering a content phase handler and send the custom response<br>
> > in<br>
> > > > that handler. However, my content phase handler is never invoked. I<br>
> > suspect<br>
> > > > some other content handler is overriding my content handler. Is there<br>
> > a<br>
> > > > way I can prevent that i.e. for a request, can I force only my content<br>
> > > > handler to be called.<br>
> > > ><br>
> > > > Please let me know what I am doing wrong? I just need to send/perform<br>
> > > > custom response/actions when a request matches my criteria. I've<br>
> > include a<br>
> > > > skeleton of my code.<br>
> > > > Any inputs are greatly appreciated. Thanks.<br>
> > > ><br>
> > > > regards,<br>
> > > > Dk.<br>
> > > ><br>
> > > > http_mod_send_response(ngx_http_request_t *r, ngx_uint_t custom_status,<br>
> > > > char *body, ngx_int_t blen)<br>
> > > > {<br>
> > > > ngx_int_t rc;<br>
> > > > ngx_log_t *log = r->connection->log;<br>
> > > > ngx_buf_t *buf = ngx_create_temp_buf(r->pool, (blen+16)); // pad.<br>
> > > ><br>
> > > > if (NULL == buf) {<br>
> > > > ngx_log_error(NGX_LOG_ERR, log, 0, "%s: Failed to allocate buffer",<br>
> > > > __FUNCTION__);<br>
> > > > return NGX_ERROR;<br>
> > > > }<br>
> > > ><br>
> > > > buf->last = ngx_copy(buf->start, (unsigned char*) data, dlen);<br>
> > > > rc = ngx_http_discard_request_body(r);<br>
> > > > if (rc != NGX_OK) {<br>
> > > > ngx_log_error(NGX_LOG_ERR, log, 0, "%s: Discard req. body failed.<br>
> > > > rc=%i", __FUNCTION__, rc);<br>
> > > > return rc;<br>
> > > > }<br>
> > > ><br>
> > > > r->headers_out.status = custom_status;<br>
> > > > r->headers_out.content_length_n = buf->last - buf->pos;<br>
> > > > r->headers_out.content_type.len = sizeof("text/plain") - 1;<br>
> > > > r->headers_out.content_type.data = (u_char *) "text/plain";<br>
> > > ><br>
> > > > rc = ngx_http_send_header(r);<br>
> > > > if (rc == NGX_ERROR || rc > NGX_OK || r->header_only) {<br>
> > > > ngx_log_error(NGX_LOG_ERR, log, 0, "%s: Send header failed. rc=%i",<br>
> > > > __FUNCTION__, rc);<br>
> > > > return rc;<br>
> > > > }<br>
> > > ><br>
> > > > ngx_chain_t *out_chain = ngx_alloc_chain_link(r->pool);<br>
> > > > if (NULL == out_chain) {<br>
> > > > ngx_log_error(NGX_LOG_ERR, log, 0, "%s: Buffer chain alloc failed",<br>
> > > > __FUNCTION__);<br>
> > > > return NGX_ERROR;<br>
> > > > }<br>
> > > ><br>
> > > > out_chain->buf = buf;<br>
> > > > out_chain->next = NULL;<br>
> > > > buf->last_buf = 1;<br>
> > > > buf->last_in_chain = 1;<br>
> > > ><br>
> > > > return ngx_http_output_filter(r, out_chain);<br>
> > > > }<br>
> > > ><br>
> > > > typedef struct {<br>
> > > > unsigned done:1;<br>
> > > > } ngx_http_mod_ctx_t;<br>
> > > ><br>
> > > > int<br>
> > > > http_module_process_request(ngx_http_request_t *r, ngx_uint_t *status,<br>
> > > > char *body, ngx_uint_t *blen)<br>
> > > > {<br>
> > > > if (/* request matches criteria */) {<br>
> > > > /* other boiler plate code */<br>
> > > > *status = get_custom_status();<br>
> > > > *body = get_custom_body();<br>
> > > > *blen = ngx_strlen(body);<br>
> > > > return *status; // this can be different from custom status.<br>
> > > > }<br>
> > > ><br>
> > > > return NGX_DECLINED;<br>
> > > > }<br>
> > > ><br>
> > > > static ngx_int_t<br>
> > > > ngx_http_request_handler(ngx_http_request_t *r)<br>
> > > > {<br>
> > > > ngx_http_mod_ctx_t *ctx = ngx_http_get_module_ctx(r,<br>
> > nginx_http_module);<br>
> > > ><br>
> > > > if (ctx) {<br>
> > > > ngx_log_error(NGX_LOG_DEBUG, r->connection->log, 0, "duplicate<br>
> > > > invokation");<br>
> > > > return NGX_DECLINED;<br>
> > > > } else {<br>
> > > > ctx = ngx_palloc(r->connection->pool, sizeof(ngx_http_mod_ctx_t));<br>
> > > > if (ctx == NULL) {<br>
> > > > ngx_log_error(NGX_LOG_ERR, r->connection->log, 0,<br>
> > > > "Out of memory. Cannot allocate context");<br>
> > > > return NGX_ERROR;<br>
> > > > }<br>
> > > ><br>
> > > > ctx->done = 0;<br>
> > > > ngx_http_set_ctx(r, ctx, nginx_http_module);<br>
> > > > }<br>
> > > ><br>
> > > > ngx_int_t rc = 0;<br>
> > > > char custom_body[512];<br>
> > > > ngx_uint_t blen;<br>
> > > > ngx_uint_t custom_status;<br>
> > > > if (!ctx->done) {<br>
> > > > rc = http_module_process_request(r, &custom_status, custom_body,<br>
> > > > &blen);<br>
> > > > }<br>
> > > ><br>
> > > > ctx->done = 1;<br>
> > > > if ((rc != 0) && (rc != NGX_DECLINED)) {<br>
> > > > return http_mod_send_response(r, custom_status, custom_body, blen);<br>
> > > > /* alternate implementation, send response in content handler.<br>
> > > > ngx_buf_t *buf = ngx_create_temp_buf(r->pool, blen);<br>
> > > > buf->last = ngx_copy(buf->start, (unsigned char*) data, dlen);<br>
> > > > ctx->custom_body = buf;<br>
> > > > ctx->rcode = custom_status;<br>
> > > > */<br>
> > > > }<br>
> > > ><br>
> > > > return NGX_DECLINED;<br>
> > > > }<br>
> > > ><br>
> > > > static ngx_int_t<br>
> > > > http_module_content_handler(ngx_http_request_t *r)<br>
> > > > {<br>
> > > > ngx_log_error(NGX_LOG_ERR, r->connection->log, 0, "%s: invoked",<br>
> > > > __FUNCTION__);<br>
> > > > ngx_http_ss_ctx_t *ctx = ngx_http_get_module_ctx(r,<br>
> > > > nginx_mitigator_module);<br>
> > > ><br>
> > > > if (ctx && ctx->content) {<br>
> > > > ctx->content = 0;<br>
> > > > return http_mod_send_response(r, ctx->rcode, ctx->custom_body);<br>
> > > > } else {<br>
> > > > ngx_log_error(NGX_LOG_ERR, r->connection->log, 0,<br>
> > > > "%s: ctx = %p, content = %d", __FUNCTION__, ctx, ctx<br>
> > ?<br>
> > > > ctx->content : -1);<br>
> > > > }<br>
> > > ><br>
> > > > return NGX_DECLINED;<br>
> > > > }<br>
> > > ><br>
> > > > static ngx_int_t<br>
> > > > ngx_http_module_init (ngx_conf_t *cf)<br>
> > > > {<br>
> > > > ngx_http_core_main_conf_t *cmcf =<br>
> > ngx_http_conf_get_module_main_conf(cf,<br>
> > > > ngx_http_core_module);<br>
> > > ><br>
> > > > if (!cmcf) {<br>
> > > > ngx_log_error(NGX_LOG_ERR, cf->log, 0, "Failed to retrieve module<br>
> > main<br>
> > > > conf");<br>
> > > > return NGX_ERROR;<br>
> > > > }<br>
> > > ><br>
> > > > ngx_http_handler_pt *hptr =<br>
> > > > ngx_array_push(&cmcf->phases[NGX_HTTP_ACCESS_PHASE].handlers);<br>
> > > > if (hptr == NULL) {<br>
> > > > ngx_log_error(NGX_LOG_ERR, cf->log, 0, "Could not retrieve access<br>
> > > > phase handler");<br>
> > > > return NGX_ERROR;<br>
> > > > }<br>
> > > ><br>
> > > > *hptr = ngx_http_request_handler;<br>
> > > > ngx_log_error(NGX_LOG_INFO, cf->log, 0, "[init] Installed request<br>
> > > > handler");<br>
> > > ><br>
> > > > ngx_http_handler_pt *cptr =<br>
> > > > ngx_array_push(&cmcf->phases[NGX_HTTP_CONTENT_PHASE].handlers);<br>
> > > > if (cptr == NULL) {<br>
> > > > ngx_log_error(NGX_LOG_ERR, cf->log, 0, "Could not retrieve access<br>
> > > > phase handler");<br>
> > > > return NGX_ERROR;<br>
> > > > }<br>
> > > ><br>
> > > > *cptr = ngx_http_request_handler;<br>
> > > > ngx_log_error(NGX_LOG_INFO, cf->log, 0, "[init] Installed request<br>
> > > > handler");<br>
> > > ><br>
> > > > return NGX_OK;<br>
> > > > }<br>
> > > ><br>
> > > ><br>
> > > ><br>
> ><br>
> > > _______________________________________________<br>
> > > nginx-devel mailing list<br>
> > > <a href="mailto:nginx-devel@nginx.org" target="_blank">nginx-devel@nginx.org</a><br>
> > > <a href="http://mailman.nginx.org/mailman/listinfo/nginx-devel" rel="noreferrer" target="_blank">http://mailman.nginx.org/mailman/listinfo/nginx-devel</a><br>
> ><br>
> ><br>
> > --<br>
> > Roman Arutyunyan<br>
> > _______________________________________________<br>
> > nginx-devel mailing list<br>
> > <a href="mailto:nginx-devel@nginx.org" target="_blank">nginx-devel@nginx.org</a><br>
> > <a href="http://mailman.nginx.org/mailman/listinfo/nginx-devel" rel="noreferrer" target="_blank">http://mailman.nginx.org/mailman/listinfo/nginx-devel</a><br>
> ><br>
<br>
> _______________________________________________<br>
> nginx-devel mailing list<br>
> <a href="mailto:nginx-devel@nginx.org" target="_blank">nginx-devel@nginx.org</a><br>
> <a href="http://mailman.nginx.org/mailman/listinfo/nginx-devel" rel="noreferrer" target="_blank">http://mailman.nginx.org/mailman/listinfo/nginx-devel</a><br>
<br>
<br>
-- <br>
Roman Arutyunyan<br>
_______________________________________________<br>
nginx-devel mailing list<br>
<a href="mailto:nginx-devel@nginx.org" target="_blank">nginx-devel@nginx.org</a><br>
<a href="http://mailman.nginx.org/mailman/listinfo/nginx-devel" rel="noreferrer" target="_blank">http://mailman.nginx.org/mailman/listinfo/nginx-devel</a><br>
</blockquote></div>