From 8cc4b7874ed84802406575df8c447bb0bb525f34 Mon Sep 17 00:00:00 2001 From: Claudiu Boriga Date: Thu, 18 Jan 2018 09:52:59 +0100 Subject: [PATCH] Add statistics for requests per second --- daemon/call.c | 35 +++++++++++++++++++++++++++++++++++ daemon/cli.c | 25 +++++++++++++++++++++++++ daemon/control_ng.c | 6 ++++++ daemon/graphite.c | 41 +++++++++++++++++++++++++++++++++++++++++ daemon/statistics.h | 12 ++++++++++++ 5 files changed, 119 insertions(+) diff --git a/daemon/call.c b/daemon/call.c index 54a1da980..d0f11ddf2 100644 --- a/daemon/call.c +++ b/daemon/call.c @@ -460,6 +460,24 @@ destroy: atomic64_add(&ps->stats.x, d); \ atomic64_add(&m->statsps.x, d); \ } while (0) + +static void update_requests_per_second_stats(struct requests_ps *request, u_int64_t new_val) { + mutex_lock(&request->lock); + + request->count++; + request->ps_avg += new_val; + + if ((request->ps_min == 0) || (request->ps_min > new_val)) { + request->ps_min = new_val; + } + + if ((request->ps_max == 0) || (request->ps_max < new_val)) { + request->ps_max = new_val; + } + + mutex_unlock(&request->lock); +} + static void callmaster_timer(void *ptr) { struct callmaster *m = ptr; struct iterator_helper hlp; @@ -472,6 +490,7 @@ static void callmaster_timer(void *ptr) { struct rtp_stats *rs; unsigned int pt; endpoint_t ep; + int offers, answers, deletes; ZERO(hlp); hlp.addr_sfd = g_hash_table_new(g_endpoint_hash, g_endpoint_eq); @@ -498,6 +517,19 @@ static void callmaster_timer(void *ptr) { atomic64_set(&m->stats.packets, atomic64_get_na(&tmpstats.packets)); atomic64_set(&m->stats.errors, atomic64_get_na(&tmpstats.errors)); + /* update statistics regarding requests per second */ + offers = atomic64_get(&m->statsps.offers); + atomic64_set(&m->statsps.offers, 0); + update_requests_per_second_stats(&m->totalstats_interval.offers_ps, offers); + + answers = atomic64_get(&m->statsps.answers); + atomic64_set(&m->statsps.answers, 0); + update_requests_per_second_stats(&m->totalstats_interval.answers_ps, answers); + + deletes = atomic64_get(&m->statsps.deletes); + atomic64_set(&m->statsps.deletes, 0); + update_requests_per_second_stats(&m->totalstats_interval.deletes_ps, deletes); + i = kernel_list(); while (i) { ke = i->data; @@ -642,6 +674,9 @@ struct callmaster *callmaster_new(struct poller *p) { mutex_init(&c->cngs_lock); c->cngs_hash = g_hash_table_new(g_sockaddr_hash, g_sockaddr_eq); + mutex_init(&c->totalstats_interval.offers_ps.lock); + mutex_init(&c->totalstats_interval.answers_ps.lock); + mutex_init(&c->totalstats_interval.deletes_ps.lock); return c; fail: diff --git a/daemon/cli.c b/daemon/cli.c index 8ea48eaa5..7613b25dc 100644 --- a/daemon/cli.c +++ b/daemon/cli.c @@ -94,6 +94,7 @@ static void cli_incoming_list_totals(char* buffer, int len, struct callmaster* m struct timeval avg, calls_dur_iv; u_int64_t num_sessions, min_sess_iv, max_sess_iv; struct request_time offer_iv, answer_iv, delete_iv; + struct requests_ps offers_ps, answers_ps, deletes_ps; mutex_lock(&m->totalstats.total_average_lock); avg = m->totalstats.total_average_call_dur; @@ -136,12 +137,19 @@ static void cli_incoming_list_totals(char* buffer, int len, struct callmaster* m offer_iv = m->totalstats_lastinterval.offer; answer_iv = m->totalstats_lastinterval.answer; delete_iv = m->totalstats_lastinterval.delete; + offers_ps = m->totalstats_lastinterval.offers_ps; + answers_ps = m->totalstats_lastinterval.answers_ps; + deletes_ps = m->totalstats_lastinterval.deletes_ps; mutex_unlock(&m->totalstats_lastinterval_lock); // compute average offer/answer/delete time timeval_divide(&offer_iv.time_avg, &offer_iv.time_avg, offer_iv.count); timeval_divide(&answer_iv.time_avg, &answer_iv.time_avg, answer_iv.count); timeval_divide(&delete_iv.time_avg, &delete_iv.time_avg, delete_iv.count); + //compute average offers/answers/deletes per second + offers_ps.ps_avg = (offers_ps.count?(offers_ps.ps_avg/offers_ps.count):0); + answers_ps.ps_avg = (answers_ps.count?(answers_ps.ps_avg/answers_ps.count):0); + deletes_ps.ps_avg = (deletes_ps.count?(deletes_ps.ps_avg/deletes_ps.count):0); printlen = snprintf(replybuffer,(outbufend-replybuffer), "\nGraphite interval statistics (last reported values to graphite):\n"); ADJUSTLEN(printlen,outbufend,replybuffer); @@ -167,6 +175,23 @@ static void cli_incoming_list_totals(char* buffer, int len, struct callmaster* m (unsigned long long)delete_iv.time_avg.tv_sec,(unsigned long long)delete_iv.time_avg.tv_usec); ADJUSTLEN(printlen,outbufend,replybuffer); + printlen = snprintf(replybuffer,(outbufend-replybuffer), " Min/Max/Avg offer requests per second :%llu/%llu/%llu per sec\n", + (unsigned long long)offers_ps.ps_min, + (unsigned long long)offers_ps.ps_max, + (unsigned long long)offers_ps.ps_avg); + ADJUSTLEN(printlen,outbufend,replybuffer); + printlen = snprintf(replybuffer,(outbufend-replybuffer), " Min/Max/Avg answer requests per second :%llu/%llu/%llu per sec\n", + (unsigned long long)answers_ps.ps_min, + (unsigned long long)answers_ps.ps_max, + (unsigned long long)answers_ps.ps_avg); + ADJUSTLEN(printlen,outbufend,replybuffer); + printlen = snprintf(replybuffer,(outbufend-replybuffer), " Min/Max/Avg delete requests per second :%llu/%llu/%llu per sec\n", + (unsigned long long)deletes_ps.ps_min, + (unsigned long long)deletes_ps.ps_max, + (unsigned long long)deletes_ps.ps_avg); + ADJUSTLEN(printlen,outbufend,replybuffer); + + printlen = snprintf(replybuffer,(outbufend-replybuffer), "\n\n"); ADJUSTLEN(printlen,outbufend,replybuffer); diff --git a/daemon/control_ng.c b/daemon/control_ng.c index c956be322..fdb1f4574 100644 --- a/daemon/control_ng.c +++ b/daemon/control_ng.c @@ -176,6 +176,7 @@ static void control_ng_incoming(struct obj *obj, str *buf, const endpoint_t *sin g_atomic_int_inc(&cur->ping); } else if (!str_cmp(&cmd, "offer")) { + //TODO inc offers per second // start offer timer gettimeofday(&offer_start, NULL); @@ -188,8 +189,10 @@ static void control_ng_incoming(struct obj *obj, str *buf, const endpoint_t *sin // print offer duration timeval_from_us(&offer_stop, timeval_diff(&offer_stop, &offer_start)); ilog(LOG_INFO, "offer time = %llu.%06llu sec", (unsigned long long)offer_stop.tv_sec, (unsigned long long)offer_stop.tv_usec); + atomic64_inc(&c->callmaster->statsps.offers); } else if (!str_cmp(&cmd, "answer")) { + //TODO inc answers per second // start answer timer gettimeofday(&answer_start, NULL); @@ -202,8 +205,10 @@ static void control_ng_incoming(struct obj *obj, str *buf, const endpoint_t *sin // print answer duration timeval_from_us(&answer_stop, timeval_diff(&answer_stop, &answer_start)); ilog(LOG_INFO, "answer time = %llu.%06llu sec", (unsigned long long)answer_stop.tv_sec, (unsigned long long)answer_stop.tv_usec); + atomic64_inc(&c->callmaster->statsps.answers); } else if (!str_cmp(&cmd, "delete")) { + //TODO inc deletes per second // start delete timer gettimeofday(&delete_start, NULL); @@ -216,6 +221,7 @@ static void control_ng_incoming(struct obj *obj, str *buf, const endpoint_t *sin // print delete duration timeval_from_us(&delete_stop, timeval_diff(&delete_stop, &delete_start)); ilog(LOG_INFO, "delete time = %llu.%06llu sec", (unsigned long long)delete_stop.tv_sec, (unsigned long long)delete_stop.tv_usec); + atomic64_inc(&c->callmaster->statsps.deletes); } else if (!str_cmp(&cmd, "query")) { errstr = call_query_ng(dict, c->callmaster, resp); diff --git a/daemon/graphite.c b/daemon/graphite.c index 4003d5eb0..25f5f1867 100644 --- a/daemon/graphite.c +++ b/daemon/graphite.c @@ -38,6 +38,18 @@ void set_prefix(char* prefix) { graphite_prefix = prefix; } +static struct requests_ps clear_requests_per_second(struct requests_ps *requests) { + struct requests_ps ret; + mutex_lock(&requests->lock); + ret = *requests; + requests->count=0; + requests->ps_max = 0; + requests->ps_min = 0; + requests->ps_avg = 0; + mutex_unlock(&requests->lock); + return ret; +} + static struct request_time timeval_clear_request_time(struct request_time *request) { struct request_time ret; @@ -131,6 +143,10 @@ int send_graphite_data(struct callmaster *cm, struct totalstats *sent_data) { ts->answer = timeval_clear_request_time(&cm->totalstats_interval.answer); ts->delete = timeval_clear_request_time(&cm->totalstats_interval.delete); + ts->offers_ps = clear_requests_per_second(&cm->totalstats_interval.offers_ps); + ts->answers_ps = clear_requests_per_second(&cm->totalstats_interval.answers_ps); + ts->deletes_ps = clear_requests_per_second(&cm->totalstats_interval.deletes_ps); + rwlock_lock_r(&cm->hashlock); mutex_lock(&cm->totalstats_interval.managed_sess_lock); ts->managed_sess_max = cm->totalstats_interval.managed_sess_max; @@ -147,6 +163,10 @@ int send_graphite_data(struct callmaster *cm, struct totalstats *sent_data) { timeval_divide(&ts->offer.time_avg, &ts->offer.time_avg, ts->offer.count); timeval_divide(&ts->answer.time_avg, &ts->answer.time_avg, ts->answer.count); timeval_divide(&ts->delete.time_avg, &ts->delete.time_avg, ts->delete.count); + //compute average offers/answers/deletes per second + ts->offers_ps.ps_avg = (ts->offers_ps.count?(ts->offers_ps.ps_avg/ts->offers_ps.count):0); + ts->answers_ps.ps_avg = (ts->answers_ps.count?(ts->answers_ps.ps_avg/ts->answers_ps.count):0); + ts->deletes_ps.ps_avg = (ts->deletes_ps.count?(ts->deletes_ps.ps_avg/ts->deletes_ps.count):0); if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } rc = sprintf(ptr,"offer_time_min %llu.%06llu %llu\n",(unsigned long long)ts->offer.time_min.tv_sec,(unsigned long long)ts->offer.time_min.tv_usec,(unsigned long long)g_now.tv_sec); ptr += rc; @@ -206,6 +226,27 @@ int send_graphite_data(struct callmaster *cm, struct totalstats *sent_data) { if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } rc = sprintf(ptr,"reject_sess "UINT64F" %llu\n", atomic64_get_na(&ts->total_rejected_sess),(unsigned long long)g_now.tv_sec); ptr += rc; + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"offers_ps_min %llu %llu\n",(unsigned long long)ts->offers_ps.ps_min,(unsigned long long)g_now.tv_sec); ptr += rc; + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"offers_ps_max %llu %llu\n",(unsigned long long)ts->offers_ps.ps_max,(unsigned long long)g_now.tv_sec); ptr += rc; + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"offers_ps_avg %llu %llu\n",(unsigned long long)ts->offers_ps.ps_avg,(unsigned long long)g_now.tv_sec); ptr += rc; + + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"answers_ps_min %llu %llu\n",(unsigned long long)ts->answers_ps.ps_min,(unsigned long long)g_now.tv_sec); ptr += rc; + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"answers_ps_max %llu %llu\n",(unsigned long long)ts->answers_ps.ps_max,(unsigned long long)g_now.tv_sec); ptr += rc; + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"answers_ps_avg %llu %llu\n",(unsigned long long)ts->answers_ps.ps_avg,(unsigned long long)g_now.tv_sec); ptr += rc; + + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"deletes_ps_min %llu %llu\n",(unsigned long long)ts->deletes_ps.ps_min,(unsigned long long)g_now.tv_sec); ptr += rc; + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"deletes_ps_max %llu %llu\n",(unsigned long long)ts->deletes_ps.ps_max,(unsigned long long)g_now.tv_sec); ptr += rc; + if (graphite_prefix!=NULL) { rc = sprintf(ptr,"%s",graphite_prefix); ptr += rc; } + rc = sprintf(ptr,"deletes_ps_avg %llu %llu\n",(unsigned long long)ts->deletes_ps.ps_avg,(unsigned long long)g_now.tv_sec); ptr += rc; + ilog(LOG_DEBUG, "min_sessions:%llu max_sessions:%llu, call_dur_per_interval:%llu.%06llu at time %llu\n", (unsigned long long) ts->managed_sess_min, (unsigned long long) ts->managed_sess_max, diff --git a/daemon/statistics.h b/daemon/statistics.h index 333a1e7ba..42311b2da 100644 --- a/daemon/statistics.h +++ b/daemon/statistics.h @@ -12,6 +12,9 @@ struct stats { u_int64_t delay_max; u_int8_t in_tos_tclass; /* XXX shouldn't be here - not stats */ atomic64 foreign_sessions; // unresponsible via redis notification + atomic64 offers; + atomic64 answers; + atomic64 deletes; }; @@ -21,6 +24,14 @@ struct request_time { struct timeval time_min, time_max, time_avg; }; +struct requests_ps { + mutex_t lock; + u_int64_t count; + u_int64_t ps_min; + u_int64_t ps_max; + u_int64_t ps_avg; +}; + struct totalstats { time_t started; @@ -52,6 +63,7 @@ struct totalstats { struct timeval total_calls_duration_interval; struct request_time offer, answer, delete; + struct requests_ps offers_ps, answers_ps, deletes_ps; }; struct rtp_stats {