You are viewing a plain text version of this content. The canonical link for it is here.
Posted to cvs@httpd.apache.org by sf...@apache.org on 2013/08/04 20:21:24 UTC
svn commit: r1510295 - in /httpd/httpd/trunk: modules/ssl/ssl_engine_io.c
server/core_filters.c
Author: sf
Date: Sun Aug 4 18:21:24 2013
New Revision: 1510295
URL: http://svn.apache.org/r1510295
Log:
add high trace level log messages for debugging buffering and write completion
Modified:
httpd/httpd/trunk/modules/ssl/ssl_engine_io.c
httpd/httpd/trunk/server/core_filters.c
Modified: httpd/httpd/trunk/modules/ssl/ssl_engine_io.c
URL: http://svn.apache.org/viewvc/httpd/httpd/trunk/modules/ssl/ssl_engine_io.c?rev=1510295&r1=1510294&r2=1510295&view=diff
==============================================================================
--- httpd/httpd/trunk/modules/ssl/ssl_engine_io.c (original)
+++ httpd/httpd/trunk/modules/ssl/ssl_engine_io.c Sun Aug 4 18:21:24 2013
@@ -788,6 +788,8 @@ static apr_status_t ssl_filter_write(ap_
*/
outctx->c->cs->sense = CONN_SENSE_WANT_READ;
outctx->rc = APR_EAGAIN;
+ ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, outctx->c,
+ "Want read during nonblocking write");
}
else if (ssl_err == SSL_ERROR_SYSCALL) {
ap_log_cerror(APLOG_MARK, APLOG_INFO, outctx->rc, c, APLOGNO(01993)
@@ -1953,6 +1955,8 @@ void ssl_io_filter_init(conn_rec *c, req
/* write is non blocking for the benefit of async mpm */
if (c->cs) {
BIO_set_nbio(filter_ctx->pbioWrite, 1);
+ ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, c,
+ "Enabling non-blocking writes");
}
ssl_io_input_add_filter(filter_ctx, c, r, ssl);
Modified: httpd/httpd/trunk/server/core_filters.c
URL: http://svn.apache.org/viewvc/httpd/httpd/trunk/server/core_filters.c?rev=1510295&r1=1510294&r2=1510295&view=diff
==============================================================================
--- httpd/httpd/trunk/server/core_filters.c (original)
+++ httpd/httpd/trunk/server/core_filters.c Sun Aug 4 18:21:24 2013
@@ -379,6 +379,7 @@ apr_status_t ap_core_output_filter(ap_fi
apr_size_t bytes_in_brigade, non_file_bytes_in_brigade;
int eor_buckets_in_brigade, morphing_bucket_in_brigade;
apr_status_t rv;
+ int loglevel = ap_get_conn_module_loglevel(c, APLOG_MODULE_INDEX);
/* Fail quickly if the connection has already been aborted. */
if (c->aborted) {
@@ -515,7 +516,7 @@ apr_status_t ap_core_output_filter(ap_fi
|| eor_buckets_in_brigade > MAX_REQUESTS_IN_PIPELINE) {
/* this segment of the brigade MUST be sent before returning. */
- if (APLOGctrace6(c)) {
+ if (loglevel >= APLOG_TRACE6) {
char *reason = APR_BUCKET_IS_FLUSH(bucket) ?
"FLUSH bucket" :
(non_file_bytes_in_brigade >= THRESHOLD_MAX_BUFFER) ?
@@ -523,8 +524,17 @@ apr_status_t ap_core_output_filter(ap_fi
morphing_bucket_in_brigade ? "morphing bucket" :
"MAX_REQUESTS_IN_PIPELINE";
ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, c,
- "core_output_filter: flushing because of %s",
- reason);
+ "will flush because of %s", reason);
+ ap_log_cerror(APLOG_MARK, APLOG_TRACE8, 0, c,
+ "seen in brigade%s: bytes: %" APR_SIZE_T_FMT
+ ", non-file bytes: %" APR_SIZE_T_FMT ", eor "
+ "buckets: %d, morphing buckets: %d",
+ flush_upto == NULL ? " so far"
+ : " since last flush point",
+ bytes_in_brigade,
+ non_file_bytes_in_brigade,
+ eor_buckets_in_brigade,
+ morphing_bucket_in_brigade);
}
/*
* Defer the actual blocking write to avoid doing many writes.
@@ -541,6 +551,10 @@ apr_status_t ap_core_output_filter(ap_fi
if (flush_upto != NULL) {
ctx->tmp_flush_bb = apr_brigade_split_ex(bb, flush_upto,
ctx->tmp_flush_bb);
+ if (loglevel >= APLOG_TRACE8) {
+ ap_log_cerror(APLOG_MARK, APLOG_TRACE8, 0, c,
+ "flushing now");
+ }
rv = send_brigade_blocking(net->client_socket, bb,
&(ctx->bytes_written), c);
if (rv != APR_SUCCESS) {
@@ -550,9 +564,23 @@ apr_status_t ap_core_output_filter(ap_fi
c->aborted = 1;
return rv;
}
+ if (loglevel >= APLOG_TRACE8) {
+ ap_log_cerror(APLOG_MARK, APLOG_TRACE8, 0, c,
+ "total bytes written: %" APR_SIZE_T_FMT,
+ ctx->bytes_written);
+ }
APR_BRIGADE_CONCAT(bb, ctx->tmp_flush_bb);
}
+ if (loglevel >= APLOG_TRACE8) {
+ ap_log_cerror(APLOG_MARK, APLOG_TRACE8, 0, c,
+ "brigade contains: bytes: %" APR_SIZE_T_FMT
+ ", non-file bytes: %" APR_SIZE_T_FMT
+ ", eor buckets: %d, morphing buckets: %d",
+ bytes_in_brigade, non_file_bytes_in_brigade,
+ eor_buckets_in_brigade, morphing_bucket_in_brigade);
+ }
+
if (bytes_in_brigade >= THRESHOLD_MIN_WRITE) {
rv = send_brigade_nonblocking(net->client_socket, bb,
&(ctx->bytes_written), c);
@@ -563,6 +591,12 @@ apr_status_t ap_core_output_filter(ap_fi
c->aborted = 1;
return rv;
}
+ if (loglevel >= APLOG_TRACE8) {
+ ap_log_cerror(APLOG_MARK, APLOG_TRACE8, 0, c,
+ "tried nonblocking write, total bytes "
+ "written: %" APR_SIZE_T_FMT,
+ ctx->bytes_written);
+ }
}
setaside_remaining_output(f, ctx, bb, c);