Experiment with live debugging of stats, and more probing tweaks

src/bwe.c

@@ -16,6 +16,12 @@
 #include "debug.h"
 #include "utils.h"
 
+#ifdef BWE_DEBUGGING
+#include <arpa/inet.h>
+#include <netdb.h>
+#include <sys/socket.h>
+#endif
+
 const char *janus_bwe_twcc_status_description(janus_bwe_twcc_status status) {
 	switch(status) {
 		case janus_bwe_twcc_status_notreceived:
@@ -67,6 +73,28 @@ janus_bwe_context *janus_bwe_context_create(void) {
 	char line[2048];
 	g_snprintf(line, sizeof(line), "time,status,estimate,probing_target,bitrate_out,rtx_out,probing_out,bitrate_in,rtx_in,probing_in,acked,lost,loss_ratio,avg_delay,avg_delay_weighted,avg_delay_fb\n");
 	fwrite(line, sizeof(char), strlen(line), bwe->csv);
+	bwe->fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
+	if(bwe->fd == -1) {
+		JANUS_LOG(LOG_ERR, "Error creating socket: %s\n", g_strerror(errno));
+	} else {
+		struct sockaddr_in address = { 0 };
+		address.sin_family = AF_INET;
+		address.sin_port = htons(0);
+		address.sin_addr.s_addr = INADDR_ANY;
+		if(bind(bwe->fd, (struct sockaddr *)&address, sizeof(address)) < 0) {
+			JANUS_LOG(LOG_ERR, "Error binding socket: %s\n", g_strerror(errno));
+			close(bwe->fd);
+			bwe->fd = -1;
+		} else {
+			address.sin_port = htons(8878);
+			address.sin_addr.s_addr = inet_addr("127.0.0.1");
+			if(connect(bwe->fd, (struct sockaddr *)&address, sizeof(address)) < 0) {
+				JANUS_LOG(LOG_ERR, "Error connecting socket: %s\n", g_strerror(errno));
+				close(bwe->fd);
+				bwe->fd = -1;
+			}
+		}
+	}
 #endif
 	return bwe;
 }
@@ -80,6 +108,8 @@ void janus_bwe_context_destroy(janus_bwe_context *bwe) {
 		janus_bwe_delay_tracker_destroy(bwe->delays);
 #ifdef BWE_DEBUGGING
 		fclose(bwe->csv);
+		if(bwe->fd > -1)
+			close(bwe->fd);
 #endif
 		g_free(bwe);
 	}
@@ -190,18 +220,26 @@ void janus_bwe_context_update(janus_bwe_context *bwe) {
 		bwe->status = janus_bwe_status_lossy;
 		bwe->status_changed = now;
 		bwe->estimate = estimate;
-	} else if(avg_delay_weighted > 1.2 && avg_delay_weighted - bwe->avg_delay > 0.1) {
-		JANUS_LOG(LOG_WARN, "[BWE] Congested (delay=%.2f, increase=%.2f)\n",
-			avg_delay_weighted, avg_delay_weighted - bwe->avg_delay);
+	} else if(avg_delay_weighted >= 1.0 && (avg_delay_weighted - bwe->avg_delay) >= 0.05) {
+		JANUS_LOG(LOG_WARN, "[BWE][%"SCNi64"] Congested (delay=%.2f, increase=%.2f)\n",
+			now, avg_delay_weighted, avg_delay_weighted - bwe->avg_delay);
 		/* FIXME Delay is increasing */
 		if(bwe->status != janus_bwe_status_lossy && bwe->status != janus_bwe_status_congested)
 			notify_plugin = TRUE;
 		bwe->status = janus_bwe_status_congested;
 		bwe->status_changed = now;
-		//~ if(estimate > bwe->estimate)
-			bwe->estimate = estimate;
+		bwe->estimate = estimate;
 		//~ else
 			//~ bwe->estimate = ((double)bwe->estimate * 0.8) + ((double)estimate * 0.2);
+	//~ } else if(bitrate_out > bitrate_in && (bitrate_out - bitrate_in > 50000)) {
+		//~ /* FIXME We sent much more than what was acked, another indicator of possible congestion? */
+		//~ JANUS_LOG(LOG_WARN, "[BWE][%"SCNi64"] Congested (too much diff with acked rate, %"SCNu32")\n",
+			//~ now, bitrate_out - bitrate_in);
+		//~ if(bwe->status != janus_bwe_status_lossy && bwe->status != janus_bwe_status_congested)
+			//~ notify_plugin = TRUE;
+		//~ bwe->status = janus_bwe_status_congested;
+		//~ bwe->status_changed = now;
+		//~ bwe->estimate = estimate;
 	} else {
 		/* FIXME All is fine? Check what state we're in */
 		if(bwe->status == janus_bwe_status_lossy || bwe->status == janus_bwe_status_congested) {
@@ -218,6 +256,7 @@ void janus_bwe_context_update(janus_bwe_context *bwe) {
 				bwe->probing_sent = 0;
 				bwe->probing_portion = 0.0;
 				bwe->probing_buildup = 0;
+				bwe->probing_buildup_step = 1000;
 				bwe->probing_buildup_timer = now;
 			} else {
 				/* FIXME Keep converging to the estimate */
@@ -249,6 +288,8 @@ void janus_bwe_context_update(janus_bwe_context *bwe) {
 		bwe->estimate, bwe->probing_target, bitrate_out, rtx_out, probing_out, bitrate_in, rtx_in, probing_in,
 		bwe->received_pkts, bwe->lost_pkts, bwe->loss_ratio, avg_delay, avg_delay_weighted, avg_delay_latest);
 	fwrite(line, sizeof(char), strlen(line), bwe->csv);
+	if(bwe->fd > -1)
+		send(bwe->fd, line, strlen(line), 0);
 #endif
 	/* Reset values */
 	bwe->delay = 0;

src/bwe.h

@@ -146,7 +146,7 @@ typedef struct janus_bwe_context {
 	/*! \brief Index of the m-line we're using for probing */
 	int probing_mindex;
 	/*! \brief How much we should aim for with out probing (and how much to increase, plus much we sent in a second) */
-	uint32_t probing_target, probing_buildup, probing_sent;
+	uint32_t probing_target, probing_buildup, probing_buildup_step, probing_sent;
 	/*! \brief How many times we went through probing in a second */
 	uint8_t probing_count;
 	/*! \brief Portion of probing we didn't manage to send the previous round */
@@ -182,8 +182,10 @@ typedef struct janus_bwe_context {
 	/*! \brief When we last notified the plugin */
 	int64_t last_notified;
 #ifdef BWE_DEBUGGING
-	/*! \brief CSV where we save the the debugging information */
+	/*! \brief CSV where we save the debugging information */
 	FILE *csv;
+	/*! \brief UDP socket where to send the debugging information */
+	int fd;
 #endif
 } janus_bwe_context;
 /*! \brief Helper to create a new bandwidth estimation context

src/ice.c

@@ -4536,6 +4536,7 @@ static gboolean janus_ice_outgoing_bwe_handle(gpointer user_data) {
 			return G_SOURCE_CONTINUE;
 		}
 		pc->bwe->probing_deferred = 0;
+		pc->bwe->probing_buildup_timer = now;
 	}
 	/* Get the medium instance we'll use for probing */
 	janus_ice_peerconnection_medium *medium = NULL;
@@ -4574,9 +4575,13 @@ static gboolean janus_ice_outgoing_bwe_handle(gpointer user_data) {
 	uint32_t required = pc->bwe->probing_target - bitrate_out;
 	if(pc->bwe->probing_buildup_timer > 0) {
 		if(pc->bwe->probing_buildup == 0)
-			pc->bwe->probing_buildup = 25000;
-		if(now - pc->bwe->probing_buildup_timer >= 500000) {
-			pc->bwe->probing_buildup += 25000;
+			pc->bwe->probing_buildup = pc->bwe->probing_buildup_step;
+		uint32_t gap = (pc->bwe->probing_buildup_step >= 10000 ? 500000 : 200000);
+		if(now - pc->bwe->probing_buildup_timer >= gap) {
+			pc->bwe->probing_buildup_step += 1000;
+			if(pc->bwe->probing_buildup_step > 20000)
+				pc->bwe->probing_buildup_step = 20000;
+			pc->bwe->probing_buildup += pc->bwe->probing_buildup_step;
 			pc->bwe->probing_buildup_timer = now;
 		}
 		if(pc->bwe->probing_buildup >= required)
@@ -4735,7 +4740,8 @@ static gboolean janus_ice_outgoing_traffic_handle(janus_ice_handle *handle, janu
 		pc->bwe->probing_sent = 0;
 		pc->bwe->probing_portion = 0.0;
 		pc->bwe->probing_buildup = 0;
-		pc->bwe->probing_buildup_timer = janus_get_monotonic_time();
+		//~ pc->bwe->probing_buildup_timer = janus_get_monotonic_time();
+		pc->bwe->probing_deferred = janus_get_monotonic_time() + G_USEC_PER_SEC;
 		return G_SOURCE_CONTINUE;
 	} else if(pkt == &janus_ice_disable_bwe) {
 		/* We need to get rif of the bandwidth estimator */

src/plugins/janus_videoroom.c

@@ -8469,7 +8469,7 @@ void janus_videoroom_estimated_bandwidth(janus_plugin_session *handle, uint32_t
 								}
 								target = 3*substream + templayer;
 							}
-							if(estimate < ps->bitrates->bitrate[target]) {
+							if(estimate < (ps->bitrates->bitrate[target] + 20000)) {
 								/* Unavailable layer, or we don't have room for these layers, find one below that fits */
 								if(target == 0) {
 									estimate = 0;
@@ -12502,7 +12502,7 @@ static void janus_videoroom_relay_rtp_packet(gpointer data, gpointer user_data)
 						if(target > 0)
 							break;
 					}
-					gateway->set_bwe_target(subscriber->session->handle, target);
+					gateway->set_bwe_target(subscriber->session->handle, target ? (target + 50000) : 0);
 				}
 			}
 			/* If we got here, update the RTP header and send the packet */