observer: record all operations and their timings

The immediate use of this is to print out the slowest operation of each
type in a replayable manner. A continuing demonstration of how we may
analyse traces...

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

7 files changed, 464 insertions, 55 deletions

diff --git a/src/Makefile.sources b/src/Makefile.sources
index c1b9fb27..8f2d09e2 100644
--- a/src/Makefile.sources
+++ b/src/Makefile.sources
@@ -389,6 +389,7 @@ cairo_drm_sources = drm/cairo-drm.c \
 cairo_gallium_sources = drm/cairo-drm-gallium-surface.c
 
 cairo_script_headers = cairo-script.h
+cairo_script_private = cairo-script-private.h
 cairo_script_sources = cairo-script-surface.c
 
 cairo_tee_headers = cairo-tee.h
diff --git a/src/cairo-recording-surface-private.h b/src/cairo-recording-surface-private.h
index 5a897da1..b7843e6c 100644
--- a/src/cairo-recording-surface-private.h
+++ b/src/cairo-recording-surface-private.h
@@ -149,6 +149,11 @@ _cairo_recording_surface_get_path (cairo_surface_t	 *surface,
 				   cairo_path_fixed_t *path);
 
 cairo_private cairo_status_t
+_cairo_recording_surface_replay_one (cairo_recording_surface_t	*surface,
+				     long unsigned index,
+				     cairo_surface_t *target);
+
+cairo_private cairo_status_t
 _cairo_recording_surface_replay (cairo_surface_t *surface,
 				 cairo_surface_t *target);
 
diff --git a/src/cairo-recording-surface.c b/src/cairo-recording-surface.c
index 1b46877c..beafb785 100644
--- a/src/cairo-recording-surface.c
+++ b/src/cairo-recording-surface.c
@@ -1480,6 +1480,96 @@ done:
     return _cairo_surface_set_error (&surface->base, status);
 }
 
