Skip to content

Commit

Permalink
v1.0.15, fixes for early connection closes
Browse files Browse the repository at this point in the history
  • Loading branch information
Stefan Eissing committed Dec 30, 2015
1 parent a121324 commit 526a39f
Show file tree
Hide file tree
Showing 12 changed files with 148 additions and 83 deletions.
8 changes: 8 additions & 0 deletions ChangeLog
View file
Original file line number Diff line number Diff line change
@@ -1,3 +1,11 @@
v1.0.15
--------------------------------------------------------------------------------
* fixed busy loops on random connection errors
* fixed connection state for event MPM that shutdown child with 'G' status
* changed default for H2KeepAliveTimeout. For async MPMs (event), will leave
keepalive handling to the MPM. For sync (worker, prefork), will default to
whatever is set for H2Timeout.

v1.0.14
--------------------------------------------------------------------------------
* fixed segfault on connection shutdown
Expand Down
2 changes: 1 addition & 1 deletion configure.ac
View file
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@
#

AC_PREREQ([2.69])
AC_INIT([mod_http2], [1.0.14], [[email protected]])
AC_INIT([mod_http2], [1.0.15], [[email protected]])

LT_PREREQ([2.2.6])
LT_INIT()
Expand Down
2 changes: 1 addition & 1 deletion mod_http2/h2_config.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,7 @@ static h2_config defconf = {
1, /* HTTP/2 server push enabled */
NULL, /* map of content-type to priorities */
5, /* normal connection timeout */
5, /* keepalive timeout */
-1, /* keepalive timeout */
0, /* stream timeout */
};

Expand Down
38 changes: 31 additions & 7 deletions mod_http2/h2_conn.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -158,47 +158,71 @@ apr_status_t h2_conn_setup(h2_ctx *ctx, conn_rec *c, request_rec *r)
static apr_status_t h2_conn_process(h2_ctx *ctx)
{
h2_session *session;
apr_status_t status;

session = h2_ctx_session_get(ctx);
if (session->c->cs) {
session->c->cs->sense = CONN_SENSE_DEFAULT;
}

h2_session_process(session, async_mpm);
status = h2_session_process(session, async_mpm);

session->c->keepalive = AP_CONN_KEEPALIVE;
if (session->c->cs) {
session->c->cs->state = CONN_STATE_WRITE_COMPLETION;
}

if (APR_STATUS_IS_EOF(status)
|| APR_STATUS_IS_ECONNRESET(status)
|| APR_STATUS_IS_ECONNABORTED(status)) {
/* fatal, probably client just closed connection. emergency shutdown */
/* Make sure this connection gets closed properly. */
ap_log_cerror( APLOG_MARK, APLOG_DEBUG, 0, session->c,
"h2_session(%ld): aborted", session->id);
session->c->keepalive = AP_CONN_CLOSE;

h2_ctx_clear(session->c);
h2_session_abort(session, status);
h2_session_eoc_callback(session);
/* hereafter session might be gone */
return APR_ECONNABORTED;
}

if (session->state == H2_SESSION_ST_CLOSING) {
ap_log_cerror( APLOG_MARK, APLOG_DEBUG, 0, session->c,
"h2_session(%ld): done", session->id);
"h2_session(%ld): closing", session->id);
/* Make sure this connection gets closed properly. */
ap_update_child_status_from_conn(session->c->sbh, SERVER_CLOSING, session->c);
session->c->keepalive = AP_CONN_CLOSE;

h2_ctx_clear(session->c);
h2_session_close(session);
/* hereafter session may be gone */
}
else if (session->state == H2_SESSION_ST_ABORTED) {
ap_log_cerror( APLOG_MARK, APLOG_DEBUG, 0, session->c,
"h2_session(%ld): already aborted", session->id);
return APR_ECONNABORTED;
}

return DONE;
return APR_SUCCESS;
}

apr_status_t h2_conn_run(struct h2_ctx *ctx, conn_rec *c)
{
int mpm_state = 0;
apr_status_t status;
do {
h2_conn_process(ctx);
status = h2_conn_process(ctx);

if (ap_mpm_query(AP_MPMQ_MPM_STATE, &mpm_state)) {
break;
}
} while (!async_mpm
} while (!async_mpm
&& status == APR_SUCCESS
&& c->keepalive == AP_CONN_KEEPALIVE
&& mpm_state != AP_MPMQ_STOPPING);

return DONE;
return status;
}


