Bug 62823

Summary: core_filter call mod_log_config before setting connec_rec to aborted
Product: Apache httpd-2 Reporter: Arnaud Grandville <contact>
Component: CoreAssignee: Apache HTTPD Bugs Mailing List <bugs>
Status: RESOLVED FIXED    
Severity: normal CC: contact
Priority: P2 Keywords: FixedInTrunk, PatchAvailable
Version: 2.5-HEAD   
Target Milestone: ---   
Hardware: PC   
OS: All   
Attachments: On failed, update connection status before logging

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.