static void test_timeval_diff(void)
{
static struct timeval input[] = {
{ 1, 0 }, { 0, 999999 },
{ 1, 0 }, { 0, 999001 },
{ 1, 1 }, { 0, 999001 },
{ 2, 1 }, { 1, 0 },
{ INT_MAX, 0 }, { INT_MAX-1, 1 }
};
static int output[] = {
1,
999,
1000,
1000001,
999999
};
unsigned int i;
long long udiff;
int mdiff;
test_begin("timeval_diff_*()");
for (i = 0; i < N_ELEMENTS(input); i += 2) {
udiff = timeval_diff_usecs(&input[i], &input[i+1]);
mdiff = timeval_diff_msecs(&input[i], &input[i+1]);
test_assert(udiff == output[i/2]);
test_assert(mdiff == udiff/1000);
udiff = timeval_diff_usecs(&input[i+1], &input[i]);
mdiff = timeval_diff_msecs(&input[i+1], &input[i]);
test_assert(udiff == -output[i/2]);
test_assert(mdiff == udiff/1000);
}
test_end();
}
static void fts_indexer_notify(struct fts_indexer_context *ctx)
{
unsigned long long elapsed_msecs, est_total_msecs;
unsigned int eta_secs;
if (ioloop_time - ctx->last_notify.tv_sec < INDEXER_NOTIFY_INTERVAL_SECS)
return;
ctx->last_notify = ioloop_timeval;
if (ctx->box->storage->callbacks.notify_ok == NULL ||
ctx->percentage == 0)
return;
elapsed_msecs = timeval_diff_msecs(&ioloop_timeval,
&ctx->search_start_time);
est_total_msecs = elapsed_msecs * 100 / ctx->percentage;
eta_secs = (est_total_msecs - elapsed_msecs) / 1000;
T_BEGIN {
const char *text;
text = t_strdup_printf("Indexed %d%% of the mailbox, "
"ETA %d:%02d", ctx->percentage,
eta_secs/60, eta_secs%60);
ctx->box->storage->callbacks.
notify_ok(ctx->box, text,
ctx->box->storage->callback_context);
ctx->notified = TRUE;
} T_END;
}
bool http_client_request_callback(struct http_client_request *req,
struct http_response *response)
{
http_client_request_callback_t *callback = req->callback;
unsigned int orig_attempts = req->attempts;
req->state = HTTP_REQUEST_STATE_GOT_RESPONSE;
req->callback = NULL;
if (callback != NULL) {
struct http_response response_copy = *response;
if (req->attempts > 0 && !req->preserve_exact_reason) {
unsigned int total_msecs =
timeval_diff_msecs(&ioloop_timeval, &req->submit_time);
response_copy.reason = t_strdup_printf(
"%s (%u attempts in %u.%03u secs)",
response_copy.reason, req->attempts,
total_msecs/1000, total_msecs%1000);
}
callback(&response_copy, req->context);
if (req->attempts != orig_attempts) {
/* retrying */
req->callback = callback;
http_client_request_resubmit(req);
return FALSE;
} else {
/* release payload early (prevents server/client deadlock in proxy) */
if (req->payload_input != NULL)
i_stream_unref(&req->payload_input);
}
}
return TRUE;
}
static unsigned int login_proxy_delay_disconnect(struct login_proxy *proxy)
{
struct login_proxy_record *rec = proxy->state_rec;
const unsigned int max_delay =
proxy->client->set->login_proxy_max_disconnect_delay;
struct timeval disconnect_time_offset;
unsigned int max_disconnects_per_sec, delay_msecs_since_ts, max_conns;
int delay_msecs;
if (rec->num_disconnects_since_ts == 0) {
rec->disconnect_timestamp = ioloop_timeval;
/* start from a slightly random timestamp. this way all proxy
processes will disconnect at slightly different times to
spread the load. */
timeval_add_msecs(&rec->disconnect_timestamp,
rand() % PROXY_DISCONNECT_INTERVAL_MSECS);
}
rec->num_disconnects_since_ts++;
if (proxy->to != NULL) {
/* we were already lazily disconnecting this */
return 0;
}
if (max_delay == 0) {
/* delaying is disabled */
return 0;
}
max_conns = rec->num_proxying_connections + rec->num_disconnects_since_ts;
max_disconnects_per_sec = (max_conns + max_delay-1) / max_delay;
if (rec->num_disconnects_since_ts <= max_disconnects_per_sec &&
rec->num_delayed_client_disconnects == 0) {
/* wait delaying until we have 1 second's worth of clients
disconnected */
return 0;
}
/* see at which time we should be disconnecting the client.
do it in 100ms intervals so the timeouts are triggered together. */
disconnect_time_offset = rec->disconnect_timestamp;
delay_msecs_since_ts = PROXY_DISCONNECT_INTERVAL_MSECS *
(max_delay * rec->num_disconnects_since_ts *
(1000/PROXY_DISCONNECT_INTERVAL_MSECS) / max_conns);
timeval_add_msecs(&disconnect_time_offset, delay_msecs_since_ts);
delay_msecs = timeval_diff_msecs(&disconnect_time_offset, &ioloop_timeval);
if (delay_msecs <= 0) {
/* we already reached the time */
return 0;
}
rec->num_delayed_client_disconnects++;
proxy->delayed_disconnect = TRUE;
proxy->to = timeout_add(delay_msecs, login_proxy_free_final, proxy);
DLLIST_PREPEND(&login_proxies_disconnecting, proxy);
return delay_msecs;
}
static bool session_has_changed(const struct mail_stats *prev,
const struct mail_stats *cur)
{
if (cur->disk_input != prev->disk_input ||
cur->disk_output != prev->disk_output ||
memcmp(&cur->trans_stats, &prev->trans_stats,
sizeof(cur->trans_stats)) != 0)
return TRUE;
/* allow a tiny bit of changes that are caused by this
timeout handling */
if (timeval_diff_msecs(&cur->user_cpu, &prev->user_cpu) != 0)
return TRUE;
if (timeval_diff_msecs(&cur->sys_cpu, &prev->sys_cpu) != 0)
return TRUE;
if (cur->maj_faults > prev->maj_faults+10)
return TRUE;
if (cur->invol_cs > prev->invol_cs+10)
return TRUE;
/* don't check for read/write count/bytes changes, since they get
changed by stats checking itself */
return FALSE;
}
static bool proxy_try_reconnect(struct login_proxy *proxy)
{
int since_started_msecs, left_msecs;
since_started_msecs =
timeval_diff_msecs(&ioloop_timeval, &proxy->created);
if (since_started_msecs < 0)
return FALSE; /* time moved backwards */
left_msecs = proxy->connect_timeout_msecs - since_started_msecs;
if (left_msecs <= 0)
return FALSE;
login_proxy_disconnect(proxy);
proxy->to = timeout_add(I_MIN(PROXY_CONNECT_RETRY_MSECS, left_msecs),
proxy_reconnect_timeout, proxy);
proxy->reconnect_count++;
return TRUE;
}
static void
passwd_check_warnings(struct auth_request *auth_request,
struct passwd_userdb_module *module,
const struct timeval *start_tv)
{
struct timeval end_tv;
unsigned int msecs, percentage;
if (gettimeofday(&end_tv, NULL) < 0)
return;
msecs = timeval_diff_msecs(&end_tv, start_tv);
if (msecs >= PASSWD_SLOW_WARN_MSECS) {
i_warning("passwd: Lookup for %s took %u secs",
auth_request->user, msecs/1000);
return;
}
if (worker || module->slow_warned)
return;
if (msecs < PASSWD_SLOW_MASTER_WARN_MSECS) {
module->fast_count++;
return;
}
module->slow_count++;
if (module->fast_count + module->slow_count <
PASSDB_SLOW_MASTER_WARN_COUNT_INTERVAL)
return;
percentage = module->slow_count * 100 /
(module->slow_count + module->fast_count);
if (percentage < PASSDB_SLOW_MASTER_WARN_MIN_PERCENTAGE) {
/* start from beginning */
module->slow_count = module->fast_count = 0;
} else {
i_warning("passwd: %u%% of last %u lookups took over "
"%u milliseconds, "
"you may want to set blocking=yes for userdb",
percentage, PASSDB_SLOW_MASTER_WARN_COUNT_INTERVAL,
PASSWD_SLOW_MASTER_WARN_MSECS);
module->slow_warned = TRUE;
}
}
void client_send_tagline(struct client_command_context *cmd, const char *data)
{
struct client *client = cmd->client;
const char *tag = cmd->tag;
int time_msecs;
if (client->output->closed || cmd->cancel)
return;
i_assert(!cmd->tagline_sent);
cmd->tagline_sent = TRUE;
if (tag == NULL || *tag == '\0')
tag = "*";
T_BEGIN {
string_t *str = t_str_new(256);
str_printfa(str, "%s %s", tag, data);
if (cmd->start_time.tv_sec != 0) {
if (str_data(str)[str_len(str)-1] == '.')
str_truncate(str, str_len(str)-1);
io_loop_time_refresh();
time_msecs = timeval_diff_msecs(&ioloop_timeval,
&cmd->start_time);
time_msecs -= cmd->usecs_in_ioloop/1000;
if (time_msecs >= 0) {
str_printfa(str, " (%d.%03d secs).",
time_msecs/1000, time_msecs%1000);
}
}
str_append(str, "\r\n");
o_stream_nsend(client->output, str_data(str), str_len(str));
} T_END;
client->last_output = ioloop_time;
}