Expand Down
51 changes: 36 additions & 15 deletions mod_http2/h2_conn_io.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -93,29 +93,35 @@ int h2_conn_io_is_buffered(h2_conn_io *io)
return io->bufsize > 0;
}

typedef struct {
conn_rec *c;
h2_conn_io *io;
} pass_out_ctx;

static apr_status_t pass_out(apr_bucket_brigade *bb, void *ctx)
{
h2_conn_io *io = (h2_conn_io*)ctx;
pass_out_ctx *pctx = ctx;
conn_rec *c = pctx->c;
apr_status_t status;
apr_off_t bblen;

if (APR_BRIGADE_EMPTY(bb)) {
return APR_SUCCESS;
}

ap_update_child_status(io->connection->sbh, SERVER_BUSY_WRITE, NULL);
ap_update_child_status(c->sbh, SERVER_BUSY_WRITE, NULL);
status = apr_brigade_length(bb, 0, &bblen);
if (status == APR_SUCCESS) {
ap_log_cerror(APLOG_MARK, APLOG_TRACE4, 0, io->connection,
ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, c,
"h2_conn_io(%ld): pass_out brigade %ld bytes",
io->connection->id, (long)bblen);
status = ap_pass_brigade(io->connection->output_filters, bb);
if (status == APR_SUCCESS) {
io->bytes_written += (apr_size_t)bblen;
io->last_write = apr_time_now();
c->id, (long)bblen);
status = ap_pass_brigade(c->output_filters, bb);
if (status == APR_SUCCESS && pctx->io) {
pctx->io->bytes_written += (apr_size_t)bblen;
pctx->io->last_write = apr_time_now();
}
apr_brigade_cleanup(bb);
}
apr_brigade_cleanup(bb);
return status;
}

