www/apache
1
0
Fork 0
mirror of https://github.com/apache/httpd.git synced 2025-08-08 15:02:10 +03:00
Code Activity

add high trace level log messages for debugging buffering and write completion

Browse Source 
git-svn-id: https://svn.apache.org/repos/asf/httpd/httpd/trunk@1510295 13f79535-47bb-0310-9956-ffa450edef68
This commit is contained in:
Stefan Fritsch
2013-08-04 18:21:24 +00:00
parent c8b4bfe20b
commit b747d7f3c3
2 changed files with 41 additions and 3 deletions
Download Patch File Download Diff File Expand all files Collapse all files

4
modules/ssl/ssl_engine_io.c
View File

@@ -788,6 +788,8 @@ static apr_status_t ssl_filter_write(ap_filter_t *f,
*/ */
outctx->c->cs->sense = CONN_SENSE_WANT_READ; outctx->c->cs->sense = CONN_SENSE_WANT_READ;
outctx->rc = APR_EAGAIN; 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) { else if (ssl_err == SSL_ERROR_SYSCALL) {
ap_log_cerror(APLOG_MARK, APLOG_INFO, outctx->rc, c, APLOGNO(01993) ap_log_cerror(APLOG_MARK, APLOG_INFO, outctx->rc, c, APLOGNO(01993)
@@ -1953,6 +1955,8 @@ void ssl_io_filter_init(conn_rec *c, request_rec *r, SSL *ssl)
/* write is non blocking for the benefit of async mpm */ /* write is non blocking for the benefit of async mpm */
if (c->cs) { if (c->cs) {
BIO_set_nbio(filter_ctx->pbioWrite, 1); 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); ssl_io_input_add_filter(filter_ctx, c, r, ssl);

40
server/core_filters.c
View File

@@ -379,6 +379,7 @@ apr_status_t ap_core_output_filter(ap_filter_t *f, apr_bucket_brigade *new_bb)
apr_size_t bytes_in_brigade, non_file_bytes_in_brigade; apr_size_t bytes_in_brigade, non_file_bytes_in_brigade;
int eor_buckets_in_brigade, morphing_bucket_in_brigade; int eor_buckets_in_brigade, morphing_bucket_in_brigade;
apr_status_t rv; apr_status_t rv;
int loglevel = ap_get_conn_module_loglevel(c, APLOG_MODULE_INDEX);
/* Fail quickly if the connection has already been aborted. */ /* Fail quickly if the connection has already been aborted. */
if (c->aborted) { if (c->aborted) {
@@ -515,7 +516,7 @@ apr_status_t ap_core_output_filter(ap_filter_t *f, apr_bucket_brigade *new_bb)
|| eor_buckets_in_brigade > MAX_REQUESTS_IN_PIPELINE) { || eor_buckets_in_brigade > MAX_REQUESTS_IN_PIPELINE) {
/* this segment of the brigade MUST be sent before returning. */ /* this segment of the brigade MUST be sent before returning. */
if (APLOGctrace6(c)) { if (loglevel >= APLOG_TRACE6) {
char *reason = APR_BUCKET_IS_FLUSH(bucket) ? char *reason = APR_BUCKET_IS_FLUSH(bucket) ?
"FLUSH bucket" : "FLUSH bucket" :
(non_file_bytes_in_brigade >= THRESHOLD_MAX_BUFFER) ? (non_file_bytes_in_brigade >= THRESHOLD_MAX_BUFFER) ?
@@ -523,8 +524,17 @@ apr_status_t ap_core_output_filter(ap_filter_t *f, apr_bucket_brigade *new_bb)
morphing_bucket_in_brigade ? "morphing bucket" : morphing_bucket_in_brigade ? "morphing bucket" :
"MAX_REQUESTS_IN_PIPELINE"; "MAX_REQUESTS_IN_PIPELINE";
ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, c, ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, c,
"core_output_filter: flushing because of %s", "will flush because of %s", reason);
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. * Defer the actual blocking write to avoid doing many writes.
@@ -541,6 +551,10 @@ apr_status_t ap_core_output_filter(ap_filter_t *f, apr_bucket_brigade *new_bb)
if (flush_upto != NULL) { if (flush_upto != NULL) {
ctx->tmp_flush_bb = apr_brigade_split_ex(bb, flush_upto, ctx->tmp_flush_bb = apr_brigade_split_ex(bb, flush_upto,
ctx->tmp_flush_bb); 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, rv = send_brigade_blocking(net->client_socket, bb,
&(ctx->bytes_written), c); &(ctx->bytes_written), c);
if (rv != APR_SUCCESS) { if (rv != APR_SUCCESS) {
@@ -550,9 +564,23 @@ apr_status_t ap_core_output_filter(ap_filter_t *f, apr_bucket_brigade *new_bb)
c->aborted = 1; c->aborted = 1;
return rv; 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); 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) { if (bytes_in_brigade >= THRESHOLD_MIN_WRITE) {
rv = send_brigade_nonblocking(net->client_socket, bb, rv = send_brigade_nonblocking(net->client_socket, bb,
&(ctx->bytes_written), c); &(ctx->bytes_written), c);
@@ -563,6 +591,12 @@ apr_status_t ap_core_output_filter(ap_filter_t *f, apr_bucket_brigade *new_bb)
c->aborted = 1; c->aborted = 1;
return rv; 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); setaside_remaining_output(f, ctx, bb, c);