observe: Provide the sum of the elapsed time of the individual operations

We can use the elapsed time of the indiividual operations to profile the
synchronous throughput of a trace and eliminate all replay overhead. At
the cost of running the trace synchronously of course.

Signed-off-by: Chris Wilson <chris@chris-wilson.co.uk>

5 files changed, 83 insertions, 14 deletions

diff --git a/perf/cairo-perf-compare-backends.c b/perf/cairo-perf-compare-backends.c
index f4a425f0..16306377 100644
--- a/perf/cairo-perf-compare-backends.c
+++ b/perf/cairo-perf-compare-backends.c
@@ -111,8 +111,6 @@ print_change_bar (double change,
 	printf ("%s", boxes[6]);
     else if (change > 0.5/8.0)
 	printf ("%s", boxes[7]);
-
-    printf ("\n");
 }
 
 static void
@@ -145,6 +143,7 @@ test_diff_print (test_diff_t		     *diff,
 
 	if (options->print_change_bars)
 	    print_change_bar (change, max_change, options->use_utf);
+	printf ("\n");
     }
 
     printf("\n");
diff --git a/perf/cairo-perf-trace.c b/perf/cairo-perf-trace.c
index 5e3b92c3..3577a25c 100644
--- a/perf/cairo-perf-trace.c
+++ b/perf/cairo-perf-trace.c
@@ -108,6 +108,7 @@ struct trace {
     const cairo_boilerplate_target_t *target;
     void            *closure;
     cairo_surface_t *surface;
+    cairo_bool_t observe;
 };
 
 cairo_bool_t
