static void rspamd_symbols_cache_resort_cb (gint fd, short what, gpointer ud) { struct timeval tv; gdouble tm; struct symbols_cache *cache = ud; struct cache_item *item, *parent; guint i; /* Plan new event */ tm = rspamd_time_jitter (cache->reload_time, 0); msg_debug_cache ("resort symbols cache, next reload in %.2f seconds", tm); g_assert (cache != NULL); evtimer_set (&cache->resort_ev, rspamd_symbols_cache_resort_cb, cache); double_to_tv (tm, &tv); event_add (&cache->resort_ev, &tv); rspamd_mempool_lock_mutex (cache->mtx); /* Gather stats from shared execution times */ for (i = 0; i < cache->items_by_id->len; i ++) { item = g_ptr_array_index (cache->items_by_id, i); if (item->type & (SYMBOL_TYPE_CALLBACK|SYMBOL_TYPE_NORMAL)) { if (item->cd->number > 0) { item->avg_counter += item->cd->number + 1; item->avg_time = item->avg_time + (item->cd->value - item->avg_time) / (gdouble)item->avg_counter; item->cd->value = item->avg_time; item->cd->number = item->avg_counter; } } } /* Sync virtual symbols */ for (i = 0; i < cache->items_by_id->len; i ++) { item = g_ptr_array_index (cache->items_by_id, i); if (item->parent != -1) { parent = g_ptr_array_index (cache->items_by_id, item->parent); if (parent) { item->avg_time = parent->avg_time; item->avg_counter = parent->avg_counter; } } } rspamd_mempool_unlock_mutex (cache->mtx); rspamd_symbols_cache_resort (cache); }
void rspamd_common_logv (rspamd_logger_t *rspamd_log, GLogLevelFlags log_level, const gchar *module, const gchar *id, const gchar *function, const gchar *fmt, va_list args) { gchar logbuf[RSPAMD_LOGBUF_SIZE]; if (rspamd_log == NULL) { rspamd_log = default_logger; } if (rspamd_log == NULL) { /* Just fprintf message to stderr */ if (log_level >= G_LOG_LEVEL_INFO) { rspamd_vsnprintf (logbuf, sizeof (logbuf), fmt, args); rspamd_escape_log_string (logbuf); fprintf (stderr, "%s\n", logbuf); } } else { if (rspamd_logger_need_log (rspamd_log, log_level, module)) { rspamd_vsnprintf (logbuf, sizeof (logbuf), fmt, args); rspamd_escape_log_string (logbuf); rspamd_mempool_lock_mutex (rspamd_log->mtx); rspamd_log->log_func (NULL, module, id, function, log_level, logbuf, FALSE, rspamd_log); rspamd_mempool_unlock_mutex (rspamd_log->mtx); } switch (log_level) { case G_LOG_LEVEL_CRITICAL: rspamd_log->log_cnt[0] ++; break; case G_LOG_LEVEL_WARNING: rspamd_log->log_cnt[1]++; break; case G_LOG_LEVEL_INFO: rspamd_log->log_cnt[2]++; break; case G_LOG_LEVEL_DEBUG: rspamd_log->log_cnt[3]++; break; default: break; } } }
/** * Set counter for a symbol */ static double rspamd_set_counter (struct cache_item *item, guint32 value) { struct counter_data *cd; double alpha; cd = item->cd; /* Calculate new value */ rspamd_mempool_lock_mutex (item->mtx); alpha = 2. / (++cd->number + 1); cd->value = cd->value * (1. - alpha) + value * alpha; rspamd_mempool_unlock_mutex (item->mtx); return cd->value; }
/** * Wrapper for glib logger */ void rspamd_glib_log_function (const gchar *log_domain, GLogLevelFlags log_level, const gchar *message, gpointer arg) { rspamd_logger_t *rspamd_log = arg; if (rspamd_log->enabled && rspamd_logger_need_log (rspamd_log, log_level, NULL)) { rspamd_mempool_lock_mutex (rspamd_log->mtx); rspamd_log->log_func (log_domain, "glib", NULL, NULL, log_level, message, FALSE, rspamd_log); rspamd_mempool_unlock_mutex (rspamd_log->mtx); } }
/** * Write log line depending on ip */ void rspamd_conditional_debug (rspamd_logger_t *rspamd_log, rspamd_inet_addr_t *addr, const gchar *module, const gchar *id, const gchar *function, const gchar *fmt, ...) { static gchar logbuf[BUFSIZ]; va_list vp; u_char *end; if (rspamd_log == NULL) { rspamd_log = default_logger; } if (rspamd_logger_need_log (rspamd_log, G_LOG_LEVEL_DEBUG, module) || rspamd_log->is_debug) { if (rspamd_log->debug_ip && addr != NULL) { if (radix_find_compressed_addr (rspamd_log->debug_ip, addr) == RADIX_NO_VALUE) { return; } } rspamd_mempool_lock_mutex (rspamd_log->mtx); va_start (vp, fmt); end = rspamd_vsnprintf (logbuf, sizeof (logbuf), fmt, vp); *end = '\0'; rspamd_escape_log_string (logbuf); va_end (vp); rspamd_log->log_func (NULL, module, id, function, G_LOG_LEVEL_DEBUG, logbuf, TRUE, rspamd_log); rspamd_mempool_unlock_mutex (rspamd_log->mtx); } }
void rspamd_http_test_func (void) { struct event_base *ev_base = event_init (); rspamd_mempool_t *pool = rspamd_mempool_new (rspamd_mempool_suggest_size ()); gpointer serv_key, client_key, peer_key; struct rspamd_keypair_cache *c; rspamd_mempool_mutex_t *mtx; rspamd_inet_addr_t addr; struct timespec ts1, ts2; gchar filepath[PATH_MAX], buf[512]; gint fd, i, j; pid_t sfd; GString *b32_key; double diff, total_diff = 0.0, latency[pconns * ntests], mean, std; rspamd_cryptobox_init (); rspamd_snprintf (filepath, sizeof (filepath), "/tmp/http-test-XXXXXX"); g_assert ((fd = mkstemp (filepath)) != -1); for (i = 0; i < file_blocks; i ++) { memset (buf, 0, sizeof (buf)); g_assert (write (fd, buf, sizeof (buf)) == sizeof (buf)); } mtx = rspamd_mempool_get_mutex (pool); rspamd_parse_inet_address (&addr, "127.0.0.1"); rspamd_inet_address_set_port (&addr, ottery_rand_range (30000) + 32768); serv_key = rspamd_http_connection_gen_key (); client_key = rspamd_http_connection_gen_key (); c = rspamd_keypair_cache_new (16); rspamd_mempool_lock_mutex (mtx); sfd = fork (); g_assert (sfd != -1); if (sfd == 0) { rspamd_http_server_func ("/tmp/", &addr, mtx, serv_key, c); exit (EXIT_SUCCESS); } rspamd_mempool_lock_mutex (mtx); /* Do client stuff */ for (i = 0; i < ntests; i ++) { for (j = 0; j < pconns; j ++) { rspamd_http_client_func (filepath + sizeof ("/tmp") - 1, &addr, NULL, NULL, c, ev_base, &latency[i * pconns + j]); } clock_gettime (CLOCK_MONOTONIC, &ts1); event_base_loop (ev_base, 0); clock_gettime (CLOCK_MONOTONIC, &ts2); diff = (ts2.tv_sec - ts1.tv_sec) * 1000. + /* Seconds */ (ts2.tv_nsec - ts1.tv_nsec) / 1000000.; /* Nanoseconds */ total_diff += diff; } msg_info ("Made %d connections of size %d in %.6f ms, %.6f cps", ntests * pconns, sizeof (buf) * file_blocks, total_diff, ntests * pconns / total_diff * 1000.); mean = rspamd_http_calculate_mean (latency, &std); msg_info ("Latency: %.6f ms mean, %.6f dev", mean, std); /* Now test encrypted */ b32_key = rspamd_http_connection_print_key (serv_key, RSPAMD_KEYPAIR_PUBKEY|RSPAMD_KEYPAIR_BASE32); g_assert (b32_key != NULL); peer_key = rspamd_http_connection_make_peer_key (b32_key->str); g_assert (peer_key != NULL); total_diff = 0.0; for (i = 0; i < ntests; i ++) { for (j = 0; j < pconns; j ++) { rspamd_http_client_func (filepath + sizeof ("/tmp") - 1, &addr, client_key, peer_key, c, ev_base, &latency[i * pconns + j]); } clock_gettime (CLOCK_MONOTONIC, &ts1); event_base_loop (ev_base, 0); clock_gettime (CLOCK_MONOTONIC, &ts2); diff = (ts2.tv_sec - ts1.tv_sec) * 1000. + /* Seconds */ (ts2.tv_nsec - ts1.tv_nsec) / 1000000.; /* Nanoseconds */ total_diff += diff; } msg_info ("Made %d encrypted connections of size %d in %.6f ms, %.6f cps", ntests * pconns, sizeof (buf) * file_blocks, total_diff, ntests * pconns / total_diff * 1000.); mean = rspamd_http_calculate_mean (latency, &std); msg_info ("Latency: %.6f ms mean, %.6f dev", mean, std); /* Restart server */ kill (sfd, SIGTERM); wait (&i); sfd = fork (); g_assert (sfd != -1); if (sfd == 0) { rspamd_http_server_func ("/tmp/", &addr, mtx, serv_key, NULL); exit (EXIT_SUCCESS); } rspamd_mempool_lock_mutex (mtx); total_diff = 0.0; for (i = 0; i < ntests; i ++) { for (j = 0; j < pconns; j ++) { rspamd_http_client_func (filepath + sizeof ("/tmp") - 1, &addr, client_key, peer_key, c, ev_base, &latency[i * pconns + j]); } clock_gettime (CLOCK_MONOTONIC, &ts1); event_base_loop (ev_base, 0); clock_gettime (CLOCK_MONOTONIC, &ts2); diff = (ts2.tv_sec - ts1.tv_sec) * 1000. + /* Seconds */ (ts2.tv_nsec - ts1.tv_nsec) / 1000000.; /* Nanoseconds */ total_diff += diff; } msg_info ("Made %d uncached encrypted connections of size %d in %.6f ms, %.6f cps", ntests * pconns, sizeof (buf) * file_blocks, total_diff, ntests * pconns / total_diff * 1000.); mean = rspamd_http_calculate_mean (latency, &std); msg_info ("Latency: %.6f ms mean, %.6f dev", mean, std); close (fd); unlink (filepath); kill (sfd, SIGTERM); }
/* * Write a line to log file (unbuffered) */ static void direct_write_log_line (rspamd_logger_t *rspamd_log, void *data, gsize count, gboolean is_iov) { gchar errmsg[128]; struct iovec *iov; const gchar *line; glong r; if (rspamd_log->enabled) { if (!rspamd_log->no_lock) { #ifndef DISABLE_PTHREAD_MUTEX if (rspamd_log->mtx) { rspamd_mempool_lock_mutex (rspamd_log->mtx); } else { rspamd_file_lock (rspamd_log->fd, FALSE); } #else rspamd_file_lock (rspamd_log->fd, FALSE); #endif } if (is_iov) { iov = (struct iovec *) data; r = writev (rspamd_log->fd, iov, count); } else { line = (const gchar *) data; r = write (rspamd_log->fd, line, count); } if (!rspamd_log->no_lock) { #ifndef DISABLE_PTHREAD_MUTEX if (rspamd_log->mtx) { rspamd_mempool_unlock_mutex (rspamd_log->mtx); } else { rspamd_file_unlock (rspamd_log->fd, FALSE); } #else rspamd_file_unlock (rspamd_log->fd, FALSE); #endif } if (r == -1) { /* We cannot write message to file, so we need to detect error and make decision */ if (errno == EINTR) { /* Try again */ direct_write_log_line (rspamd_log, data, count, is_iov); return; } r = rspamd_snprintf (errmsg, sizeof (errmsg), "direct_write_log_line: cannot write log line: %s", strerror (errno)); if (errno == EFAULT || errno == EINVAL || errno == EFBIG || errno == ENOSPC) { /* Rare case */ rspamd_log->throttling = TRUE; rspamd_log->throttling_time = time (NULL); } else if (errno == EPIPE || errno == EBADF) { /* We write to some pipe and it disappears, disable logging or we has opened bad file descriptor */ rspamd_log->enabled = FALSE; } } else if (rspamd_log->throttling) { rspamd_log->throttling = FALSE; } } }