Index: server/mpm/event/event.c =================================================================== --- server/mpm/event/event.c (Revision 1891311) +++ server/mpm/event/event.c (Arbeitskopie) @@ -596,13 +596,19 @@ listener_may_exit = 1; disable_listensocks(); + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, APLOGNO() + "wakeup_listener: start"); /* Unblock the listener if it's poll()ing */ if (event_pollset && listener_is_wakeable) { + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, APLOGNO() + "wakeup_listener: apr_pollset_wakeup"); apr_pollset_wakeup(event_pollset); } /* unblock the listener if it's waiting for a worker */ if (worker_queue_info) { + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, APLOGNO() + "wakeup_listener: ap_queue_info_term"); ap_queue_info_term(worker_queue_info); } @@ -620,10 +626,14 @@ * with SIGHUP unblocked, but that doesn't work on Linux */ #ifdef HAVE_PTHREAD_KILL + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, APLOGNO() + "wakeup_listener: pthread_kill"); pthread_kill(*listener_os_thread, LISTENER_SIGNAL); #else kill(ap_my_pid, LISTENER_SIGNAL); #endif + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, APLOGNO() + "wakeup_listener: end"); } #define ST_INIT 0 @@ -795,9 +805,16 @@ * now accept new connections. */ is_last_connection = !apr_atomic_dec32(&connection_count); + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, + APLOGNO() "decrement_connection_count: last_connection=%d" + " listener_may_exit=%d connection_count=%d", + is_last_connection, listener_may_exit, + apr_atomic_read32(&connection_count)); if (listener_is_wakeable && ((is_last_connection && listener_may_exit) || (listeners_disabled() && !connections_above_limit(NULL)))) { + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, + APLOGNO() "decrement_connection_count: pollset_wakeup"); apr_pollset_wakeup(event_pollset); } return APR_SUCCESS; @@ -1940,15 +1957,6 @@ rc = apr_pollset_poll(event_pollset, timeout_interval, &num, &out_pfd); if (rc != APR_SUCCESS) { if (APR_STATUS_IS_EINTR(rc)) { - /* Woken up, if we are exiting or listeners are disabled we - * must fall through to kill kept-alive connections or test - * whether listeners should be re-enabled. Otherwise we only - * need to update timeouts (logic is above, so simply restart - * the loop). - */ - if (!listener_may_exit && !listeners_disabled()) { - continue; - } timeout_time = 0; } else if (!APR_STATUS_IS_TIMEUP(rc)) { @@ -1967,6 +1975,10 @@ || apr_atomic_read32(&connection_count) == 0) break; } + ap_log_error(APLOG_MARK, APLOG_DEBUG, rc, ap_server_conf, + APLOGNO() "pollset returned listener_may_exit=%d" + " connection_count=%d", listener_may_exit, + apr_atomic_read32(&connection_count)); for (user_chain = NULL; num; --num, ++out_pfd) { listener_poll_type *pt = (listener_poll_type *) out_pfd->client_data; @@ -2235,10 +2247,20 @@ */ if (defer_linger_chain) { get_worker(&have_idle_worker, 0, &workers_were_busy); + ap_log_error(APLOG_MARK, APLOG_DEBUG, rc, ap_server_conf, + APLOGNO() "listener: process defer_linger_chain " + "have_idle_worker=%d listener_may_exit=%d connection_count=%d", + have_idle_worker, listener_may_exit, + apr_atomic_read32(&connection_count)); if (have_idle_worker && defer_linger_chain /* re-test */ && push2worker(NULL, NULL, NULL) == APR_SUCCESS) { have_idle_worker = 0; + ap_log_error(APLOG_MARK, APLOG_DEBUG, rc, ap_server_conf, + APLOGNO() "listener: process defer_linger_chain " + "pushed to worker, listener_may_exit=%d connection_count=%d", + listener_may_exit, + apr_atomic_read32(&connection_count)); } } @@ -2284,6 +2306,46 @@ } } +static void process_defer_linger(apr_thread_t * thd, int process_slot, int thread_slot) +{ + event_conn_state_t *cs; + apr_socket_t *csd; + apr_status_t rv; + + /* If there are deferred lingering closes, handle them now. */ + while (!workers_may_exit) { + cs = defer_linger_chain; + if (!cs) { + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, + APLOGNO() "process_defer_linger, nothing more to do"); + break; + } + if (apr_atomic_casptr((void *)&defer_linger_chain, cs->chain, + cs) != cs) { + /* Race lost, try again */ + continue; + } + cs->chain = NULL; + + worker_sockets[thread_slot] = csd = cs->pfd.desc.s; +#ifdef AP_DEBUG + rv = apr_socket_timeout_set(csd, SECONDS_TO_LINGER); + AP_DEBUG_ASSERT(rv == APR_SUCCESS); +#else + apr_socket_timeout_set(csd, SECONDS_TO_LINGER); +#endif + cs->pub.state = CONN_STATE_LINGER; + ap_log_error(APLOG_MARK, APLOG_DEBUG, rv, ap_server_conf, + APLOGNO() "process_defer_linger, processing socket, connection_count=%d", + apr_atomic_read32(&connection_count)); + process_socket(thd, cs->p, csd, cs, process_slot, thread_slot); + ap_log_error(APLOG_MARK, APLOG_DEBUG, rv, ap_server_conf, + APLOGNO() "process_defer_linger, processed socket, connection_count=%d", + apr_atomic_read32(&connection_count)); + worker_sockets[thread_slot] = NULL; + } +} + /* XXX For ungraceful termination/restart, we definitely don't want to * wait for active connections to finish but we may want to wait * for idle workers to get out of the queue code and release mutexes, @@ -2337,8 +2399,15 @@ break; } + ap_log_error(APLOG_MARK, APLOG_DEBUG, rv, ap_server_conf, + APLOGNO() "worker read worker_queue, " + "workers_may_exit=%d, dying=%d", + workers_may_exit, dying); rv = ap_queue_pop_something(worker_queue, &csd, (void **)&cs, &ptrans, &te); + ap_log_error(APLOG_MARK, APLOG_DEBUG, rv, ap_server_conf, + APLOGNO() "worker pop_something, workers_may_exit=%d, dying=%d", + workers_may_exit, dying); if (rv != APR_SUCCESS) { /* We get APR_EOF during a graceful shutdown once all the @@ -2359,6 +2428,10 @@ * workers_may_exit is set. */ else if (APR_STATUS_IS_EINTR(rv)) { + ap_log_error(APLOG_MARK, APLOG_DEBUG, rv, ap_server_conf, + APLOGNO() "worker pop_something interrupted, " + "goto worker_pop"); + /*process_defer_linger(thd, process_slot, thread_slot);*/ goto worker_pop; } /* We got some other error. */ @@ -2385,30 +2458,7 @@ } } - /* If there are deferred lingering closes, handle them now. */ - while (!workers_may_exit) { - cs = defer_linger_chain; - if (!cs) { - break; - } - if (apr_atomic_casptr((void *)&defer_linger_chain, cs->chain, - cs) != cs) { - /* Race lost, try again */ - continue; - } - cs->chain = NULL; - - worker_sockets[thread_slot] = csd = cs->pfd.desc.s; -#ifdef AP_DEBUG - rv = apr_socket_timeout_set(csd, SECONDS_TO_LINGER); - AP_DEBUG_ASSERT(rv == APR_SUCCESS); -#else - apr_socket_timeout_set(csd, SECONDS_TO_LINGER); -#endif - cs->pub.state = CONN_STATE_LINGER; - process_socket(thd, cs->p, csd, cs, process_slot, thread_slot); - worker_sockets[thread_slot] = NULL; - } + process_defer_linger(thd, process_slot, thread_slot); } ap_update_child_status_from_indexes(process_slot, thread_slot, @@ -2705,6 +2755,8 @@ iter = 0; while (iter < 10 && !dying) { /* listener has not stopped accepting yet */ + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, ap_server_conf, APLOGNO() + "listener has not stopped accepting yet (%d iter)", iter); apr_sleep(apr_time_make(0, 500000)); wakeup_listener(); ++iter; @@ -2918,7 +2970,12 @@ * If the worker hasn't exited, then this blocks until * they have (then cleans up). */ + ap_log_error(APLOG_MARK, APLOG_TRACE1, 0, ap_server_conf, + "%s termination received, join workers", + AP_MPM_PODX_GRACEFUL ? "graceful" : "ungraceful"); join_workers(ts->listener, threads); + ap_log_error(APLOG_MARK, APLOG_TRACE1, 0, ap_server_conf, + "termination, workers joined, exiting"); } free(threads);