Profiling code: C89 style

src/tint.c

@@ -30,6 +30,8 @@
 #include <X11/extensions/Xdamage.h>
 #include <Imlib2.h>
 #include <signal.h>
+#include <time.h>
+#include <sys/time.h>
 
 #ifdef HAVE_SN
 #include <libsn/sn.h>
@@ -57,6 +59,84 @@ Atom dnd_selection;
 Atom dnd_atom;
 int dnd_sent_request;
 char *dnd_launcher_exec;
+gboolean debug_fps = FALSE;
+float *fps_distribution = NULL;
+
+void create_fps_distribution()
+{
+	// measure FPS with resolution:
+	// 0-59: 1		   (60 samples)
+	// 60-199: 10      (14)
+	// 200-1,999: 25   (72)
+	// 1k-19,999: 1000 (19)
+	// 20x+: inf       (1)
+	// => 166 samples
+	if (fps_distribution)
+		return;
+	fps_distribution = calloc(170, sizeof(float));
+}
+
+void cleanup_fps_distribution()
+{
+	free(fps_distribution);
+	fps_distribution = NULL;
+}
+
+void sample_fps(double fps)
+{
+	int fps_rounded = (int)(fps + 0.5);
+	int i = 1;
+	if (fps_rounded < 60) {
+		i += fps_rounded;
+	} else {
+		i += 60;
+		if (fps_rounded < 200) {
+			i += (fps_rounded - 60) / 10;
+		} else {
+			i += 14;
+			if (fps_rounded < 2000) {
+				i += (fps_rounded - 200) / 25;
+			} else {
+				i += 72;
+				if (fps_rounded < 20000) {
+					i += (fps_rounded - 2000) / 1000;
+				} else {
+					i += 20;
+				}
+			}
+		}
+	}
+	// fprintf(stderr, "fps = %.0f => i = %d\n", fps, i);
+	fps_distribution[i] += 1.;
+	fps_distribution[0] += 1.;
+}
+
+void fps_compute_stats(double *low, double *median, double *high, double *samples)
+{
+	*median = *low = *high = *samples = -1;
+	if (!fps_distribution || fps_distribution[0] < 1)
+		return;
+	float total = fps_distribution[0];
+	*samples = (double) fps_distribution[0];
+	float cum_low = 0.05f * total;
+	float cum_median = 0.5f * total;
+	float cum_high = 0.95f * total;
+	float cum = 0;
+	int i;
+	for (i = 1; i <= 166; i++) {
+		double value =
+			(i < 60) ? i : (i < 74) ? (60 + (i - 60) * 10) : (i < 146) ? (200 + (i - 74) * 25)
+																	  : (i < 165) ? (2000 + (i - 146) * 1000) : 20000;
+		// fprintf(stderr, "%6.0f (i = %3d) : %.0f | ", value, i, (double)fps_distribution[i]);
+		cum += fps_distribution[i];
+		if (*low < 0 && cum >= cum_low)
+			*low = value;
+		if (*median < 0 && cum >= cum_median)
+			*median = value;
+		if (*high < 0 && cum >= cum_high)
+			*high = value;
+	}
+}
 
 void signal_handler(int sig)
 {
@@ -123,6 +203,9 @@ void init (int argc, char *argv[])
 //	sigaddset(&block_mask, SIGHUP);
 //	sigaddset(&block_mask, SIGUSR1);
 //	sigprocmask(SIG_BLOCK, &block_mask, 0);
+	debug_fps = getenv("DEBUG_FPS") != NULL;
+	if (debug_fps)
+		create_fps_distribution();
 }
 
 #ifdef HAVE_SN
@@ -254,6 +337,7 @@ void cleanup()
 	cleanup_server();
 	cleanup_timeout();
 	if (server.dsp) XCloseDisplay(server.dsp);
+	cleanup_fps_distribution();
 }
 
 
@@ -998,7 +1082,7 @@ void dnd_drop(XClientMessageEvent *e)
 		//The source is sending anyway, despite instructions to the contrary.
 		//So reply that we're not interested.
 		XClientMessageEvent m;
-		memset(&m, sizeof(m), 0);
+		memset(&m, 0, sizeof(m));
 		m.type = ClientMessage;
 		m.display = e->display;
 		m.window = e->data.l[0];
@@ -1011,6 +1095,19 @@ void dnd_drop(XClientMessageEvent *e)
 	}
 }
 
+double get_time()
+{
+	struct timespec cur_time;
+	clock_gettime(CLOCK_MONOTONIC, &cur_time);
+	return cur_time.tv_sec + cur_time.tv_nsec * 1.0e-9;
+}
+
+#define GREEN "\033[1;32m"
+#define YELLOW "\033[1;33m"
+#define RED "\033[1;31m"
+#define BLUE "\033[1;34m"
+#define RESET "\033[0m"
+
 int main (int argc, char *argv[])
 {
 	XEvent e;
@@ -1061,8 +1158,14 @@ start:
 //	sigset_t empty_mask;
 //	sigemptyset(&empty_mask);
 
+	double ts_event_read = 0;
+	double ts_event_processed = 0;
+	double ts_render_finished = 0;
+	double ts_flush_finished = 0;
 	while (1) {
 		if (panel_refresh) {
+			if (debug_fps)
+				ts_event_processed = get_time();
 			panel_refresh = 0;
 
 			for (i=0 ; i < nb_panel ; i++) {
@@ -1089,6 +1192,31 @@ start:
 				// force icon's refresh
 				refresh_systray_icon();
 			}
+
+			if (debug_fps)
+				ts_render_finished = get_time();
+			if (debug_fps && ts_event_read > 0) {
+				ts_flush_finished = get_time();
+				double period = ts_flush_finished - ts_event_read;
+				double fps = 1.0 / period;
+				sample_fps(fps);
+				double proc_ratio = (ts_event_processed - ts_event_read) / period;
+				double render_ratio = (ts_render_finished - ts_event_processed) / period;
+				double flush_ratio = (ts_flush_finished - ts_render_finished) / period;
+				double fps_low, fps_median, fps_high, fps_samples;
+				fps_compute_stats(&fps_low, &fps_median, &fps_high, &fps_samples);
+				fprintf(stderr,
+						BLUE "fps = %.0f (low %.0f, med %.0f, high %.0f, samples %.0f) : processing %.0f%%, rendering %.0f%%, "
+							 "flushing %.0f%%" RESET "\n",
+						fps,
+						fps_low,
+						fps_median,
+						fps_high,
+						fps_samples,
+						proc_ratio * 100,
+						render_ratio * 100,
+						flush_ratio * 100);
+			}
 		}
 
 		// thanks to AngryLlama for the timer
@@ -1102,9 +1230,12 @@ start:
 			timeout = 0;
 
 		// Wait for X Event or a Timer
+		ts_event_read = 0;
 		if (select(x11_fd+1, &fdset, 0, 0, timeout) > 0) {
 			while (XPending (server.dsp)) {
 				XNextEvent(server.dsp, &e);
+				if (debug_fps)
+					ts_event_read = get_time();
 #if HAVE_SN
 				sn_display_process_event (server.sn_dsp, &e);
 #endif // HAVE_SN
@@ -1304,7 +1435,7 @@ start:
 
 									// Reply OK.
 									XClientMessageEvent m;
-									memset(&m, sizeof(m), 0);
+									memset(&m, 0, sizeof(m));
 									m.type = ClientMessage;
 									m.display = server.dsp;
 									m.window = dnd_source_window;