+cairo_status_t
+_cairo_recording_surface_replay_one (cairo_recording_surface_t	*surface,
+				     long unsigned index,
+				     cairo_surface_t	     *target)
+{
+    cairo_surface_wrapper_t wrapper;
+    cairo_command_t **elements, *command;
+    cairo_int_status_t status;
+
+    if (unlikely (surface->base.status))
+	return surface->base.status;
+
+    if (unlikely (target->status))
+	return target->status;
+
+    if (unlikely (surface->base.finished))
+	return _cairo_error (CAIRO_STATUS_SURFACE_FINISHED);
+
+    assert (_cairo_surface_is_recording (&surface->base));
+
+    /* XXX
+     * Use a surface wrapper because we may want to do transformed
+     * replay in the future.
+     */
+    _cairo_surface_wrapper_init (&wrapper, target);
+
+    if (index > surface->commands.num_elements)
+	return _cairo_error (CAIRO_STATUS_READ_ERROR);
+
+    elements = _cairo_array_index (&surface->commands, 0);
+    command = elements[index];
+    switch (command->header.type) {
+    case CAIRO_COMMAND_PAINT:
+	status = _cairo_surface_wrapper_paint (&wrapper,
+					       command->header.op,
+					       &command->paint.source.base,
+					       command->header.clip);
+	break;
+
+    case CAIRO_COMMAND_MASK:
+	status = _cairo_surface_wrapper_mask (&wrapper,
+					      command->header.op,
+					      &command->mask.source.base,
+					      &command->mask.mask.base,
+					      command->header.clip);
+	break;
+
+    case CAIRO_COMMAND_STROKE:
+	status = _cairo_surface_wrapper_stroke (&wrapper,
+						command->header.op,
+						&command->stroke.source.base,
+						&command->stroke.path,
+						&command->stroke.style,
+						&command->stroke.ctm,
+						&command->stroke.ctm_inverse,
+						command->stroke.tolerance,
+						command->stroke.antialias,
+						command->header.clip);
+	break;
+
+    case CAIRO_COMMAND_FILL:
+	status = _cairo_surface_wrapper_fill (&wrapper,
+					      command->header.op,
+					      &command->fill.source.base,
+					      &command->fill.path,
+					      command->fill.fill_rule,
+					      command->fill.tolerance,
+					      command->fill.antialias,
+					      command->header.clip);
+	break;
+
+    case CAIRO_COMMAND_SHOW_TEXT_GLYPHS:
+	status = _cairo_surface_wrapper_show_text_glyphs (&wrapper,
+							  command->header.op,
+							  &command->show_text_glyphs.source.base,
+							  command->show_text_glyphs.utf8, command->show_text_glyphs.utf8_len,
+							  command->show_text_glyphs.glyphs, command->show_text_glyphs.num_glyphs,
+							  command->show_text_glyphs.clusters, command->show_text_glyphs.num_clusters,
+							  command->show_text_glyphs.cluster_flags,
+							  command->show_text_glyphs.scaled_font,
+							  command->header.clip);
+	break;
+
+    default:
+	ASSERT_NOT_REACHED;
+    }
+
+    _cairo_surface_wrapper_fini (&wrapper);
+    return _cairo_surface_set_error (&surface->base, status);
+}
 /**
  * _cairo_recording_surface_replay:
  * @surface: the #cairo_recording_surface_t
diff --git a/src/cairo-script-private.h b/src/cairo-script-private.h
new file mode 100644
index 00000000..6a94fd80
--- /dev/null
+++ b/src/cairo-script-private.h
@@ -0,0 +1,56 @@
+/* cairo - a vector graphics library with display and print output
+ *
+ * Copyright © 2008 Chris Wilson
+ *
+ * This library is free software; you can redistribute it and/or
+ * modify it either under the terms of the GNU Lesser General Public
+ * License version 2.1 as published by the Free Software Foundation
+ * (the "LGPL") or, at your option, under the terms of the Mozilla
+ * Public License Version 1.1 (the "MPL"). If you do not alter this
+ * notice, a recipient may use your version of this file under either
+ * the MPL or the LGPL.
+ *
+ * You should have received a copy of the LGPL along with this library
+ * in the file COPYING-LGPL-2.1; if not, write to the Free Software
+ * Foundation, Inc., 51 Franklin Street, Suite 500, Boston, MA 02110-1335, USA
+ * You should have received a copy of the MPL along with this library
+ * in the file COPYING-MPL-1.1
+ *
+ * The contents of this file are subject to the Mozilla Public License
+ * Version 1.1 (the "License"); you may not use this file except in
+ * compliance with the License. You may obtain a copy of the License at
+ * http://www.mozilla.org/MPL/
+ *
+ * This software is distributed on an "AS IS" basis, WITHOUT WARRANTY
+ * OF ANY KIND, either express or implied. See the LGPL or the MPL for
+ * the specific language governing rights and limitations.
+ *
+ * The Original Code is the cairo graphics library.
+ *
+ * The Initial Developer of the Original Code is Chris Wilson
+ *
+ * Contributor(s):
+ *	Chris Wilson <chris@chris-wilson.co.uk>
+ */
+
+#ifndef CAIRO_SCRIPT_PRIVATE_H
+#define CAIRO_SCRIPT_PRIVATE_H
+
+#include "cairo.h"
+
+#include "cairo-script.h"
+
+CAIRO_BEGIN_DECLS
+
+cairo_private cairo_device_t *
+_cairo_script_context_create_internal (cairo_output_stream_t *stream);
+
+cairo_private void
+_cairo_script_context_attach_snapshots (cairo_device_t *device,
+					cairo_bool_t enable);
+
+slim_hidden_proto (cairo_script_surface_create);
+
+CAIRO_END_DECLS
+
+#endif /* CAIRO_SCRIPT_PRIVATE_H */
diff --git a/src/cairo-script-surface.c b/src/cairo-script-surface.c
index 856dbe3a..f3e561bb 100644
--- a/src/cairo-script-surface.c
+++ b/src/cairo-script-surface.c
@@ -45,6 +45,7 @@
 #include "cairoint.h"
 
 #include "cairo-script.h"
+#include "cairo-script-private.h"
 
 #include "cairo-analysis-surface-private.h"
 #include "cairo-default-context-private.h"
