Merge branch 'dev-measuredelay-full' into dev-fmetz

Conflicts:
	daemon/call.c
	daemon/call.h
	daemon/cli.c
	daemon/kernel.c
	daemon/main.c
	kernel-module/xt_RTPENGINE.c
	kernel-module/xt_RTPENGINE.h

daemon/call.c

@@ -32,7 +32,7 @@
 #include "rtcp.h"
 #include "rtp.h"
 #include "call_interfaces.h"
-
+#include "rtpengine_config.h"
 
 
 
@@ -1344,6 +1344,14 @@ static void callmaster_timer(void *ptr) {
 		DS(bytes);
 		DS(errors);
 
+#if (RE_HAS_MEASUREDELAY)
+		mutex_lock(&m->statspslock);
+		ps->stats.delay_min = m->statsps.delay_min = ke->stats.delay_min;
+		ps->stats.delay_avg = m->statsps.delay_avg = ke->stats.delay_avg;
+		ps->stats.delay_max = m->statsps.delay_max = ke->stats.delay_max;
+		mutex_unlock(&m->statspslock);
+#endif
+
 		mutex_lock(&ps->in_lock);
 
 		if (ke->stats.packets != ps->kernel_stats.packets)
@@ -1353,6 +1361,12 @@ static void callmaster_timer(void *ptr) {
 		ps->kernel_stats.bytes = ke->stats.bytes;
 		ps->kernel_stats.errors = ke->stats.errors;
 
+#if (RE_HAS_MEASUREDELAY)
+		ps->kernel_stats.delay_min = ke->stats.delay_min;
+		ps->kernel_stats.delay_avg = ke->stats.delay_avg;
+		ps->kernel_stats.delay_max = ke->stats.delay_max;
+#endif
+
 		update = 0;
 
 		sink = packet_stream_sink(ps);
@@ -2487,21 +2501,63 @@ void call_destroy(struct call *c) {
 
 				if (_log_facility_cdr) {
 				    const char* protocol = (!PS_ISSET(ps, RTP) && PS_ISSET(ps, RTCP)) ? "rtcp" : "rtp";
-				    cdrbufcur += sprintf(cdrbufcur,
-				            "ml%i_midx%u_%s_endpoint_ip=%s, "
-				            "ml%i_midx%u_%s_endpoint_port=%u, "
-				            "ml%i_midx%u_%s_local_relay_port=%u, "
-				            "ml%i_midx%u_%s_relayed_packets=%llu, "
-				            "ml%i_midx%u_%s_relayed_bytes=%llu, "
-				            "ml%i_midx%u_%s_relayed_errors=%llu, "
-				            "ml%i_midx%u_%s_last_packet=%llu, ",
-				            cdrlinecnt, md->index, protocol, addr,
-				            cdrlinecnt, md->index, protocol, ps->endpoint.port,
-				            cdrlinecnt, md->index, protocol, (unsigned int) (ps->sfd ? ps->sfd->fd.localport : 0),
-				            cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.packets,
-				            cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.bytes,
-				            cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.errors,
-				            cdrlinecnt, md->index, protocol, (unsigned long long) ps->last_packet);
+				    if(!PS_ISSET(ps, RTP) && PS_ISSET(ps, RTCP)) {
+				    	cdrbufcur += sprintf(cdrbufcur,
+				    			"ml%i_midx%u_%s_endpoint_ip=%s, "
+				    			"ml%i_midx%u_%s_endpoint_port=%u, "
+				    			"ml%i_midx%u_%s_local_relay_port=%u, "
+				    			"ml%i_midx%u_%s_relayed_packets=%llu, "
+				    			"ml%i_midx%u_%s_relayed_bytes=%llu, "
+				    			"ml%i_midx%u_%s_relayed_errors=%llu, "
+				    			"ml%i_midx%u_%s_last_packet=%llu, ",
+								cdrlinecnt, md->index, protocol, addr,
+								cdrlinecnt, md->index, protocol, ps->endpoint.port,
+								cdrlinecnt, md->index, protocol, (unsigned int) (ps->sfd ? ps->sfd->fd.localport : 0),
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.packets,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.bytes,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.errors,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->last_packet);
+				    } else {
+#if (RE_HAS_MEASUREDELAY)
+				    	cdrbufcur += sprintf(cdrbufcur,
+				    			"ml%i_midx%u_%s_endpoint_ip=%s, "
+				    			"ml%i_midx%u_%s_endpoint_port=%u, "
+				    			"ml%i_midx%u_%s_local_relay_port=%u, "
+				    			"ml%i_midx%u_%s_relayed_packets=%llu, "
+				    			"ml%i_midx%u_%s_relayed_bytes=%llu, "
+				    			"ml%i_midx%u_%s_relayed_errors=%llu, "
+				    			"ml%i_midx%u_%s_last_packet=%llu, "
+				    			"ml%i_midx%u_%s_delay_min=%llu.%09llu, "
+				    			"ml%i_midx%u_%s_delay_avg=%llu.%09llu, "
+				    			"ml%i_midx%u_%s_delay_max=%llu.%09llu, ",
+								cdrlinecnt, md->index, protocol, addr,
+								cdrlinecnt, md->index, protocol, ps->endpoint.port,
+								cdrlinecnt, md->index, protocol, (unsigned int) (ps->sfd ? ps->sfd->fd.localport : 0),
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.packets,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.bytes,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.errors,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->last_packet,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.delay_min.tv_sec, (unsigned long long) ps->stats.delay_min.tv_nsec,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.delay_avg.tv_sec, (unsigned long long) ps->stats.delay_avg.tv_nsec,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.delay_max.tv_sec, (unsigned long long) ps->stats.delay_max.tv_nsec);
+#else
+				    	cdrbufcur += sprintf(cdrbufcur,
+				    			"ml%i_midx%u_%s_endpoint_ip=%s, "
+				    			"ml%i_midx%u_%s_endpoint_port=%u, "
+				    			"ml%i_midx%u_%s_local_relay_port=%u, "
+				    			"ml%i_midx%u_%s_relayed_packets=%llu, "
+				    			"ml%i_midx%u_%s_relayed_bytes=%llu, "
+				    			"ml%i_midx%u_%s_relayed_errors=%llu, "
+				    			"ml%i_midx%u_%s_last_packet=%llu, ",
+								cdrlinecnt, md->index, protocol, addr,
+								cdrlinecnt, md->index, protocol, ps->endpoint.port,
+								cdrlinecnt, md->index, protocol, (unsigned int) (ps->sfd ? ps->sfd->fd.localport : 0),
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.packets,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.bytes,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->stats.errors,
+								cdrlinecnt, md->index, protocol, (unsigned long long) ps->last_packet);
+#endif
+				    }
 				}
 
 				ilog(LOG_INFO, "------ Media #%u, port %5u <> %15s:%-5hu%s, "

daemon/call.h

@@ -190,6 +190,9 @@ struct stats {
 	u_int64_t			packets;
 	u_int64_t			bytes;
 	u_int64_t			errors;
+	struct timespec		delay_min;
+	struct timespec		delay_avg;
+	struct timespec		delay_max;
 };
 
 struct totalstats {

daemon/cli.c

@@ -14,6 +14,7 @@
 #include "call.h"
 #include "cli.h"
 
+#include "rtpengine_config.h"
 
 static const char* TRUNCATED = "    ... Output truncated. Increase Output Buffer ...\n";
 
@@ -147,6 +148,37 @@ static void cli_incoming_list_callid(char* buffer, int len, struct callmaster* m
                if (PS_ISSET(ps, FALLBACK_RTCP))
                    continue;
 
+#if (RE_HAS_MEASUREDELAY)
+               if (!PS_ISSET(ps, RTP) && PS_ISSET(ps, RTCP)) {
+                   printlen = snprintf(replybuffer,(outbufend-replybuffer), "------ Media #%u, port %5u <> %15s:%-5hu%s, "
+                        "%llu p, %llu b, %llu e, %llu last_packet\n",
+                        md->index,
+                        (unsigned int) (ps->sfd ? ps->sfd->fd.localport : 0),
+                        smart_ntop_p_buf(&ps->endpoint.ip46), ps->endpoint.port,
+                        (!PS_ISSET(ps, RTP) && PS_ISSET(ps, RTCP)) ? " (RTCP)" : "",
+                            (unsigned long long) ps->stats.packets,
+                            (unsigned long long) ps->stats.bytes,
+                            (unsigned long long) ps->stats.errors,
+                            (unsigned long long) ps->last_packet);
+               } else {
+               printlen = snprintf(replybuffer,(outbufend-replybuffer), "------ Media #%u, port %5u <> %15s:%-5hu%s, "
+                    "%llu p, %llu b, %llu e, %llu last_packet, %llu.%09llu delay_min, %llu.%09llu delay_avg, %llu.%09llu delay_max\n",
+                    md->index,
+                    (unsigned int) (ps->sfd ? ps->sfd->fd.localport : 0),
+                    smart_ntop_p_buf(&ps->endpoint.ip46), ps->endpoint.port,
+                    (!PS_ISSET(ps, RTP) && PS_ISSET(ps, RTCP)) ? " (RTCP)" : "",
+                        (unsigned long long) ps->stats.packets,
+                        (unsigned long long) ps->stats.bytes,
+                        (unsigned long long) ps->stats.errors,
+                        (unsigned long long) ps->last_packet,
+						(unsigned long long) ps->stats.delay_min.tv_sec,
+						(unsigned long long) ps->stats.delay_min.tv_nsec,
+						(unsigned long long) ps->stats.delay_avg.tv_sec,
+						(unsigned long long) ps->stats.delay_avg.tv_nsec,
+						(unsigned long long) ps->stats.delay_max.tv_sec,
+						(unsigned long long) ps->stats.delay_max.tv_nsec);
+               }
+#else
                printlen = snprintf(replybuffer,(outbufend-replybuffer), "------ Media #%u, port %5u <> %15s:%-5hu%s, "
                     "%llu p, %llu b, %llu e, %llu last_packet\n",
                     md->index,
@@ -157,6 +189,7 @@ static void cli_incoming_list_callid(char* buffer, int len, struct callmaster* m
                         (unsigned long long) ps->stats.bytes,
                         (unsigned long long) ps->stats.errors,
                         (unsigned long long) ps->last_packet);
+#endif
                ADJUSTLEN(printlen,outbufend,replybuffer);
            }
        }

daemon/kernel.c

@@ -102,7 +102,6 @@ int kernel_del_stream(int fd, u_int16_t p) {
 	return -1;
 }
 
-
 GList *kernel_list(unsigned int id) {
 	char str[64];
 	int fd;

daemon/main.c

@@ -662,6 +662,7 @@ int main(int argc, char **argv) {
 
 	thread_create_detach(sighandler, NULL);
 	thread_create_detach(timer_loop, ctx.p);
+
 	if (graphite_ip)
 		thread_create_detach(graphite_loop, ctx.m);
 

kernel-module/rtpengine_config.h

@@ -0,0 +1,15 @@
+/*
+ * rtpengine_config.h
+ *
+ * Description: Config file with preprocessor config makros
+ *
+ *  Created on: Mar 18, 2015
+ *      Author: fmetz
+ */
+
+#ifndef RTPENGINE_CONFIG_H_
+#define RTPENGINE_CONFIG_H_
+
+#define RE_HAS_MEASUREDELAY 1
+
+#endif /* RTPENGINE_CONFIG_H_ */

kernel-module/xt_RTPENGINE.c

@@ -27,6 +27,8 @@
 #include "xt_RTPENGINE.h"
 #endif
 
+#include "rtpengine_config.h"
+
 MODULE_LICENSE("GPL");
 
 
@@ -1792,6 +1794,7 @@ drop:
 
 
 static int send_proxy_packet(struct sk_buff *skb, struct re_address *src, struct re_address *dst, unsigned char tos) {
+
 	if (src->family != dst->family)
 		goto drop;
 
@@ -2105,7 +2108,48 @@ static inline int is_dtls(struct sk_buff *skb) {
 	return 1;
 }
 
-static unsigned int rtpengine46(struct sk_buff *skb, struct rtpengine_table *t, struct re_address *src) {
+static void re_timespec_subtract (struct timespec *result, const struct timespec *a, const struct timespec *b) {
+	long long nanoseconds=0;
+	nanoseconds = ((long)a->tv_sec - (long long)b->tv_sec) * (long long)1000000000 + ((long long)a->tv_nsec - (long long)b->tv_nsec);
+	result->tv_sec = nanoseconds/(long long)1000000000;
+	result->tv_nsec = nanoseconds%(long long)1000000000;
+}
+
+static void re_timespec_multiply(struct timespec *result, const struct timespec *a, const long long multiplier) {
+	long long nanoseconds=0;
+	nanoseconds = ((long)a->tv_sec * (long long)1000000000) + (long long)a->tv_nsec * multiplier;
+	result->tv_sec = nanoseconds/(long long)1000000000;
+	result->tv_nsec = nanoseconds%(long long)1000000000;
+}
+
+static void re_timespec_devide(struct timespec *result, const struct timespec *a, const long devisor) {
+	long long nanoseconds=0;
+	nanoseconds = ((long)a->tv_sec * (long long)1000000000) + (long long)a->tv_nsec / devisor;
+	result->tv_sec = nanoseconds/(long long)1000000000;
+	result->tv_nsec = nanoseconds%(long long)1000000000;
+}
+
+static void re_timespec_add(struct timespec *result, const struct timespec *a, const struct timespec *b) {
+	long long nanoseconds=0;
+	nanoseconds = ((long)a->tv_sec + (long long)b->tv_sec) * (long long)1000000000 + ((long long)a->tv_nsec + (long long)b->tv_nsec);
+	result->tv_sec = nanoseconds/(long long)1000000000;
+	result->tv_nsec = nanoseconds%(long long)1000000000;
+}
+
+/* Return negative, zero, positive if A < B, A == B, A > B, respectively.
+   Assume the nanosecond components are in range, or close to it.  */
+static int re_timespec_cmp (struct timespec *a, struct timespec *b)
+{
+  return (a->tv_sec < b->tv_sec ? -1
+	  : a->tv_sec > b->tv_sec ? 1
+	  : a->tv_nsec - b->tv_nsec);
+}
+
+#if (RE_HAS_MEASUREDELAY)
+	static unsigned int rtpengine46(struct sk_buff *skb, struct rtpengine_table *t, struct re_address *src, struct timespec *starttime) {
+#else
+	static unsigned int rtpengine46(struct sk_buff *skb, struct rtpengine_table *t, struct re_address *src) {
+#endif
 	struct udphdr *uh;
 	struct rtpengine_target *g;
 	struct sk_buff *skb2;
@@ -2116,6 +2160,10 @@ static unsigned int rtpengine46(struct sk_buff *skb, struct rtpengine_table *t,
 	struct rtp_parsed rtp;
 	u_int64_t pkt_idx = 0;
 
+#if (RE_HAS_MEASUREDELAY)
+	struct timespec endtime, delay;
+#endif
+
 	skb_reset_transport_header(skb);
 	uh = udp_hdr(skb);
 	skb_pull(skb, sizeof(*uh));
@@ -2214,11 +2262,35 @@ not_rtp:
 
 out:
 	spin_lock_irqsave(&g->stats_lock, flags);
+
 	if (err)
 		g->stats.errors++;
 	else {
 		g->stats.packets++;
 		g->stats.bytes += skb->len;
+
+#if (RE_HAS_MEASUREDELAY)
+		getnstimeofday(&endtime);
+
+		re_timespec_subtract(&delay,&endtime, starttime);
+
+		if (g->stats.packets==1) {
+			g->stats.delay_min=delay;
+			g->stats.delay_avg=delay;
+			g->stats.delay_max=delay;
+		} else {
+			if (re_timespec_cmp(&g->stats.delay_min,&delay)>0) {
+				g->stats.delay_min = delay;
+			}
+			if (re_timespec_cmp(&g->stats.delay_max,&delay)<0) {
+				g->stats.delay_max = delay;
+			}
+
+			re_timespec_multiply(&g->stats.delay_avg,&g->stats.delay_avg,g->stats.packets-1);
+			re_timespec_add(&g->stats.delay_avg,&g->stats.delay_avg,&delay);
+			re_timespec_devide(&g->stats.delay_avg,&g->stats.delay_avg,g->stats.packets);
+		}
+#endif
 	}
 	spin_unlock_irqrestore(&g->stats_lock, flags);
 
@@ -2255,6 +2327,11 @@ static unsigned int rtpengine4(struct sk_buff *oskb, const struct xt_action_para
 	struct rtpengine_table *t;
 	struct re_address src;
 
+#if (RE_HAS_MEASUREDELAY)
+	struct timespec starttime;
+	getnstimeofday(&starttime);
+#endif
+
 	t = get_table(pinfo->id);
 	if (!t)
 		goto skip;
@@ -2273,7 +2350,11 @@ static unsigned int rtpengine4(struct sk_buff *oskb, const struct xt_action_para
 	src.family = AF_INET;
 	src.u.ipv4 = ih->saddr;
 
+#if (RE_HAS_MEASUREDELAY)
+	return rtpengine46(skb, t, &src, &starttime);
+#else
 	return rtpengine46(skb, t, &src);
+#endif
 
 skip2:
 	kfree_skb(skb);
@@ -2297,6 +2378,11 @@ static unsigned int rtpengine6(struct sk_buff *oskb, const struct xt_action_para
 	struct rtpengine_table *t;
 	struct re_address src;
 
+#if (RE_HAS_MEASUREDELAY)
+	struct timespec starttime;
+	getnstimeofday(&starttime);
+#endif
+
 	t = get_table(pinfo->id);
 	if (!t)
 		goto skip;
@@ -2315,7 +2401,11 @@ static unsigned int rtpengine6(struct sk_buff *oskb, const struct xt_action_para
 	src.family = AF_INET6;
 	memcpy(&src.u.ipv6, &ih->saddr, sizeof(src.u.ipv6));
 
+#if (RE_HAS_MEASUREDELAY)
+	return rtpengine46(skb, t, &src, &starttime);
+#else
 	return rtpengine46(skb, t, &src);
+#endif
 
 skip2:
 	kfree_skb(skb);

kernel-module/xt_RTPENGINE.h

@@ -9,6 +9,9 @@ struct rtpengine_stats {
 	u_int64_t			packets;
 	u_int64_t			bytes;
 	u_int64_t			errors;
+	struct timespec     delay_min;
+	struct timespec     delay_avg;
+	struct timespec     delay_max;
 };
 
 struct re_address {
@@ -85,7 +88,7 @@ struct rtpengine_message {
 		MMG_NOOP = 1,
 		MMG_ADD,
 		MMG_DEL,
-		MMG_UPDATE,
+		MMG_UPDATE
 	}				cmd;
 
 	struct rtpengine_target_info	target;