From dbe3e2361b9fac89bfec6a0180975685446edc9b Mon Sep 17 00:00:00 2001 From: Glenn Strauss Date: Thu, 11 Mar 2021 06:32:28 -0500 Subject: [PATCH] [multiple] prefer monotonic time for internal use Note: monotonic time does not change while VM is suspended Continue to use real time where required by HTTP protocol, for logging and for other user-visible instances, such as mod_status, as well as for external databases and caches. --- src/connections.c | 35 ++++++++++++++++-------------- src/gw_backend.c | 32 ++++++++++++++-------------- src/h2.c | 10 ++++----- src/log.c | 9 ++++++++ src/log.h | 2 ++ src/mod_accesslog.c | 2 +- src/mod_auth.c | 4 ++-- src/mod_magnet_cache.c | 4 ---- src/mod_magnet_cache.h | 2 -- src/mod_vhostdb.c | 4 ++-- src/mod_wstunnel.c | 4 ++-- src/server.c | 48 +++++++++++++++++++++++++++--------------- src/stat_cache.c | 10 ++++----- 13 files changed, 94 insertions(+), 72 deletions(-) diff --git a/src/connections.c b/src/connections.c index 410c035d..ec45fad8 100644 --- a/src/connections.c +++ b/src/connections.c @@ -151,12 +151,12 @@ static void connection_read_for_eos_plain(connection * const con) { #endif /* 0 == len || (len < 0 && (errno is a non-recoverable error)) */ - con->close_timeout_ts = log_epoch_secs - (HTTP_LINGER_TIMEOUT+1); + con->close_timeout_ts = log_monotonic_secs - (HTTP_LINGER_TIMEOUT+1); } static void connection_read_for_eos_ssl(connection * const con) { if (con->network_read(con, con->read_queue, MAX_READ_LIMIT) < 0) - con->close_timeout_ts = log_epoch_secs - (HTTP_LINGER_TIMEOUT+1); + con->close_timeout_ts = log_monotonic_secs - (HTTP_LINGER_TIMEOUT+1); chunkqueue_reset(con->read_queue); } @@ -169,7 +169,7 @@ static void connection_read_for_eos(connection * const con) { static void connection_handle_close_state(connection *con) { connection_read_for_eos(con); - if (log_epoch_secs - con->close_timeout_ts > HTTP_LINGER_TIMEOUT) { + if (log_monotonic_secs - con->close_timeout_ts > HTTP_LINGER_TIMEOUT) { connection_close(con); } } @@ -183,7 +183,7 @@ static void connection_handle_shutdown(connection *con) { /* close the connection */ if (con->fd >= 0 && (con->is_ssl_sock || 0 == shutdown(con->fd, SHUT_WR))) { - con->close_timeout_ts = log_epoch_secs; + con->close_timeout_ts = log_monotonic_secs; request_st * const r = &con->request; connection_set_state(r, CON_STATE_CLOSE); @@ -236,7 +236,8 @@ static void connection_handle_response_end_state(request_st * const r, connectio r->bytes_read_ckpt = con->bytes_read; r->bytes_written_ckpt = con->bytes_written; #if 0 - r->start_hp.tv_sec = con->read_idle_ts = log_epoch_secs; + r->start_hp.tv_sec = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; #endif connection_set_state(r, CON_STATE_REQUEST_START); } else { @@ -286,7 +287,7 @@ connection_write_chunkqueue (connection * const con, chunkqueue * const restrict { /*assert(!chunkqueue_is_empty(cq));*//* checked by callers */ - con->write_request_ts = log_epoch_secs; + con->write_request_ts = log_monotonic_secs; max_bytes = connection_write_throttle(con, max_bytes); if (0 == max_bytes) return 1; @@ -614,7 +615,7 @@ static chunk * connection_read_header_more(connection *con, chunkqueue *cq, chun * and return from this routine with r->http_version == HTTP_VERSION_2) */ if ((NULL == c || NULL == c->next) && con->is_readable > 0) { - con->read_idle_ts = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; if (0 != con->network_read(con, cq, MAX_READ_LIMIT)) { request_st * const r = &con->request; connection_set_state_error(r, CON_STATE_ERROR); @@ -764,7 +765,8 @@ static int connection_handle_read_state(connection * const con) { if (r->conf.high_precision_timestamps) log_clock_gettime_realtime(&r->start_hp); } - if (pipelined_request_start && c) con->read_idle_ts = log_epoch_secs; + if (pipelined_request_start && c) + con->read_idle_ts = log_monotonic_secs; } if (NULL == c) return 0; /* incomplete request headers */ @@ -1005,7 +1007,7 @@ connection *connection_accepted(server *srv, server_socket *srv_socket, sock_add request_st * const r = &con->request; connection_set_state(r, CON_STATE_REQUEST_START); - con->connection_start = log_epoch_secs; + con->connection_start = log_monotonic_secs; con->dst_addr = *cnt_addr; sock_addr_cache_inet_ntop_copy_buffer(con->dst_addr_buf,&con->dst_addr); con->srv_socket = srv_socket; @@ -1065,7 +1067,8 @@ connection_state_machine_loop (request_st * const r, connection * const con) switch ((ostate = r->state)) { case CON_STATE_REQUEST_START: /* transient */ /*(should not be reached by HTTP/2 streams)*/ - r->start_hp.tv_sec = con->read_idle_ts = log_epoch_secs; + r->start_hp.tv_sec = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; if (r->conf.high_precision_timestamps) log_clock_gettime_realtime(&r->start_hp); @@ -1157,7 +1160,7 @@ connection_revents_err (request_st * const r, connection * const con) con->revents_err = 0; if (r->state == CON_STATE_CLOSE) - con->close_timeout_ts = log_epoch_secs - (HTTP_LINGER_TIMEOUT+1); + con->close_timeout_ts = log_monotonic_secs - (HTTP_LINGER_TIMEOUT+1); else if (revents & FDEVENT_HUP) connection_set_state_error(r, CON_STATE_ERROR); else if (revents & FDEVENT_RDHUP) { @@ -1258,9 +1261,9 @@ connection_set_fdevent_interest (request_st * const r, connection * const con) /* update timestamps when enabling interest in events */ if ((n & FDEVENT_IN) && !(events & FDEVENT_IN)) - con->read_idle_ts = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; if ((n & FDEVENT_OUT) && !(events & FDEVENT_OUT)) - con->write_request_ts = log_epoch_secs; + con->write_request_ts = log_monotonic_secs; fdevent_fdnode_event_set(con->srv->ev, con->fdn, n); } @@ -1625,7 +1628,7 @@ void connection_periodic_maint (server * const srv, const time_t cur_ts) { void connection_graceful_shutdown_maint (server *srv) { connections * const conns = &srv->conns; const int graceful_expire = - (srv->graceful_expire_ts && srv->graceful_expire_ts < log_epoch_secs); + (srv->graceful_expire_ts && srv->graceful_expire_ts < log_monotonic_secs); for (uint32_t ndx = 0; ndx < conns->used; ++ndx) { connection * const con = conns->ptr[ndx]; int changed = 0; @@ -1636,7 +1639,7 @@ void connection_graceful_shutdown_maint (server *srv) { * (from zero) *up to* one more second, but no more */ if (HTTP_LINGER_TIMEOUT > 1) con->close_timeout_ts -= (HTTP_LINGER_TIMEOUT - 1); - if (log_epoch_secs - con->close_timeout_ts > HTTP_LINGER_TIMEOUT) + if (log_monotonic_secs - con->close_timeout_ts > HTTP_LINGER_TIMEOUT) changed = 1; } else if (con->h2 && r->state == CON_STATE_WRITE) { @@ -1954,7 +1957,7 @@ connection_handle_read_post_state (request_st * const r) is_closed = 1; } else if (con->is_readable > 0) { - con->read_idle_ts = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; switch(con->network_read(con, cq, MAX_READ_LIMIT)) { case -1: diff --git a/src/gw_backend.c b/src/gw_backend.c index 621b4691..dbe27193 100644 --- a/src/gw_backend.c +++ b/src/gw_backend.c @@ -222,7 +222,7 @@ static int gw_extension_insert(gw_exts *ext, const buffer *key, gw_host *fh) { static void gw_proc_connect_success(gw_host *host, gw_proc *proc, int debug, request_st * const r) { gw_proc_tag_inc(host, proc, CONST_STR_LEN(".connected")); - proc->last_used = log_epoch_secs; + proc->last_used = log_monotonic_secs; if (debug) { log_error(r->conf.errh, __FILE__, __LINE__, @@ -233,7 +233,7 @@ static void gw_proc_connect_success(gw_host *host, gw_proc *proc, int debug, req __attribute_cold__ static void gw_proc_connect_error(request_st * const r, gw_host *host, gw_proc *proc, pid_t pid, int errnum, int debug) { - const time_t cur_ts = log_epoch_secs; + const time_t cur_ts = log_monotonic_secs; log_error_st * const errh = r->conf.errh; log_error(errh, __FILE__, __LINE__, "establishing connection failed: socket: %s: %s", @@ -307,7 +307,7 @@ static void gw_proc_release(gw_host *host, gw_proc *proc, int debug, log_error_s } static void gw_proc_check_enable(gw_host * const host, gw_proc * const proc, log_error_st * const errh) { - if (log_epoch_secs <= proc->disabled_until) return; + if (log_monotonic_secs <= proc->disabled_until) return; if (proc->state != PROC_STATE_OVERLOADED) return; gw_proc_set_state(host, proc, PROC_STATE_RUNNING); @@ -360,7 +360,7 @@ static int gw_proc_waitpid(gw_host *host, gw_proc *proc, log_error_st *errh) { proc->pid = 0; if (proc->state != PROC_STATE_KILLED) - proc->disabled_until = log_epoch_secs; + proc->disabled_until = log_monotonic_secs; gw_proc_set_state(host, proc, PROC_STATE_DIED); return 1; } @@ -586,12 +586,12 @@ static int gw_spawn_connection(gw_host * const host, gw_proc * const proc, log_e log_error(errh, __FILE__, __LINE__, "gw-backend failed to start: %s", host->bin_path->ptr); proc->pid = 0; - proc->disabled_until = log_epoch_secs; + proc->disabled_until = log_monotonic_secs; return -1; } /* register process */ - proc->last_used = log_epoch_secs; + proc->last_used = log_monotonic_secs; proc->is_local = 1; /* wait */ @@ -628,7 +628,7 @@ static void gw_proc_spawn(gw_host * const host, log_error_st * const errh, const /* (proc->pid <= 0 indicates PROC_STATE_DIED, not PROC_STATE_KILLED) */ if (proc->pid > 0) continue; /* (do not attempt to spawn another proc if a proc just exited) */ - if (proc->disabled_until >= log_epoch_secs) return; + if (proc->disabled_until >= log_monotonic_secs) return; break; } if (proc) { @@ -1027,7 +1027,7 @@ static void gw_restart_dead_procs(gw_host * const host, log_error_st * const err /*(state should not happen in workers if server.max-worker > 0)*/ /*(if PROC_STATE_DIED_WAIT_FOR_PID is used in future, might want * to save proc->disabled_until before gw_proc_waitpid() since - * gw_proc_waitpid will set proc->disabled_until to log_epoch_secs, + * gw_proc_waitpid will set proc->disabled_until=log_monotonic_secs, * and so process will not be restarted below until one sec later)*/ if (0 == gw_proc_waitpid(host, proc, errh)) { gw_proc_check_enable(host, proc, errh); @@ -1046,7 +1046,7 @@ static void gw_restart_dead_procs(gw_host * const host, log_error_st * const err if (proc->load != 0) break; /* avoid spinning if child exits too quickly */ - if (proc->disabled_until >= log_epoch_secs) break; + if (proc->disabled_until >= log_monotonic_secs) break; /* restart the child */ @@ -1747,7 +1747,7 @@ int gw_get_defaults_balance(server *srv, const buffer *b) { static void gw_set_state(gw_handler_ctx *hctx, gw_connection_state_t state) { hctx->state = state; - /*hctx->state_timestamp = log_epoch_secs;*/ + /*hctx->state_timestamp = log_monotonic_secs;*/ } @@ -1969,7 +1969,7 @@ static handler_t gw_write_request(gw_handler_ctx * const hctx, request_st * cons } } else if (hctx->wb.bytes_out > bytes_out) { - hctx->proc->last_used = log_epoch_secs; + hctx->proc->last_used = log_monotonic_secs; if (hctx->stdin_append && chunkqueue_length(&hctx->wb) < 65536 - 16384 && !chunkqueue_is_empty(&r->reqbody_queue)) { @@ -2172,10 +2172,10 @@ static handler_t gw_recv_response(gw_handler_ctx * const hctx, request_st * cons * may not be triggered for partial collection of HTTP response headers * or partial packets for backend protocol (e.g. FastCGI) */ if (r->write_queue.bytes_in > bytes_in) - proc->last_used = log_epoch_secs; + proc->last_used = log_monotonic_secs; return HANDLER_GO_ON; case HANDLER_FINISHED: - proc->last_used = log_epoch_secs; + proc->last_used = log_monotonic_secs; if (hctx->gw_mode == GW_AUTHORIZER && (200 == r->http_status || 0 == r->http_status)) { /* @@ -2245,7 +2245,7 @@ static handler_t gw_recv_response_error(gw_handler_ctx * const hctx, request_st /* intentionally check proc->disabed_until before gw_proc_waitpid */ gw_host * const host = hctx->host; log_error_st * const errh = r->con->srv->errh; - if (proc->disabled_until < log_epoch_secs + if (proc->disabled_until < log_monotonic_secs && 0 != gw_proc_waitpid(host, proc, errh)) { if (hctx->conf.debug) { log_error(errh, __FILE__, __LINE__, @@ -2620,7 +2620,7 @@ static void gw_handle_trigger_host(gw_host * const host, log_error_st * const er gw_proc_spawn(host, errh, debug); } - idle_timestamp = log_epoch_secs - host->idle_timeout; + idle_timestamp = log_monotonic_secs - host->idle_timeout; for (proc = host->first; proc; proc = proc->next) { if (host->num_procs <= host->min_procs) break; if (0 != proc->load) continue; @@ -2738,7 +2738,7 @@ handler_t gw_handle_waitpid_cb(server *srv, void *p_d, pid_t pid, int status) { * or global scope (for convenience)) * (unable to use p->defaults.debug since gw_plugin_config * might be part of a larger plugin_config) */ - const time_t cur_ts = log_epoch_secs; + const time_t cur_ts = log_monotonic_secs; gw_exts *exts = conf->exts; for (uint32_t j = 0; j < exts->used; ++j) { gw_extension *ex = exts->exts+j; diff --git a/src/h2.c b/src/h2.c index 5c0c4c96..09ee2480 100644 --- a/src/h2.c +++ b/src/h2.c @@ -1498,7 +1498,7 @@ h2_parse_frames (connection * const con) chunkqueue_mark_written(cq, 9+flen); if (rc <= 0) return 0; - con->read_idle_ts = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; } else if (s[3] == H2_FTYPE_DATA) { /* future: might try to stream data for incomplete frames, @@ -1508,7 +1508,7 @@ h2_parse_frames (connection * const con) * frames, and try to resend if socket buffers are full, this is * probably not a big concern in practice. */ if (cqlen < 9+flen) return 1; /* incomplete frame; go on */ - con->read_idle_ts = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; /*(h2_recv_data() must consume frame from cq or else return 0)*/ if (!h2_recv_data(con, s, flen)) return 0; @@ -1659,7 +1659,7 @@ h2_read_client_connection_preface (struct connection * const con, chunkqueue * c con->network_read = network_read; *hctx = NULL; /*(intentionally update timestamp only after reading preface complete)*/ - con->read_idle_ts = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; } return rc; } @@ -1671,7 +1671,7 @@ h2_init_con (request_st * const restrict h2r, connection * const restrict con, c h2con * const h2c = calloc(1, sizeof(h2con)); force_assert(h2c); con->h2 = h2c; - con->read_idle_ts = log_epoch_secs; + con->read_idle_ts = log_monotonic_secs; con->keep_alive_idle = h2r->conf.max_keep_alive_idle; h2r->h2_rwin = 65535; /* h2 connection recv window */ @@ -1683,7 +1683,7 @@ h2_init_con (request_st * const restrict h2r, connection * const restrict con, c h2c->s_initial_window_size = 65535; /* SETTINGS_INITIAL_WINDOW_SIZE */ h2c->s_max_frame_size = 16384; /* SETTINGS_MAX_FRAME_SIZE */ h2c->s_max_header_list_size = ~0u; /* SETTINGS_MAX_HEADER_LIST_SIZE */ - h2c->sent_settings = log_epoch_secs; /*(send SETTINGS below)*/ + h2c->sent_settings = log_monotonic_secs;/*(send SETTINGS below)*/ lshpack_dec_init(&h2c->decoder); lshpack_enc_init(&h2c->encoder); diff --git a/src/log.c b/src/log.c index facd7af7..98d5555e 100644 --- a/src/log.c +++ b/src/log.c @@ -27,6 +27,7 @@ #endif time_t log_epoch_secs = 0; +time_t log_monotonic_secs = 0; int log_clock_gettime_realtime (struct timespec *ts) { #ifdef HAVE_CLOCK_GETTIME @@ -42,6 +43,14 @@ int log_clock_gettime_realtime (struct timespec *ts) { #endif } +int log_clock_gettime_monotonic (struct timespec *ts) { + #ifdef HAVE_CLOCK_GETTIME + return clock_gettime(CLOCK_MONOTONIC, ts); + #else + return log_clock_gettime_realtime(ts); /*(fallback)*/ + #endif +} + /* retry write on EINTR or when not all data was written */ ssize_t write_all(int fd, const void * const buf, size_t count) { ssize_t written = 0; diff --git a/src/log.h b/src/log.h index b54e7556..9d29cd94 100644 --- a/src/log.h +++ b/src/log.h @@ -6,9 +6,11 @@ #include "buffer.h" extern time_t log_epoch_secs; +extern time_t log_monotonic_secs; struct timespec; /* declaration */ int log_clock_gettime_realtime (struct timespec *ts); +int log_clock_gettime_monotonic (struct timespec *ts); ssize_t write_all(int fd, const void* buf, size_t count); diff --git a/src/mod_accesslog.c b/src/mod_accesslog.c index f8f76df2..441b50c0 100644 --- a/src/mod_accesslog.c +++ b/src/mod_accesslog.c @@ -762,7 +762,7 @@ static void log_access_flush(plugin_data * const p) { TRIGGER_FUNC(log_access_periodic_flush) { /* flush buffered access logs every 4 seconds */ - if (0 == (log_epoch_secs & 3)) log_access_flush((plugin_data *)p_d); + if (0 == (log_monotonic_secs & 3)) log_access_flush((plugin_data *)p_d); UNUSED(srv); return HANDLER_GO_ON; } diff --git a/src/mod_auth.c b/src/mod_auth.c index 03d9daa7..a6de655d 100644 --- a/src/mod_auth.c +++ b/src/mod_auth.c @@ -59,7 +59,7 @@ http_auth_cache_entry_init (const struct http_auth_require_t * const require, co malloc(sizeof(http_auth_cache_entry) + ulen + pwlen); force_assert(ae); ae->require = require; - ae->ctime = log_epoch_secs; + ae->ctime = log_monotonic_secs; ae->dalgo = dalgo; ae->ulen = ulen; ae->dlen = pwlen; @@ -177,7 +177,7 @@ mod_auth_periodic_cleanup(splay_tree **sptree_ptr, const time_t max_age, const t TRIGGER_FUNC(mod_auth_periodic) { const plugin_data * const p = p_d; - const time_t cur_ts = log_epoch_secs; + const time_t cur_ts = log_monotonic_secs; if (cur_ts & 0x7) return HANDLER_GO_ON; /*(continue once each 8 sec)*/ UNUSED(srv); diff --git a/src/mod_magnet_cache.c b/src/mod_magnet_cache.c index 3afdf2a8..9166f0bf 100644 --- a/src/mod_magnet_cache.c +++ b/src/mod_magnet_cache.c @@ -61,8 +61,6 @@ lua_State *script_cache_get_script(script_cache *cache, buffer *name, int etag_f sc = cache->ptr[i]; if (!buffer_is_equal(name, sc->name)) continue; - sc->last_used = log_epoch_secs; - /* oops, the script failed last time */ if (lua_gettop(sc->L) == 0) break; @@ -104,8 +102,6 @@ lua_State *script_cache_get_script(script_cache *cache, buffer *name, int etag_f luaL_openlibs(sc->L); } - sc->last_used = log_epoch_secs; - if (0 != luaL_loadfile(sc->L, name->ptr)) { /* oops, an error, return it */ return sc->L; diff --git a/src/mod_magnet_cache.h b/src/mod_magnet_cache.h index eb9e544c..19b9aa68 100644 --- a/src/mod_magnet_cache.h +++ b/src/mod_magnet_cache.h @@ -12,8 +12,6 @@ typedef struct { buffer *etag; lua_State *L; - - time_t last_used; /* LRU */ } script; typedef struct { diff --git a/src/mod_vhostdb.c b/src/mod_vhostdb.c index e3e32c18..546409df 100644 --- a/src/mod_vhostdb.c +++ b/src/mod_vhostdb.c @@ -54,7 +54,7 @@ vhostdb_cache_entry_init (const buffer * const server_name, const buffer * const const uint32_t dlen = buffer_string_length(docroot); vhostdb_cache_entry * const ve = malloc(sizeof(vhostdb_cache_entry) + slen + dlen); - ve->ctime = log_epoch_secs; + ve->ctime = log_monotonic_secs; ve->slen = slen; ve->dlen = dlen; ve->server_name = (char *)(ve + 1); @@ -359,7 +359,7 @@ mod_vhostdb_periodic_cleanup(splay_tree **sptree_ptr, const time_t max_age, cons TRIGGER_FUNC(mod_vhostdb_periodic) { const plugin_data * const p = p_d; - const time_t cur_ts = log_epoch_secs; + const time_t cur_ts = log_monotonic_secs; if (cur_ts & 0x7) return HANDLER_GO_ON; /*(continue once each 8 sec)*/ UNUSED(srv); diff --git a/src/mod_wstunnel.c b/src/mod_wstunnel.c index 3abc49a7..007ebf43 100644 --- a/src/mod_wstunnel.c +++ b/src/mod_wstunnel.c @@ -360,7 +360,7 @@ static handler_t wstunnel_create_env(gw_handler_ctx *gwhctx) { r->http_status = 101; /* Switching Protocols */ r->resp_body_started = 1; - hctx->ping_ts = log_epoch_secs; + hctx->ping_ts = log_monotonic_secs; gw_set_transparent(&hctx->gw); return HANDLER_GO_ON; @@ -588,7 +588,7 @@ static handler_t mod_wstunnel_check_extension(request_st * const r, void *p_d) { TRIGGER_FUNC(mod_wstunnel_handle_trigger) { const plugin_data * const p = p_d; - const time_t cur_ts = log_epoch_secs + 1; + const time_t cur_ts = log_monotonic_secs + 1; gw_handle_trigger(srv, p_d); diff --git a/src/server.c b/src/server.c index d77fa925..ec448d1c 100644 --- a/src/server.c +++ b/src/server.c @@ -225,6 +225,15 @@ static int daemonize(void) { } #endif +static time_t +server_monotonic_secs (void) +{ + struct timespec ts; + return (0 == log_clock_gettime_realtime(&ts)) + ? ts.tv_sec + : log_monotonic_secs; +} + __attribute_cold__ static server *server_init(void) { server *srv = calloc(1, sizeof(*srv)); @@ -241,6 +250,7 @@ static server *server_init(void) { li_rand_reseed(); srv->startup_ts = log_epoch_secs = time(NULL); + log_monotonic_secs = server_monotonic_secs(); srv->errh = log_error_st_init(); @@ -921,7 +931,7 @@ static void server_graceful_shutdown_maint (server *srv) { if (oneshot_fd) { /* permit keep-alive on one-shot connections until graceful_expire_ts */ if (!srv->graceful_expire_ts) return; - if (srv->graceful_expire_ts >= log_epoch_secs) return; + if (srv->graceful_expire_ts >= log_monotonic_secs) return; } connection_graceful_shutdown_maint(srv); } @@ -936,7 +946,7 @@ static void server_graceful_state (server *srv) { CONST_STR_LEN("server.graceful-shutdown-timeout")); srv->graceful_expire_ts = config_plugin_value_to_int32(du, 0); if (srv->graceful_expire_ts) - srv->graceful_expire_ts += log_epoch_secs; + srv->graceful_expire_ts += log_monotonic_secs; } server_graceful_shutdown_maint(srv); } @@ -1578,6 +1588,7 @@ static int server_main_setup (server * const srv, int argc, char **argv) { if (-1 != (pid = fdevent_waitpid(-1, &status, 0))) { log_epoch_secs = time(NULL); + log_monotonic_secs = server_monotonic_secs(); if (plugins_call_handle_waitpid(srv, pid, status) != HANDLER_GO_ON) { if (!timer) alarm((timer = 5)); continue; @@ -1602,6 +1613,7 @@ static int server_main_setup (server * const srv, int argc, char **argv) { switch (errno) { case EINTR: log_epoch_secs = time(NULL); + log_monotonic_secs = server_monotonic_secs(); /** * if we receive a SIGHUP we have to close our logs ourself as we don't * have the mainloop who can help us here @@ -1620,7 +1632,7 @@ static int server_main_setup (server * const srv, int argc, char **argv) { handle_sig_alarm = 0; timer = 0; plugins_call_handle_trigger(srv); - fdevent_restart_logger_pipes(log_epoch_secs); + fdevent_restart_logger_pipes(log_monotonic_secs); } break; default: @@ -1795,14 +1807,15 @@ static void server_handle_sighup (server * const srv) { } __attribute_noinline__ -static void server_handle_sigalrm (server * const srv, time_t min_ts, time_t last_active_ts) { +static void server_handle_sigalrm (server * const srv, time_t mono_ts, time_t last_active_ts) { plugins_call_handle_trigger(srv); - log_epoch_secs = min_ts; + log_monotonic_secs = mono_ts; + log_epoch_secs = time(NULL); /* check idle time limit, if enabled */ - if (idle_limit && idle_limit < min_ts - last_active_ts && !graceful_shutdown) { + if (idle_limit && idle_limit < mono_ts - last_active_ts && !graceful_shutdown) { log_error(srv->errh, __FILE__, __LINE__, "[note] idle timeout %ds exceeded, " "initiating graceful shutdown", (int)idle_limit); @@ -1816,19 +1829,19 @@ static void server_handle_sigalrm (server * const srv, time_t min_ts, time_t las #ifdef HAVE_GETLOADAVG /* refresh loadavg data every 30 seconds */ - if (srv->loadts + 30 < min_ts) { + if (srv->loadts + 30 < mono_ts) { if (-1 != getloadavg(srv->loadavg, 3)) { - srv->loadts = min_ts; + srv->loadts = mono_ts; } } #endif - if (0 == (min_ts & 0x3f)) { /*(once every 64 secs)*/ + if (0 == (mono_ts & 0x3f)) { /*(once every 64 secs)*/ /* free excess chunkqueue buffers every 64 secs */ chunkqueue_chunk_pool_clear(); /* attempt to restart dead piped loggers every 64 secs */ if (0 == srv->srvconf.max_worker) - fdevent_restart_logger_pipes(min_ts); + fdevent_restart_logger_pipes(mono_ts); } /* cleanup stat-cache */ stat_cache_trigger_cleanup(); @@ -1837,7 +1850,7 @@ static void server_handle_sigalrm (server * const srv, time_t min_ts, time_t las /* if graceful_shutdown, accelerate cleanup of recently completed request/responses */ if (graceful_shutdown && !srv_shutdown) server_graceful_shutdown_maint(srv); - connection_periodic_maint(srv, min_ts); + connection_periodic_maint(srv, mono_ts); } __attribute_noinline__ @@ -1852,7 +1865,7 @@ static void server_handle_sigchld (server * const srv) { } if (0 == srv->srvconf.max_worker) { /* check piped-loggers and restart, even if shutting down */ - if (fdevent_waitpid_logger_pipe_pid(pid, log_epoch_secs)) { + if (fdevent_waitpid_logger_pipe_pid(pid, log_monotonic_secs)) { continue; } } @@ -1873,7 +1886,8 @@ static void server_run_con_queue (connections * const restrict joblist) { __attribute_hot__ __attribute_noinline__ static void server_main_loop (server * const srv) { - time_t last_active_ts = time(NULL); + time_t last_active_ts = server_monotonic_secs(); + log_epoch_secs = time(NULL); while (!srv_shutdown) { @@ -1887,9 +1901,9 @@ static void server_main_loop (server * const srv) { if (handle_sig_alarm) { handle_sig_alarm = 0; #endif - time_t min_ts = time(NULL); - if (min_ts != log_epoch_secs) { - server_handle_sigalrm(srv, min_ts, last_active_ts); + time_t mono_ts = server_monotonic_secs(); + if (mono_ts != log_monotonic_secs) { + server_handle_sigalrm(srv, mono_ts, last_active_ts); } #ifdef USE_ALARM } @@ -1921,7 +1935,7 @@ static void server_main_loop (server * const srv) { connections * const joblist = connection_joblist; if (fdevent_poll(srv->ev, joblist->used ? 0 : 1000) > 0) { - last_active_ts = log_epoch_secs; + last_active_ts = log_monotonic_secs; } connection_joblist = (joblist == &srv->joblist_A) diff --git a/src/stat_cache.c b/src/stat_cache.c index bc87601e..199e89ee 100644 --- a/src/stat_cache.c +++ b/src/stat_cache.c @@ -679,7 +679,7 @@ static fam_dir_entry * fam_dir_monitor(stat_cache_fam *scf, char *fn, uint32_t d /* directory already registered */ } - const time_t cur_ts = log_epoch_secs; + const time_t cur_ts = log_monotonic_secs; struct stat lst; int ck_dir = fn_is_dir; if (!fn_is_dir && (NULL==fam_dir || cur_ts - fam_dir->stat_ts >= 16)) { @@ -1112,7 +1112,7 @@ void stat_cache_update_entry(const char *name, uint32_t len, } sce->st = *st; } - sce->stat_ts = log_epoch_secs; + sce->stat_ts = log_monotonic_secs; } } @@ -1266,7 +1266,7 @@ stat_cache_entry * stat_cache_get_entry(const buffer * const name) { * check if the directory for this file has changed */ - const time_t cur_ts = log_epoch_secs; + const time_t cur_ts = log_monotonic_secs; const int file_ndx = splaytree_djbhash(name->ptr, len); splay_tree *sptree = sc.files = splaytree_splay(sc.files, file_ndx); @@ -1503,7 +1503,7 @@ void stat_cache_trigger_cleanup(void) { #ifdef HAVE_FAM_H if (STAT_CACHE_ENGINE_FAM == sc.stat_cache_engine) { - if (log_epoch_secs & 0x1F) return; + if (log_monotonic_secs & 0x1F) return; /* once every 32 seconds (0x1F == 31) */ max_age = 32; fam_dir_periodic_cleanup(); @@ -1514,5 +1514,5 @@ void stat_cache_trigger_cleanup(void) { } #endif - stat_cache_periodic_cleanup(max_age, log_epoch_secs); + stat_cache_periodic_cleanup(max_age, log_monotonic_secs); }