Hi Stefan, thanks for testing again!
On Wed, Jul 19, 2017 at 7:42 PM, Stefan Priebe - Profihost AG <s.pri...@profihost.ag> wrote: > > What looks strange > from a first view is that async connections closing has very high and > strange values: > 4294967211 Indeed, I messed up with mpm_event's lingering_count in the first patch. And it can lead to disabling the listener, which I think is what you observe. Attached is a v2 if you feel confident enough, still ;) Regards, Yann.
Index: server/mpm/event/event.c =================================================================== --- server/mpm/event/event.c (revision 1802058) +++ server/mpm/event/event.c (working copy) @@ -243,6 +243,8 @@ struct event_conn_state_t { apr_pollfd_t pfd; /** public parts of the connection state */ conn_state_t pub; + /** shutdown quickly in LINGER state? */ + int shutdown_linger; }; APR_RING_HEAD(timeout_head_t, event_conn_state_t); @@ -260,11 +262,13 @@ struct timeout_queue { * keepalive_q uses vhost's KeepAliveTimeOut * linger_q uses MAX_SECS_TO_LINGER * short_linger_q uses SECONDS_TO_LINGER + * shutdown_linger_q uses SECONDS_TO_LINGER */ static struct timeout_queue *write_completion_q, *keepalive_q, *linger_q, - *short_linger_q; + *short_linger_q, + *shutdown_linger_q; static volatile apr_time_t queues_next_expiry; /* Prevent extra poll/wakeup calls for timeouts close in the future (queues @@ -699,6 +703,7 @@ static apr_status_t decrement_connection_count(voi { event_conn_state_t *cs = cs_; switch (cs->pub.state) { + case CONN_STATE_LINGER: case CONN_STATE_LINGER_NORMAL: case CONN_STATE_LINGER_SHORT: apr_atomic_dec32(&lingering_count); @@ -731,11 +736,16 @@ static void notify_resume(event_conn_state_t *cs, ap_run_resume_connection(cs->c, cs->r); } -static int start_lingering_close_common(event_conn_state_t *cs, int in_worker) +static int have_idle_worker = 0; +static void push_cs2worker(event_conn_state_t *cs, + int *all_busy); + +static int start_lingering_close_common(event_conn_state_t *cs, + struct timeout_queue *q, + int in_worker) { apr_status_t rv; - struct timeout_queue *q; - apr_socket_t *csd = cs->pfd.desc.s; + apr_socket_t *csd = ap_get_conn_socket(cs->c); #ifdef AP_DEBUG { rv = apr_socket_timeout_set(csd, 0); @@ -745,20 +755,6 @@ static void notify_resume(event_conn_state_t *cs, apr_socket_timeout_set(csd, 0); #endif cs->queue_timestamp = apr_time_now(); - /* - * If some module requested a shortened waiting period, only wait for - * 2s (SECONDS_TO_LINGER). This is useful for mitigating certain - * DoS attacks. - */ - if (apr_table_get(cs->c->notes, "short-lingering-close")) { - q = short_linger_q; - cs->pub.state = CONN_STATE_LINGER_SHORT; - } - else { - q = linger_q; - cs->pub.state = CONN_STATE_LINGER_NORMAL; - } - apr_atomic_inc32(&lingering_count); if (in_worker) { notify_suspend(cs); } @@ -796,40 +792,63 @@ static void notify_resume(event_conn_state_t *cs, */ static int start_lingering_close_blocking(event_conn_state_t *cs) { - if (ap_start_lingering_close(cs->c)) { + struct timeout_queue *q; + int closed = ap_start_lingering_close(cs->c); + if (closed || cs->shutdown_linger) { notify_suspend(cs); + if (!closed) { + apr_socket_t *csd = ap_get_conn_socket(cs->c); + apr_socket_close(csd); + } ap_push_pool(worker_queue_info, cs->p); return 0; } - return start_lingering_close_common(cs, 1); + /* + * If some module requested a shortened waiting period, only wait for + * 2s (SECONDS_TO_LINGER). This is useful for mitigating certain + * DoS attacks. + */ + if (apr_table_get(cs->c->notes, "short-lingering-close")) { + q = short_linger_q; + cs->pub.state = CONN_STATE_LINGER_SHORT; + } + else { + q = linger_q; + cs->pub.state = CONN_STATE_LINGER_NORMAL; + } + /* Don't count lingering close twice for this connection, + * we may come from start_lingering_close_nonblocking(). + */ + if (!cs->shutdown_linger) { + apr_atomic_inc32(&lingering_count); + } + return start_lingering_close_common(cs, q, 1); } /* - * Close our side of the connection, NOT flushing data to the client. - * This should only be called if there has been an error or if we know - * that our send buffers are empty. + * Defer to a worker the flush and close of our side of the connection. * Pre-condition: cs is not in any timeout queue and not in the pollset, * timeout_mutex is not locked * return: 0 if connection is fully closed, * 1 if connection is lingering - * may be called by listener thread + * May be called by listener thread + * + * The caller wants the nonblocking garantee and (still) to shutdown the + * connection (i.e. run the pre_close hook, send a TLS close notify alert + * possibly, the FIN packet, ...), quite antithetical hence the defer. */ static int start_lingering_close_nonblocking(event_conn_state_t *cs) { - conn_rec *c = cs->c; - apr_socket_t *csd = cs->pfd.desc.s; - - if (ap_prep_lingering_close(c) - || c->aborted - || ap_shutdown_conn(c, 0) != APR_SUCCESS || c->aborted - || apr_socket_shutdown(csd, APR_SHUTDOWN_WRITE) != APR_SUCCESS) { - apr_socket_close(csd); - ap_push_pool(worker_queue_info, cs->p); - if (dying) - ap_queue_interrupt_one(worker_queue); - return 0; - } - return start_lingering_close_common(cs, 0); + /* Ask for writability on the socket and then let some worker do the job. + * This function is likely called(-back) when a timeout occurs (keepalive, + * write completion) so it should take a limited time to complete in any + * case, currently SECONDS_TO_LINGER. + */ + cs->shutdown_linger = 1; + cs->pub.state = CONN_STATE_LINGER; + cs->pub.sense = CONN_SENSE_WANT_WRITE; + apr_atomic_inc32(&lingering_count); + return start_lingering_close_common(cs, shutdown_linger_q, 0); } /* @@ -856,6 +875,19 @@ static int stop_lingering_close(event_conn_state_t } /* + * forcibly close a lingering connection after the shutdown period has + * expired + * Pre-condition: cs is not in any timeout queue and not in the pollset + * return: irrelevant (need same prototype as start_lingering_close) + */ +static int shutdown_lingering_close(event_conn_state_t *cs) +{ + int all_busy = 0; + push_cs2worker(cs, &all_busy); + return 0; +} + +/* * This runs before any non-MPM cleanup code on the connection; * if the connection is currently suspended as far as modules * know, provide notification of resumption. @@ -1281,6 +1313,8 @@ static apr_status_t init_pollset(apr_pool_t *p) return APR_SUCCESS; } +static void get_worker(int blocking, int *all_busy); + static apr_status_t push_timer2worker(timer_event_t* te) { return ap_queue_push_timer(worker_queue, te); @@ -1287,16 +1321,14 @@ static apr_status_t push_timer2worker(timer_event_ } /* - * Pre-condition: pfd->cs is neither in pollset nor timeout queue + * Pre-condition: cs is neither in pollset nor timeout queue * this function may only be called by the listener */ -static apr_status_t push2worker(const apr_pollfd_t * pfd, - apr_pollset_t * pollset) +static void push_cs2worker(event_conn_state_t *cs, + int *all_busy) { - listener_poll_type *pt = (listener_poll_type *) pfd->client_data; - event_conn_state_t *cs = (event_conn_state_t *) pt->baton; apr_status_t rc; - + get_worker(1, all_busy); rc = ap_queue_push(worker_queue, cs->pfd.desc.s, cs, cs->p); if (rc != APR_SUCCESS) { /* trash the connection; we couldn't queue the connected @@ -1304,28 +1336,33 @@ static apr_status_t push_timer2worker(timer_event_ */ apr_bucket_alloc_destroy(cs->bucket_alloc); apr_socket_close(cs->pfd.desc.s); - ap_log_error(APLOG_MARK, APLOG_CRIT, rc, - ap_server_conf, APLOGNO(00471) "push2worker: ap_queue_push failed"); + ap_log_error(APLOG_MARK, APLOG_CRIT, rc, ap_server_conf, APLOGNO(00471) + "push_cs2worker: ap_queue_push failed"); ap_push_pool(worker_queue_info, cs->p); + + /* XXX: shouldn't we call this? + signal_threads(ST_GRACEFUL); + */ } - - return rc; + else { + have_idle_worker = 0; + } } /* get_worker: - * If *have_idle_worker_p == 0, reserve a worker thread, and set - * *have_idle_worker_p = 1. - * If *have_idle_worker_p is already 1, will do nothing. + * If have_idle_worker == 0, reserve a worker thread, and set + * have_idle_worker = 1. + * If have_idle_worker is already 1, will do nothing. * If blocking == 1, block if all workers are currently busy. * If no worker was available immediately, will set *all_busy to 1. * XXX: If there are no workers, we should not block immediately but * XXX: close all keep-alive connections first. */ -static void get_worker(int *have_idle_worker_p, int blocking, int *all_busy) +static void get_worker(int blocking, int *all_busy) { apr_status_t rc; - if (*have_idle_worker_p) { + if (have_idle_worker) { /* already reserved a worker thread - must have hit a * transient error on a previous pass */ @@ -1338,7 +1375,7 @@ static apr_status_t push_timer2worker(timer_event_ rc = ap_queue_info_try_get_idler(worker_queue_info); if (rc == APR_SUCCESS || APR_STATUS_IS_EOF(rc)) { - *have_idle_worker_p = 1; + have_idle_worker = 1; } else if (!blocking && rc == APR_EAGAIN) { *all_busy = 1; @@ -1675,7 +1712,6 @@ static void * APR_THREAD_FUNC listener_thread(apr_ struct process_score *ps = ap_get_scoreboard_process(process_slot); apr_pool_t *tpool = apr_thread_pool_get(thd); int closed = 0, listeners_disabled = 0; - int have_idle_worker = 0; apr_time_t last_log; last_log = apr_time_now(); @@ -1845,22 +1881,25 @@ static void * APR_THREAD_FUNC listener_thread(apr_ /* one of the sockets is readable */ event_conn_state_t *cs = (event_conn_state_t *) pt->baton; struct timeout_queue *remove_from_q = cs->sc->wc_q; - int blocking = 1; switch (cs->pub.state) { + case CONN_STATE_LINGER: + remove_from_q = shutdown_linger_q; + goto pass_to_worker; + case CONN_STATE_CHECK_REQUEST_LINE_READABLE: cs->pub.state = CONN_STATE_READ_REQUEST_LINE; remove_from_q = cs->sc->ka_q; - /* don't wait for a worker for a keepalive request */ - blocking = 0; - /* FALL THROUGH */ + goto pass_to_worker; + case CONN_STATE_WRITE_COMPLETION: - get_worker(&have_idle_worker, blocking, - &workers_were_busy); +pass_to_worker: apr_thread_mutex_lock(timeout_mutex); TO_QUEUE_REMOVE(remove_from_q, cs); rc = apr_pollset_remove(event_pollset, &cs->pfd); apr_thread_mutex_unlock(timeout_mutex); + TO_QUEUE_ELEM_INIT(cs); + /* * Some of the pollset backends, like KQueue or Epoll * automagically remove the FD if the socket is closed, @@ -1870,33 +1909,19 @@ static void * APR_THREAD_FUNC listener_thread(apr_ if (rc != APR_SUCCESS && !APR_STATUS_IS_NOTFOUND(rc)) { ap_log_error(APLOG_MARK, APLOG_ERR, rc, ap_server_conf, APLOGNO(03094) "pollset remove failed"); - start_lingering_close_nonblocking(cs); - break; + apr_socket_timeout_set(cs->pfd.desc.s, 0); + cs->pub.state = CONN_STATE_LINGER; + cs->shutdown_linger = 1; } - TO_QUEUE_ELEM_INIT(cs); - /* If we didn't get a worker immediately for a keep-alive - * request, we close the connection, so that the client can - * re-connect to a different process. - */ - if (!have_idle_worker) { - start_lingering_close_nonblocking(cs); - break; - } - rc = push2worker(out_pfd, event_pollset); - if (rc != APR_SUCCESS) { - ap_log_error(APLOG_MARK, APLOG_CRIT, rc, - ap_server_conf, APLOGNO(03095) - "push2worker failed"); - } - else { - have_idle_worker = 0; - } + push_cs2worker(cs, &workers_were_busy); break; + case CONN_STATE_LINGER_NORMAL: case CONN_STATE_LINGER_SHORT: process_lingering_close(cs, out_pfd); break; + default: ap_log_error(APLOG_MARK, APLOG_CRIT, rc, ap_server_conf, APLOGNO(03096) @@ -1964,7 +1989,7 @@ static void * APR_THREAD_FUNC listener_thread(apr_ } apr_pool_tag(ptrans, "transaction"); - get_worker(&have_idle_worker, 1, &workers_were_busy); + get_worker(1, &workers_were_busy); rc = lr->accept_func(&csd, lr, ptrans); /* later we trash rv and rely on csd to indicate @@ -2073,6 +2098,9 @@ static void * APR_THREAD_FUNC listener_thread(apr_ /* Step 4: (short) lingering close completion timeouts */ process_timeout_queue(short_linger_q, timeout_time, stop_lingering_close); + /* Step 5: (shutdown) lingering close completion timeouts */ + process_timeout_queue(shutdown_linger_q, timeout_time, + shutdown_lingering_close); apr_thread_mutex_unlock(timeout_mutex); @@ -3520,10 +3548,15 @@ static int event_post_config(apr_pool_t *pconf, ap wc.hash = apr_hash_make(ptemp); ka.hash = apr_hash_make(ptemp); - linger_q = TO_QUEUE_MAKE(pconf, apr_time_from_sec(MAX_SECS_TO_LINGER), + linger_q = TO_QUEUE_MAKE(pconf, + apr_time_from_sec(MAX_SECS_TO_LINGER), NULL); - short_linger_q = TO_QUEUE_MAKE(pconf, apr_time_from_sec(SECONDS_TO_LINGER), + short_linger_q = TO_QUEUE_MAKE(pconf, + apr_time_from_sec(SECONDS_TO_LINGER), NULL); + shutdown_linger_q = TO_QUEUE_MAKE(pconf, + apr_time_from_sec(SECONDS_TO_LINGER), + NULL); for (; s; s = s->next) { event_srv_cfg *sc = apr_pcalloc(pconf, sizeof *sc);