Expand Down Expand Up @@ -169,7 +175,10 @@ apr_status_t h2_conn_io_write(h2_conn_io *io,
const char *buf, size_t length)
{
apr_status_t status = APR_SUCCESS;
pass_out_ctx ctx;

ctx.c = io->connection;
ctx.io = io;
io->unflushed = 1;
if (io->bufsize > 0) {
ap_log_cerror(APLOG_MARK, APLOG_TRACE4, 0, io->connection,
Expand All @@ -183,8 +192,9 @@ apr_status_t h2_conn_io_write(h2_conn_io *io,
while (length > 0 && (status == APR_SUCCESS)) {
apr_size_t avail = io->bufsize - io->buflen;
if (avail <= 0) {

bucketeer_buffer(io);
status = pass_out(io->output, io);
status = pass_out(io->output, &ctx);
io->buflen = 0;
}
else if (length > avail) {
Expand All @@ -205,7 +215,7 @@ apr_status_t h2_conn_io_write(h2_conn_io *io,
else {
ap_log_cerror(APLOG_MARK, APLOG_TRACE4, status, io->connection,
"h2_conn_io: writing %ld bytes to brigade", (long)length);
status = apr_brigade_write(io->output, pass_out, io, buf, length);
status = apr_brigade_write(io->output, pass_out, &ctx, buf, length);
}

return status;
Expand Down Expand Up @@ -242,9 +252,11 @@ apr_status_t h2_conn_io_consider_flush(h2_conn_io *io)
return status;
}

static apr_status_t h2_conn_io_flush_int(h2_conn_io *io, int force)
static apr_status_t h2_conn_io_flush_int(h2_conn_io *io, int force, int eoc)
{
if (io->unflushed || force) {
pass_out_ctx ctx;

if (io->buflen > 0) {
/* something in the buffer, put it in the output brigade */
ap_log_cerror(APLOG_MARK, APLOG_TRACE4, 0, io->connection,
Expand All @@ -262,20 +274,29 @@ static apr_status_t h2_conn_io_flush_int(h2_conn_io *io, int force)
"h2_conn_io: flush");
/* Send it out */
io->unflushed = 0;
return pass_out(io->output, io);

ctx.c = io->connection;
ctx.io = eoc? NULL : io;
return pass_out(io->output, &ctx);
/* no more access after this, as we might have flushed an EOC bucket
* that de-allocated us all. */
}
return APR_SUCCESS;
}

apr_status_t h2_conn_io_write_eoc(h2_conn_io *io, apr_bucket *b)
{
APR_BRIGADE_INSERT_TAIL(io->output, b);
return h2_conn_io_flush_int(io, 1, 1);
}

apr_status_t h2_conn_io_flush(h2_conn_io *io)
{
return h2_conn_io_flush_int(io, 1);
return h2_conn_io_flush_int(io, 1, 0);
}

apr_status_t h2_conn_io_pass(h2_conn_io *io)
{
return h2_conn_io_flush_int(io, 0);
return h2_conn_io_flush_int(io, 0, 0);
}

1 change: 1 addition & 0 deletions mod_http2/h2_conn_io.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -60,5 +60,6 @@ apr_status_t h2_conn_io_consider_flush(h2_conn_io *io);

apr_status_t h2_conn_io_pass(h2_conn_io *io);
apr_status_t h2_conn_io_flush(h2_conn_io *io);
apr_status_t h2_conn_io_write_eoc(h2_conn_io *io, apr_bucket *b);

#endif /* defined(__mod_h2__h2_conn_io__) */
15 changes: 12 additions & 3 deletions mod_http2/h2_mplx.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -264,21 +264,30 @@ apr_status_t h2_mplx_release_and_join(h2_mplx *m, apr_thread_cond_t *wait)
workers_unregister(m);
status = apr_thread_mutex_lock(m->lock);
if (APR_SUCCESS == status) {
int i;

/* disable WINDOW_UPDATE callbacks */
h2_mplx_set_consumed_cb(m, NULL, NULL);
while (!h2_io_set_iter(m->stream_ios, stream_done_iter, m)) {
/* iterator until all h2_io have been orphaned or destroyed */
}

release(m, 0);
while (m->refs > 0) {
for (i = 0; m->refs > 0; ++i) {

m->join_wait = wait;
ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, m->c,
"h2_mplx(%ld): release_join, refs=%d, waiting...",
m->id, m->refs);
apr_thread_cond_wait(wait, m->lock);

status = apr_thread_cond_timedwait(wait, m->lock, apr_time_from_sec(2));
if (APR_STATUS_IS_TIMEUP(status)) {
ap_log_cerror(APLOG_MARK, APLOG_INFO, 0, m->c,
"h2_mplx(%ld): release timeup %d, refs=%d, waiting...",
m->id, i, m->refs);
}
}
ap_log_cerror(APLOG_MARK, APLOG_TRACE1, 0, m->c,
ap_log_cerror(APLOG_MARK, APLOG_DEBUG, 0, m->c,
"h2_mplx(%ld): release_join -> destroy, (#ios=%ld)",
m->id, (long)h2_io_set_size(m->stream_ios));
apr_thread_mutex_unlock(m->lock);
Expand Down
Loading

6 comments on commit 526a39f

@lkraav
Copy link

@lkraav lkraav commented on 526a39f Jan 1, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I upgraded to 1.0.15. I think now I'm seeing occasional strange browser behavior where hitting Refresh (F5, Ctrl+R) for the first time doesn't reload the page anymore. Repeat key hit works every time. As said, this happens occasionally, but often enough to be clearly noticeable - like ~20% of the time perhaps? Because this release has notes about connection states and keep-alives, I thought I'd share while looking to gather more data about this.

@icing
Copy link
Owner

@icing icing commented on 526a39f Jan 2, 2016 via email

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lkraav
Copy link

@lkraav lkraav commented on 526a39f Jan 2, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks. I just bumped myself to 1.0.16, let's see how it goes.

PS I thought I read in some release notes that connections were going to be logged as HTTP/2.0 now? I still see HTTP/2.

PSS that's one bomb goatee you got going on.

@lkraav
Copy link

@lkraav lkraav commented on 526a39f Jan 3, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

1.0.16 at least by default configuration still has the same effect. Firefox network panel shows a red square for these connections and Request tab has "Connection: Keep-Alive" field listed, so it's likely it's related.

It messes up some AJAX controls, because the browser makes the app think it's an active but endless connection going on, and UI gets stuck until you reload the whole page.

@icing
Copy link
Owner

@icing icing commented on 526a39f Jan 3, 2016 via email

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lkraav
Copy link

@lkraav lkraav commented on 526a39f Jan 3, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, event MPM.

/etc/apache2 $ ag KeepAlive
modules.d/00_default_settings.conf
7:# KeepAlive: Whether or not to allow persistent connections (more than
9:KeepAlive On
11:# MaxKeepAliveRequests: The maximum number of requests to allow
14:MaxKeepAliveRequests 100
16:# KeepAliveTimeout: Number of seconds to wait for the next request from the
18:KeepAliveTimeout 15

Please sign in to comment.