2: header already sent
Dk Jack
dnj0496 at gmail.com
Tue Jul 17 00:11:12 UTC 2018
Thanks Roman,
Passing NGX_OK to finalize_request also worked. I'll use that. Thanks for
all you help.
Dk
PS: Requiring ev->data to be of type ngx_conn_t is a strange one. I thought
it was for user data.
On Mon, Jul 16, 2018 at 4:29 AM Roman Arutyunyan <arut at nginx.com> wrote:
> 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 <arut at 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 at 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 at 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 at nginx.org
> > > > > > http://mailman.nginx.org/mailman/listinfo/nginx-devel
> > > > >
> > > > >
> > > > > --
> > > > > Roman Arutyunyan
> > > > > _______________________________________________
> > > > > nginx-devel mailing list
> > > > > nginx-devel at nginx.org
> > > > > http://mailman.nginx.org/mailman/listinfo/nginx-devel
> > > > >
> > >
> > > > _______________________________________________
> > > > nginx-devel mailing list
> > > > nginx-devel at nginx.org
> > > > http://mailman.nginx.org/mailman/listinfo/nginx-devel
> > >
> > >
> > > --
> > > Roman Arutyunyan
> > > _______________________________________________
> > > nginx-devel mailing list
> > > nginx-devel at nginx.org
> > > http://mailman.nginx.org/mailman/listinfo/nginx-devel
> > >
>
> > _______________________________________________
> > nginx-devel mailing list
> > nginx-devel at nginx.org
> > http://mailman.nginx.org/mailman/listinfo/nginx-devel
>
>
> --
> Roman Arutyunyan
> _______________________________________________
> nginx-devel mailing list
> nginx-devel at nginx.org
> http://mailman.nginx.org/mailman/listinfo/nginx-devel
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx-devel/attachments/20180716/7acb4792/attachment-0001.html>
More information about the nginx-devel
mailing list