@@ -253,6 +254,10 @@ _similar_surface_create (void		 *closure,
     cairo_surface_t *surface;
     struct scache skey, *s;
 
+    if (args->observe)
+	    return cairo_surface_create_similar (args->surface,
+						 content, width, height);
+
     if (uid == 0 || surface_cache == NULL)
 	return args->target->create_similar (args->surface, content, width, height);
 
@@ -356,6 +361,7 @@ usage (const char *argv0)
 "The command-line arguments are interpreted as follows:\n"
 "\n"
 "  -r	raw; display each time measurement instead of summary statistics\n"
+"  -s	sync; only sum the elapsed time of the indiviual operations\n"
 "  -v	verbose; in raw mode also show the summaries\n"
 "  -i	iterations; specify the number of iterations per test case\n"
 "  -x   exclude; specify a file to read a list of traces to exclude\n"
@@ -479,6 +485,7 @@ parse_options (cairo_perf_t *perf,
     perf->exact_iterations = 0;
 
     perf->raw = FALSE;
+    perf->observe = FALSE;
     perf->list_only = FALSE;
     perf->names = NULL;
     perf->num_names = 0;
@@ -488,7 +495,7 @@ parse_options (cairo_perf_t *perf,
     perf->num_exclude_names = 0;
 
     while (1) {
-	c = _cairo_getopt (argc, argv, "i:x:lrvc");
+	c = _cairo_getopt (argc, argv, "i:x:lsrvc");
 	if (c == -1)
 	    break;
 
@@ -509,6 +516,9 @@ parse_options (cairo_perf_t *perf,
 	    perf->raw = TRUE;
 	    perf->summary = NULL;
 	    break;
+	case 's':
+	    perf->observe = TRUE;
+	    break;
 	case 'v':
 	    verbose = 1;
 	    break;
@@ -599,6 +609,8 @@ cairo_perf_trace (cairo_perf_t			   *perf,
 	NULL /* copy_page */
     };
 
+    args.observe = perf->observe;
+
     trace_cpy = xstrdup (trace);
     name = basename_no_ext (trace_cpy);
 
@@ -638,6 +650,12 @@ cairo_perf_trace (cairo_perf_t			   *perf,
 					       CAIRO_BOILERPLATE_MODE_PERF,
 					       0,
 					       &args.closure);
+	if (perf->observe) {
+	    cairo_surface_t *obs;
+	    obs = cairo_surface_create_observer (args.surface);
+	    cairo_surface_destroy (args.surface);
+	    args.surface = obs;
+	}
 	if (cairo_surface_status (args.surface)) {
 	    fprintf (stderr,
 		     "Error: Failed to create target surface: %s\n",
@@ -663,14 +681,20 @@ cairo_perf_trace (cairo_perf_t			   *perf,
 	csi = cairo_script_interpreter_create ();
 	cairo_script_interpreter_install_hooks (csi, &hooks);
 
-	cairo_perf_yield ();
-	cairo_perf_timer_start ();
+	if (! perf->observe) {
+	    cairo_perf_yield ();
+	    cairo_perf_timer_start ();
+	}
 
 	cairo_script_interpreter_run (csi, trace);
-	clear_surface (args.surface); /* queue a write to the sync'ed surface */
 
-	cairo_perf_timer_stop ();
-	times[i] = cairo_perf_timer_elapsed ();
+	if (perf->observe) {
+	    times[i] = cairo_device_observer_elapsed (cairo_surface_get_device (args.surface)) * (1e-9 * cairo_perf_ticks_per_second ());
+	} else {
+	    clear_surface (args.surface); /* queue a write to the sync'ed surface */
+	    cairo_perf_timer_stop ();
+	    times[i] = cairo_perf_timer_elapsed ();
+	}
 
 	cairo_script_interpreter_finish (csi);
 	scache_clear ();
diff --git a/perf/cairo-perf.h b/perf/cairo-perf.h
index b52bdfaf..9c70b5b3 100644
--- a/perf/cairo-perf.h
+++ b/perf/cairo-perf.h
@@ -77,6 +77,7 @@ typedef struct _cairo_perf {
     cairo_bool_t exact_iterations;
     cairo_bool_t raw;
     cairo_bool_t list_only;
+    cairo_bool_t observe;
     char **names;
     unsigned int num_names;
     char **exclude_names;
diff --git a/src/cairo-surface-observer.c b/src/cairo-surface-observer.c
index 15190e92..3c4521fb 100644
--- a/src/cairo-surface-observer.c
+++ b/src/cairo-surface-observer.c
@@ -1634,6 +1634,18 @@ replay_record (cairo_observation_t *log,
     assert (status == CAIRO_INT_STATUS_SUCCESS);
 }
 
+static double
+_cairo_observation_total_elapsed_ns (cairo_observation_t *log)
+{
+    double total = 0;
+    total += log->paint.elapsed;
+    total += log->mask.elapsed;
+    total += log->fill.elapsed;
+    total += log->stroke.elapsed;
+    total += log->glyphs.elapsed;
+    return total;
+}
+
 static void
 _cairo_observation_print (cairo_output_stream_t *stream,
 			  cairo_observation_t *log)
@@ -1644,6 +1656,10 @@ _cairo_observation_print (cairo_output_stream_t *stream,
     script = _cairo_script_context_create_internal (stream);
     _cairo_script_context_attach_snapshots (script, FALSE);
 
+    total = _cairo_observation_total_elapsed_ns (log);
+
+    _cairo_output_stream_printf (stream, "elapsed: %f\n",
+				 total);
     _cairo_output_stream_printf (stream, "surfaces: %d\n",
 				 log->num_surfaces);
     _cairo_output_stream_printf (stream, "contexts: %d\n",
@@ -1651,12 +1667,6 @@ _cairo_observation_print (cairo_output_stream_t *stream,
     _cairo_output_stream_printf (stream, "sources acquired: %d\n",
 				 log->num_sources_acquired);
 
-    total = 0;
-    total += log->paint.elapsed;
-    total += log->mask.elapsed;
-    total += log->fill.elapsed;
-    total += log->stroke.elapsed;
-    total += log->glyphs.elapsed;
 
     _cairo_output_stream_printf (stream, "paint: count %d [no-op %d], elapsed %f [%f%%]\n",
 				 log->paint.count, log->paint.noop,
@@ -1790,6 +1800,21 @@ cairo_surface_observer_print (cairo_surface_t *abstract_surface,
     _cairo_output_stream_destroy (stream);
 }
 
+double
+cairo_surface_observer_elapsed (cairo_surface_t *abstract_surface)
+{
+    cairo_surface_observer_t *surface;
+
+    if (unlikely (CAIRO_REFERENCE_COUNT_IS_INVALID (&abstract_surface->ref_count)))
+	return;
+
+    if (! _cairo_surface_is_observer (abstract_surface))
+	return;
+
+    surface = (cairo_surface_observer_t *) abstract_surface;
+    return _cairo_observation_total_elapsed_ns (&surface->log);
+}
+
 void
 cairo_device_observer_print (cairo_device_t *abstract_device,
 			     cairo_write_func_t write_func,
@@ -1810,3 +1835,18 @@ cairo_device_observer_print (cairo_device_t *abstract_device,
     _cairo_observation_print (stream, &device->log);
     _cairo_output_stream_destroy (stream);
 }
+
+double
+cairo_device_observer_elapsed (cairo_device_t *abstract_device)
+{
+    cairo_device_observer_t *device;
+
+    if (unlikely (CAIRO_REFERENCE_COUNT_IS_INVALID (&abstract_device->ref_count)))
+	return;
+
+    if (! _cairo_device_is_observer (abstract_device))
+	return;
+
+    device = (cairo_device_observer_t *) abstract_device;
+    return _cairo_observation_total_elapsed_ns (&device->log);
+}
diff --git a/src/cairo.h b/src/cairo.h
index 4d0afaf4..53065a19 100644
--- a/src/cairo.h
+++ b/src/cairo.h
@@ -2120,12 +2120,17 @@ cairo_public void
 cairo_surface_observer_print (cairo_surface_t *surface,
 			      cairo_write_func_t write_func,
 			      void *closure);
+cairo_public double
+cairo_surface_observer_elapsed (cairo_surface_t *surface);
 
 cairo_public void
 cairo_device_observer_print (cairo_device_t *device,
 			     cairo_write_func_t write_func,
 			     void *closure);
 
+cairo_public double
+cairo_device_observer_elapsed (cairo_device_t *device);
+
 cairo_public cairo_surface_t *
 cairo_surface_reference (cairo_surface_t *surface);