Bug 62823 - core_filter call mod_log_config before setting connec_rec to aborted
Summary: core_filter call mod_log_config before setting connec_rec to aborted
Status: RESOLVED FIXED
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: Core (show other bugs)
Version: 2.5-HEAD
Hardware: PC All
: P2 normal (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords: FixedInTrunk, PatchAvailable
Depends on:
Blocks:
 
Reported: 2018-10-13 12:15 UTC by Arnaud Grandville
Modified: 2019-04-13 18:30 UTC (History)
1 user (show)



Attachments
On failed, update connection status before logging (1.29 KB, text/plain)
2018-10-14 06:20 UTC, Arnaud Grandville
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Arnaud Grandville 2018-10-13 12:15:30 UTC
I'm writing a module to translate http rest/json calls to pkcs11 protocol.
I found a curious behavior, if the client gives up his request, whereas I use the %X flag is specified in my logFormat, the access log didn't report the request as cancelled with a "X".

My module ends with several calls to ap_rwrite and return OK.
But in server\core_filters.c when the brigade send fails the brigade is cleaned and request is logged before aborded status was updated

...
        rv = send_brigade_blocking(net->client_socket, bb,
                                   &(ctx->bytes_written), c);
        if (rv != APR_SUCCESS) {
            /* The client has aborted the connection */
            ap_log_cerror(APLOG_MARK, APLOG_TRACE1, rv, c,
                          "core_output_filter: writing data to the network");
            apr_brigade_cleanup(bb);
            c->aborted = 1;
            return rv;
        }
...

would it not be necessary to update connection state before calling apr_brigade_cleanup ?
Comment 1 Ruediger Pluem 2018-10-13 21:38:04 UTC
(In reply to Arnaud Grandville from comment #0)
> I'm writing a module to translate http rest/json calls to pkcs11 protocol.
> I found a curious behavior, if the client gives up his request, whereas I
> use the %X flag is specified in my logFormat, the access log didn't report
> the request as cancelled with a "X".
> 
> My module ends with several calls to ap_rwrite and return OK.
> But in server\core_filters.c when the brigade send fails the brigade is
> cleaned and request is logged before aborded status was updated
> 
> ...
>         rv = send_brigade_blocking(net->client_socket, bb,
>                                    &(ctx->bytes_written), c);
>         if (rv != APR_SUCCESS) {
>             /* The client has aborted the connection */
>             ap_log_cerror(APLOG_MARK, APLOG_TRACE1, rv, c,
>                           "core_output_filter: writing data to the network");
>             apr_brigade_cleanup(bb);
>             c->aborted = 1;
>             return rv;
>         }
> ...
> 
> would it not be necessary to update connection state before calling
> apr_brigade_cleanup ?

Is the problem fixed if you reverse the order of

apr_brigade_cleanup(bb);

and 

c->aborted = 1;
Comment 2 Arnaud Grandville 2018-10-14 06:20:51 UTC
Created attachment 36197 [details]
On failed, update connection status before logging
Comment 3 Arnaud Grandville 2018-10-14 06:28:44 UTC
(In reply to Ruediger Pluem from comment #1)
> (In reply to Arnaud Grandville from comment #0)
> > I'm writing a module to translate http rest/json calls to pkcs11 protocol.
> > I found a curious behavior, if the client gives up his request, whereas I
> > use the %X flag is specified in my logFormat, the access log didn't report
> > the request as cancelled with a "X".
> > 
> > My module ends with several calls to ap_rwrite and return OK.
> > But in server\core_filters.c when the brigade send fails the brigade is
> > cleaned and request is logged before aborded status was updated
> > 
> > ...
> >         rv = send_brigade_blocking(net->client_socket, bb,
> >                                    &(ctx->bytes_written), c);
> >         if (rv != APR_SUCCESS) {
> >             /* The client has aborted the connection */
> >             ap_log_cerror(APLOG_MARK, APLOG_TRACE1, rv, c,
> >                           "core_output_filter: writing data to the network");
> >             apr_brigade_cleanup(bb);
> >             c->aborted = 1;
> >             return rv;
> >         }
> > ...
> > 
> > would it not be necessary to update connection state before calling
> > apr_brigade_cleanup ?
> 
> Is the problem fixed if you reverse the order of
> 
> apr_brigade_cleanup(bb);
> 
> and 
> 
> c->aborted = 1;

yes, that's right.
Comment 4 Ruediger Pluem 2018-10-15 19:27:42 UTC
Committed trunk patch as r1843939. Your version of the patch fits for 2.4.x (trunk and 2.4.x are slightly different in this code section in the meantime) and can be used while backporting to 2.4.x.