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.

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.

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.
-------------------------------------------------------------------------------------------------------------------

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 <arut@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 <arut@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 <dnj0496@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