@@ -100,7 +101,9 @@ struct _cairo_script_context {
     cairo_device_t base;
 
     int active;
+    int attach_snapshots;
 
+    cairo_bool_t owns_stream;
     cairo_output_stream_t *stream;
     cairo_script_mode_t mode;
 
@@ -1070,6 +1073,9 @@ attach_snapshot (cairo_script_context_t *ctx,
 {
     struct script_snapshot *surface;
 
+    if (! ctx->attach_snapshots)
+	return;
+
     surface = malloc (sizeof (*surface));
     if (unlikely (surface == NULL))
 	return;
@@ -1983,10 +1989,12 @@ _cairo_script_surface_create_similar (void	       *abstract_surface,
 
     _get_target (other);
     _cairo_output_stream_printf (ctx->stream,
-				 "%u %u //%s similar dup /s%u exch def context\n",
+				 "%u %u //%s similar",
 				 width, height,
-				 _content_to_string (content),
-				 surface->base.unique_id);
+				 _content_to_string (content));
+    attach_snapshot (ctx, &surface->base);
+    _cairo_output_stream_printf (ctx->stream, " context\n");
+
     surface->emitted = TRUE;
     surface->defined = TRUE;
     surface->base.is_clear = TRUE;
@@ -2025,7 +2033,8 @@ _device_destroy (void *abstract_device)
     _bitmap_fini (ctx->surface_id.next);
     _bitmap_fini (ctx->font_id.next);
 
-    status = _cairo_output_stream_destroy (ctx->stream);
+    if (ctx->owns_stream)
+	status = _cairo_output_stream_destroy (ctx->stream);
 
     free (ctx);
 }
@@ -3623,7 +3632,7 @@ static const cairo_device_backend_t _cairo_script_device_backend = {
     _device_destroy
 };
 
-static cairo_device_t *
+cairo_device_t *
 _cairo_script_context_create_internal (cairo_output_stream_t *stream)
 {
     cairo_script_context_t *ctx;
@@ -3644,8 +3653,33 @@ _cairo_script_context_create_internal (cairo_output_stream_t *stream)
     cairo_list_init (&ctx->fonts);
     cairo_list_init (&ctx->defines);
 
-    _cairo_output_stream_puts (ctx->stream, "%!CairoScript\n");
+    ctx->attach_snapshots = TRUE;
+
+    return &ctx->base;
+}
+
+void
+_cairo_script_context_attach_snapshots (cairo_device_t *device,
+					cairo_bool_t enable)
+{
+    cairo_script_context_t *ctx;
 
+    ctx = (cairo_script_context_t *) device;
+    ctx->attach_snapshots = enable;
+}
+
+static cairo_device_t *
+_cairo_script_context_create (cairo_output_stream_t *stream)
+{
+    cairo_script_context_t *ctx;
+
+    ctx = (cairo_script_context_t *)
+	_cairo_script_context_create_internal (stream);
+    if (unlikely (ctx->base.status))
+	return &ctx->base;
+
+    ctx->owns_stream = TRUE;
+    _cairo_output_stream_puts (ctx->stream, "%!CairoScript\n");
     return &ctx->base;
 }
 
@@ -3659,7 +3693,7 @@ cairo_script_create (const char *filename)
     if ((status = _cairo_output_stream_get_status (stream)))
 	return _cairo_device_create_in_error (status);
 
-    return _cairo_script_context_create_internal (stream);
+    return _cairo_script_context_create (stream);
 }
 
 cairo_device_t *
@@ -3673,7 +3707,7 @@ cairo_script_create_for_stream (cairo_write_func_t	 write_func,
     if ((status = _cairo_output_stream_get_status (stream)))
 	return _cairo_device_create_in_error (status);
 
-    return _cairo_script_context_create_internal (stream);
+    return _cairo_script_context_create (stream);
 }
 
 void
@@ -3733,6 +3767,7 @@ cairo_script_surface_create (cairo_device_t *device,
 						   content, extents,
 						   NULL)->base;
 }
+slim_hidden_def (cairo_script_surface_create);
 
 cairo_surface_t *
 cairo_script_surface_create_for_target (cairo_device_t *device,
diff --git a/src/cairo-surface-observer-private.h b/src/cairo-surface-observer-private.h
index 9e188684..d30a0e1e 100644
--- a/src/cairo-surface-observer-private.h
+++ b/src/cairo-surface-observer-private.h
@@ -39,6 +39,7 @@
 #include "cairoint.h" /* cairo_surface_backend_t */
 
 #include "cairo-device-private.h"
+#include "cairo-recording-surface-private.h"
 #include "cairo-surface-private.h"
 
 struct stat {
@@ -74,6 +75,11 @@ typedef struct _cairo_observation_record cairo_observation_record_t;
 typedef struct _cairo_device_observer cairo_device_observer_t;
 
 struct _cairo_observation_record {
+    cairo_content_t target_content;
+    int target_width;
+    int target_height;
+
+    int index;
     cairo_operator_t op;
     int source;
     int mask;
@@ -161,6 +167,9 @@ struct _cairo_observation {
 
 	cairo_observation_record_t slowest;
     } glyphs;
+
+    cairo_array_t timings;
+    cairo_recording_surface_t *record;
 };
 
 struct _cairo_device_observer {
diff --git a/src/cairo-surface-observer.c b/src/cairo-surface-observer.c
index 06be2c27..abb00e7e 100644
--- a/src/cairo-surface-observer.c
+++ b/src/cairo-surface-observer.c
@@ -35,13 +35,16 @@
 
 #include "cairoint.h"
 
+#include "cairo-surface-observer-private.h"
+
 #include "cairo-combsort-private.h"
 #include "cairo-composite-rectangles-private.h"
 #include "cairo-error-private.h"
 #include "cairo-image-surface-private.h"
 #include "cairo-pattern-private.h"
 #include "cairo-output-stream-private.h"
-#include "cairo-surface-observer-private.h"
+#include "cairo-recording-surface-private.h"
+#include "cairo-script-private.h"
 #include "cairo-surface-subsurface-private.h"
 #include "cairo-reference-count-private.h"
 
@@ -120,6 +123,17 @@ log_init (cairo_observation_t *log)
     init_fill (&log->fill);
     init_stroke (&log->stroke);
     init_glyphs (&log->glyphs);
+
+    _cairo_array_init (&log->timings, sizeof (cairo_observation_record_t));
+    log->record = (cairo_recording_surface_t *)
+	    cairo_recording_surface_create (CAIRO_CONTENT_COLOR_ALPHA, NULL);
+}
+
+static void
+log_fini (cairo_observation_t *log)
+{
+    _cairo_array_fini (&log->timings);
+    cairo_surface_destroy (&log->record->base);
 }
 
 static cairo_surface_t*
@@ -282,6 +296,7 @@ static void
 _cairo_device_observer_finish (void *_device)
 {
     cairo_device_observer_t *device = (cairo_device_observer_t *) _device;
+    log_fini (&device->log);
     cairo_device_finish (device->target);
 }
 
@@ -362,6 +377,7 @@ _cairo_surface_observer_finish (void *abstract_surface)
     cairo_surface_observer_t *surface = abstract_surface;
 
     cairo_surface_destroy (surface->target);
+    log_fini (&surface->log);
 
     return CAIRO_STATUS_SUCCESS;
 }
@@ -429,6 +445,22 @@ _cairo_surface_observer_unmap_image (void *abstract_surface,
 }
 
 static void
+record_target (cairo_observation_record_t *r,
+	       cairo_surface_t *target)
+{
+    cairo_rectangle_int_t extents;
+
+    r->target_content = target->content;
+    if (_cairo_surface_get_extents (target, &extents)) {
+	r->target_width = extents.width;
+	r->target_height = extents.height;
+    } else {
+	r->target_width = -1;
+	r->target_height = -1;
+    }
+}
+
+static void
 record_paint (cairo_observation_record_t *r,
 	      cairo_surface_t *target,
 	      cairo_operator_t op,
@@ -436,6 +468,8 @@ record_paint (cairo_observation_record_t *r,
 	      const cairo_clip_t *clip,
 	      double elapsed)
 {
+    record_target (r, target);
+
     r->op = op;
     r->source = classify_pattern (source, target);
     r->mask = -1;
@@ -457,6 +491,8 @@ record_mask (cairo_observation_record_t *r,
 	     const cairo_clip_t *clip,
 	     double elapsed)
 {
+    record_target (r, target);
+
     r->op = op;
     r->source = classify_pattern (source, target);
     r->mask = classify_pattern (mask, target);
@@ -481,6 +517,8 @@ record_fill (cairo_observation_record_t *r,
 	     const cairo_clip_t		*clip,
 	     double elapsed)
 {
+    record_target (r, target);
+
     r->op = op;
     r->source = classify_pattern (source, target);
     r->mask = -1;
@@ -507,6 +545,8 @@ record_stroke (cairo_observation_record_t *r,
 	       const cairo_clip_t	*clip,
 	       double			 elapsed)
 {
+    record_target (r, target);
+
     r->op = op;
     r->source = classify_pattern (source, target);
     r->mask = -1;
@@ -530,6 +570,8 @@ record_glyphs (cairo_observation_record_t *r,
 	       const cairo_clip_t	*clip,
 	       double			 elapsed)
 {
+    record_target (r, target);
+
     r->op = op;
     r->source = classify_pattern (source, target);
     r->mask = -1;
@@ -543,6 +585,19 @@ record_glyphs (cairo_observation_record_t *r,
 }
 
 static void
+add_record (cairo_observation_t *log,
+	    cairo_observation_record_t *r,
+	    unsigned long index)
+{
+    cairo_int_status_t status;
+
+    r->index = index - 1;
+
+    status = _cairo_array_append (&log->timings, r);
+    assert (status == CAIRO_INT_STATUS_SUCCESS);
+}
+
+static void
 start_timer (struct timespec *ts)
 {
     clock_gettime (CLOCK_MONOTONIC, ts);
@@ -583,6 +638,28 @@ midpt (const cairo_composite_rectangles_t *extents, int *x, int *y)
     *y = extents->bounded.y + extents->bounded.height / 2;
 }
 
+static void
+add_record_paint (cairo_observation_t *log,
+		 cairo_surface_t *target,
+		 cairo_operator_t op,
+		 const cairo_pattern_t *source,
+		 const cairo_clip_t *clip,
+		 double elapsed)
+{
+    cairo_observation_record_t record;
+    cairo_int_status_t status;
+
+    record_paint (&record, target, op, source, clip, elapsed);
+
+    status = _cairo_surface_paint (&log->record->base, op, source, clip);
+    assert (status == CAIRO_INT_STATUS_SUCCESS);
+    add_record (log, &record, log->record->commands.num_elements);
+
+    if (elapsed > log->paint.slowest.elapsed)
+	log->paint.slowest = record;
+    log->paint.elapsed += elapsed;
+}
+
 static cairo_int_status_t
 _cairo_surface_observer_paint (void *abstract_surface,
 			       cairo_operator_t op,
@@ -637,19 +714,36 @@ _cairo_surface_observer_paint (void *abstract_surface,
     sync (surface->target, x, y);
     elapsed = stop_timer (&ts);
 
-    if (elapsed > surface->log.paint.slowest.elapsed)
-	record_paint (&surface->log.paint.slowest,
-		      surface->target, op, source, clip, elapsed);
-    surface->log.paint.elapsed += elapsed;
-
-    if (elapsed > device->log.paint.slowest.elapsed)
-	record_paint (&device->log.paint.slowest,
-		      surface->target, op, source, clip, elapsed);
-    device->log.paint.elapsed += elapsed;
+    add_record_paint (&surface->log, surface->target, op, source, clip, elapsed);
+    add_record_paint (&device->log, surface->target, op, source, clip, elapsed);
 
     return CAIRO_STATUS_SUCCESS;
 }
 
+static void
+add_record_mask (cairo_observation_t *log,
+		 cairo_surface_t *target,
+		 cairo_operator_t op,
+		 const cairo_pattern_t *source,
+		 const cairo_pattern_t *mask,
+		 const cairo_clip_t *clip,
+		 double elapsed)
+{
+    cairo_observation_record_t record;
+    cairo_int_status_t status;
+
+    record_mask (&record, target, op, source, mask, clip, elapsed);
+
+    status = _cairo_surface_mask (&log->record->base,
+				  op, source, mask, clip);
+    assert (status == CAIRO_INT_STATUS_SUCCESS);
+    add_record (log, &record, log->record->commands.num_elements);
+
+    if (elapsed > log->mask.slowest.elapsed)
+	log->mask.slowest = record;
+    log->mask.elapsed += elapsed;
+}
+
 static cairo_int_status_t
 _cairo_surface_observer_mask (void *abstract_surface,
 			      cairo_operator_t op,
@@ -705,19 +799,48 @@ _cairo_surface_observer_mask (void *abstract_surface,
     sync (surface->target, x, y);
     elapsed = stop_timer (&ts);
 
-    if (elapsed > surface->log.mask.slowest.elapsed)
-	record_mask (&surface->log.mask.slowest,
-		     surface->target, op, source, mask, clip, elapsed);
-    surface->log.mask.elapsed += elapsed;
-
-    if (elapsed > device->log.mask.slowest.elapsed)
-	record_mask (&device->log.mask.slowest,
-		      surface->target, op, source, mask, clip, elapsed);
-    device->log.mask.elapsed += elapsed;
+    add_record_mask (&surface->log,
+		     surface->target, op, source, mask, clip,
+		     elapsed);
+    add_record_mask (&device->log,
+		     surface->target, op, source, mask, clip,
+		     elapsed);
 
     return CAIRO_STATUS_SUCCESS;
 }
 
+static void
+add_record_fill (cairo_observation_t *log,
+		 cairo_surface_t *target,
+		 cairo_operator_t		op,
+		 const cairo_pattern_t		*source,
+		 const cairo_path_fixed_t	*path,
+		 cairo_fill_rule_t		 fill_rule,
+		 double				 tolerance,
+		 cairo_antialias_t		 antialias,
+		 const cairo_clip_t		 *clip,
+		 double elapsed)
+{
+    cairo_observation_record_t record;
+    cairo_int_status_t status;
+
+    record_fill (&record,
+		 target, op, source,
+		 path, fill_rule, tolerance, antialias,
+		 clip, elapsed);
+
+    status = _cairo_surface_fill (&log->record->base,
+				  op, source,
+				  path, fill_rule, tolerance, antialias,
+				  clip);
+    assert (status == CAIRO_INT_STATUS_SUCCESS);
+    add_record (log, &record, log->record->commands.num_elements);
+
+    if (elapsed > log->fill.slowest.elapsed)
+	log->fill.slowest = record;
+    log->fill.elapsed += elapsed;
+}
+
 static cairo_int_status_t
 _cairo_surface_observer_fill (void			*abstract_surface,
 			      cairo_operator_t		op,
@@ -781,23 +904,55 @@ _cairo_surface_observer_fill (void			*abstract_surface,
     sync (surface->target, x, y);
     elapsed = stop_timer (&ts);
 
-    if (elapsed > surface->log.fill.slowest.elapsed)
-	record_fill (&surface->log.fill.slowest,
+    add_record_fill (&surface->log,
 		     surface->target, op, source, path,
 		     fill_rule, tolerance, antialias,
 		     clip, elapsed);
-    surface->log.fill.elapsed += elapsed;
 
-    if (elapsed > device->log.fill.slowest.elapsed)
-	record_fill (&device->log.fill.slowest,
+    add_record_fill (&device->log,
 		     surface->target, op, source, path,
 		     fill_rule, tolerance, antialias,
 		     clip, elapsed);
-    device->log.fill.elapsed += elapsed;
 
     return CAIRO_STATUS_SUCCESS;
 }
 
+static void
+add_record_stroke (cairo_observation_t *log,
+		 cairo_surface_t *target,
+		 cairo_operator_t		 op,
+		 const cairo_pattern_t		*source,
+		 const cairo_path_fixed_t	*path,
+		 const cairo_stroke_style_t	*style,
+		 const cairo_matrix_t		*ctm,
+		 const cairo_matrix_t		*ctm_inverse,
+		 double				 tolerance,
+		 cairo_antialias_t		 antialias,
+		 const cairo_clip_t		*clip,
+		 double elapsed)
+{
+    cairo_observation_record_t record;
+    cairo_int_status_t status;
+
+    record_stroke (&record,
+		   target, op, source,
+		   path, style, ctm,ctm_inverse,
+		   tolerance, antialias,
+		   clip, elapsed);
+
+    status = _cairo_surface_stroke (&log->record->base,
+				    op, source,
+				    path, style, ctm,ctm_inverse,
+				    tolerance, antialias,
+				    clip);
+    assert (status == CAIRO_INT_STATUS_SUCCESS);
+    add_record (log, &record, log->record->commands.num_elements);
+
+    if (elapsed > log->stroke.slowest.elapsed)
+	log->stroke.slowest = record;
+    log->stroke.elapsed += elapsed;
+}
+
 static cairo_int_status_t
 _cairo_surface_observer_stroke (void				*abstract_surface,
 				cairo_operator_t		 op,
@@ -867,25 +1022,54 @@ _cairo_surface_observer_stroke (void				*abstract_surface,
     sync (surface->target, x, y);
     elapsed = stop_timer (&ts);
 
-    if (elapsed > surface->log.stroke.slowest.elapsed)
-	    record_stroke (&surface->log.stroke.slowest,
-			   surface->target, op, source, path,
-			   style, ctm,ctm_inverse,
-			   tolerance, antialias,
-			   clip, elapsed);
-    surface->log.stroke.elapsed += elapsed;
+    add_record_stroke (&surface->log,
+		       surface->target, op, source, path,
+		       style, ctm,ctm_inverse,
+		       tolerance, antialias,
+		       clip, elapsed);
 
-    if (elapsed > device->log.stroke.slowest.elapsed)
-	record_stroke (&device->log.stroke.slowest,
+    add_record_stroke (&device->log,
 		       surface->target, op, source, path,
-		       style, ctm, ctm_inverse,
+		       style, ctm,ctm_inverse,
 		       tolerance, antialias,
 		       clip, elapsed);
-    device->log.stroke.elapsed += elapsed;
 
     return CAIRO_STATUS_SUCCESS;
 }
 
+static void
+add_record_glyphs (cairo_observation_t	*log,
+		   cairo_surface_t	*target,
+		   cairo_operator_t	 op,
+		   const cairo_pattern_t*source,
+		   cairo_glyph_t	*glyphs,
+		   int			 num_glyphs,
+		   cairo_scaled_font_t	*scaled_font,
+		   const cairo_clip_t	*clip,
+		   double elapsed)
+{
+    cairo_observation_record_t record;
+    cairo_int_status_t status;
+
+    record_glyphs (&record,
+		   target, op, source,
+		   glyphs, num_glyphs, scaled_font,
+		   clip, elapsed);
+
+    status = _cairo_surface_show_text_glyphs (&log->record->base, op, source,
+					      NULL, 0,
+					      glyphs, num_glyphs,
+					      NULL, 0, 0,
+					      scaled_font,
+					      clip);
+    assert (status == CAIRO_INT_STATUS_SUCCESS);
+    add_record (log, &record, log->record->commands.num_elements);
+
+    if (elapsed > log->glyphs.slowest.elapsed)
+	log->glyphs.slowest = record;
+    log->glyphs.elapsed += elapsed;
+}
+
 static cairo_int_status_t
 _cairo_surface_observer_glyphs (void			*abstract_surface,
 				cairo_operator_t	 op,
@@ -949,19 +1133,15 @@ _cairo_surface_observer_glyphs (void			*abstract_surface,
     sync (surface->target, x, y);
     elapsed = stop_timer (&ts);
 
-    if (elapsed > surface->log.glyphs.slowest.elapsed)
-	    record_glyphs (&surface->log.glyphs.slowest,
-			   surface->target, op, source,
-			   glyphs, num_glyphs, scaled_font,
-			   clip, elapsed);
-    surface->log.glyphs.elapsed += elapsed;
+    add_record_glyphs (&surface->log,
+		       surface->target, op, source,
+		       glyphs, num_glyphs, scaled_font,
+		       clip, elapsed);
 
-    if (elapsed > device->log.glyphs.slowest.elapsed)
-	record_glyphs (&device->log.glyphs.slowest,
+    add_record_glyphs (&device->log,
 		       surface->target, op, source,
 		       glyphs, num_glyphs, scaled_font,
 		       clip, elapsed);
-    device->log.glyphs.elapsed += elapsed;
 
     return CAIRO_STATUS_SUCCESS;
 }
@@ -1066,8 +1246,6 @@ _cairo_surface_observer_snapshot (void *abstract_surface)
 {
     cairo_surface_observer_t *surface = abstract_surface;
 
-    printf ("taking snapshot\n");
-
     /* XXX hook onto the snapshot so that we measure number of reads */
 
     if (surface->target->backend->snapshot)
@@ -1390,11 +1568,34 @@ static double percent (double a, double b)
 }
 
 static void
+replay_record (cairo_observation_t *log,
+	       cairo_observation_record_t *r,
+	       cairo_device_t *script)
+{
+    cairo_surface_t *surface;
+    cairo_int_status_t status;
+
+    surface = cairo_script_surface_create (script,
+					   r->target_content,
+					   r->target_width,
+					   r->target_height);
+    status =
+	_cairo_recording_surface_replay_one (log->record, r->index, surface);
+    cairo_surface_destroy (surface);
+
+    assert (status == CAIRO_INT_STATUS_SUCCESS);
+}
+
+static void
 _cairo_observation_print (cairo_output_stream_t *stream,
 			  cairo_observation_t *log)
 {
+    cairo_device_t *script;
     double total;
 
+    script = _cairo_script_context_create_internal (stream);
+    _cairo_script_context_attach_snapshots (script, FALSE);
+
     _cairo_output_stream_printf (stream, "surfaces: %d\n",
 				 log->num_surfaces);
     _cairo_output_stream_printf (stream, "contexts: %d\n",
@@ -1425,6 +1626,8 @@ _cairo_observation_print (cairo_output_stream_t *stream,
 	print_record (stream, &log->paint.slowest);
 
 	_cairo_output_stream_printf (stream, "\n");
+	replay_record (log, &log->paint.slowest, script);
+	_cairo_output_stream_printf (stream, "\n\n");
     }
 
     _cairo_output_stream_printf (stream, "mask: count %d [no-op %d], elapsed %f [%f%%]\n",
@@ -1444,6 +1647,8 @@ _cairo_observation_print (cairo_output_stream_t *stream,
 	print_record (stream, &log->mask.slowest);
 
 	_cairo_output_stream_printf (stream, "\n");
+	replay_record (log, &log->mask.slowest, script);
+	_cairo_output_stream_printf (stream, "\n\n");
     }
 
     _cairo_output_stream_printf (stream, "fill: count %d [no-op %d], elaspsed %f [%f%%]\n",
@@ -1465,6 +1670,8 @@ _cairo_observation_print (cairo_output_stream_t *stream,
 	print_record (stream, &log->fill.slowest);
 
 	_cairo_output_stream_printf (stream, "\n");
+	replay_record (log, &log->fill.slowest, script);
+	_cairo_output_stream_printf (stream, "\n\n");
     }
 
     _cairo_output_stream_printf (stream, "stroke: count %d [no-op %d], elapsed %f [%f%%]\n",
@@ -1487,6 +1694,8 @@ _cairo_observation_print (cairo_output_stream_t *stream,
 	print_record (stream, &log->stroke.slowest);
 
 	_cairo_output_stream_printf (stream, "\n");
+	replay_record (log, &log->stroke.slowest, script);
+	_cairo_output_stream_printf (stream, "\n\n");
     }
 
     _cairo_output_stream_printf (stream, "glyphs: count %d [no-op %d], elasped %f [%f%%]\n",
@@ -1505,7 +1714,11 @@ _cairo_observation_print (cairo_output_stream_t *stream,
 	print_record (stream, &log->glyphs.slowest);
 
 	_cairo_output_stream_printf (stream, "\n");
+	replay_record (log, &log->glyphs.slowest, script);
+	_cairo_output_stream_printf (stream, "\n\n");
     }
+
+    cairo_device_destroy (script);
 }
 
 void