[gimp] Add additional profiling to tile usage.
- From: Sven Neumann <neo src gnome org>
- To: svn-commits-list gnome org
- Subject: [gimp] Add additional profiling to tile usage.
- Date: Thu, 4 Jun 2009 06:18:50 -0400 (EDT)
commit ac51a588d643e61bd21e444d93690a1a392a536f
Author: Monty <xiphmont gmail com>
Date: Tue May 26 04:39:10 2009 -0400
Add additional profiling to tile usage.
Add more profiling In order to analyze efficiency and behavior of the
tile cache. Profiling includes run-time indication of idle swapper
activity.
Also, fixes to original tile profiling code that appears to have
bitrotted some; it was no longer tracking changes made to tile memory
outside of tile.c.
---
app/base/tile-cache.c | 72 ++++++++++++++++++++--
app/base/tile-manager.c | 12 ++++
app/base/tile-private.h | 14 ++++
app/base/tile-swap.c | 158 +++++++++++++++++++++++++++++++++++++++++++++-
app/base/tile.c | 14 ++---
5 files changed, 252 insertions(+), 18 deletions(-)
diff --git a/app/base/tile-cache.c b/app/base/tile-cache.c
index 6fd47fd..170588b 100644
--- a/app/base/tile-cache.c
+++ b/app/base/tile-cache.c
@@ -51,6 +51,14 @@ static TileList clean_list = { NULL, NULL };
static TileList dirty_list = { NULL, NULL };
static guint idle_swapper = 0;
+#ifdef TILE_PROFILING
+extern gulong tile_idle_swapout;
+extern gulong tile_total_zorched;
+extern gulong tile_total_zorched_swapout;
+extern glong tile_total_interactive_sec;
+extern glong tile_total_interactive_usec;
+extern gint tile_exist_count;
+#endif
#ifdef ENABLE_MP
@@ -154,14 +162,43 @@ tile_cache_insert (Tile *tile)
* cache is smaller than the size of a tile in which case
* it won't be possible to put it in the cache.
*/
- while ((cur_cache_size + max_tile_size) > max_cache_size)
+
+#ifdef TILE_PROFILING
+ if ((cur_cache_size + tile->size) > max_cache_size)
{
- if (! tile_cache_zorch_next ())
+ GTimeVal now;
+ GTimeVal later;
+ g_get_current_time(&now);
+#endif
+
+ while ((cur_cache_size + max_tile_size) > max_cache_size)
{
- g_warning ("cache: unable to find room for a tile");
- goto out;
+ if (! tile_cache_zorch_next ())
+ {
+ g_warning ("cache: unable to find room for a tile");
+ goto out;
+ }
}
+
+#ifdef TILE_PROFILING
+ g_get_current_time(&later);
+ tile_total_interactive_usec += later.tv_usec - now.tv_usec;
+ tile_total_interactive_sec += later.tv_sec - now.tv_sec;
+
+ if (tile_total_interactive_usec < 0)
+ {
+ tile_total_interactive_usec += 1000000;
+ tile_total_interactive_sec--;
+ }
+
+ if (tile_total_interactive_usec > 1000000)
+ {
+ tile_total_interactive_usec -= 1000000;
+ tile_total_interactive_sec++;
+ }
+
}
+#endif
cur_cache_size += tile->size;
}
@@ -186,6 +223,10 @@ tile_cache_insert (Tile *tile)
if (! idle_swapper &&
cur_cache_dirty * 2 > max_cache_size)
{
+
+#ifdef TILE_PROFILING
+ g_printerr("idle swapper -> running");
+#endif
idle_swapper = g_timeout_add_full (G_PRIORITY_LOW,
IDLE_SWAPPER_TIMEOUT,
tile_idle_preswap,
@@ -264,6 +305,16 @@ tile_cache_zorch_next (void)
else
return FALSE;
+#ifdef TILE_PROFILING
+ tile_total_zorched++;
+ tile->zorched = TRUE;
+ if (tile->dirty || tile->swap_offset == -1)
+ {
+ tile_total_zorched_swapout++;
+ tile->zorchout = TRUE;
+ }
+#endif
+
tile_cache_flush_internal (tile);
if (tile->dirty || tile->swap_offset == -1)
@@ -275,7 +326,9 @@ tile_cache_zorch_next (void)
{
g_free (tile->data);
tile->data = NULL;
-
+#ifdef TILE_PROFILING
+ tile_exist_count--;
+#endif
return TRUE;
}
@@ -290,6 +343,9 @@ tile_idle_preswap (gpointer data)
if (cur_cache_dirty * 2 < max_cache_size)
{
+#ifdef TILE_PROFILING
+ g_printerr("\nidle swapper -> stopped\n");
+#endif
idle_swapper = 0;
return FALSE;
}
@@ -298,6 +354,12 @@ tile_idle_preswap (gpointer data)
if ((tile = dirty_list.first))
{
+
+#ifdef TILE_PROFILING
+ g_printerr(".");
+ tile_idle_swapout++;
+#endif
+
tile_swap_out (tile);
dirty_list.first = tile->next;
diff --git a/app/base/tile-manager.c b/app/base/tile-manager.c
index b713e97..6e4d1d3 100644
--- a/app/base/tile-manager.c
+++ b/app/base/tile-manager.c
@@ -34,6 +34,10 @@
static void tile_manager_allocate_tiles (TileManager *tm);
+#ifdef TILE_PROFILING
+extern gint tile_exist_peak;
+extern gint tile_exist_count;
+#endif
GType
gimp_tile_manager_get_type (void)
@@ -199,6 +203,11 @@ tile_manager_get (TileManager *tm,
new->size = new->ewidth * new->eheight * new->bpp;
new->data = g_new (guchar, new->size);
+#ifdef TILE_PROFILING
+ tile_exist_count++;
+ if (tile_exist_count > tile_exist_peak)
+ tile_exist_peak = tile_exist_count;
+#endif
if (tile->rowhint)
{
@@ -364,6 +373,9 @@ tile_manager_invalidate_tile (TileManager *tm,
{
g_free (tile->data);
tile->data = NULL;
+#ifdef TILE_PROFILING
+ tile_exist_count--;
+#endif
}
if (tile->swap_offset != -1)
diff --git a/app/base/tile-private.h b/app/base/tile-private.h
index 8021278..d900c03 100644
--- a/app/base/tile-private.h
+++ b/app/base/tile-private.h
@@ -18,6 +18,9 @@
#ifndef __TILE_PRIVATE_H__
#define __TILE_PRIVATE_H__
+/* Uncomment to enable global counters to profile the tile system. */
+/* #define TILE_PROFILING */
+
#include <sys/types.h>
typedef struct _TileLink TileLink;
@@ -48,6 +51,17 @@ struct _Tile
guint dirty : 1; /* is the tile dirty? has it been modified? */
guint valid : 1; /* is the tile valid? */
+#ifdef TILE_PROFILING
+
+ guint zorched : 1; /* was the tile flushed due to cache pressure
+ [zorched]? */
+ guint zorchout: 1; /* was the tile swapped out due to cache
+ pressure [zorched]? */
+ guint inonce : 1; /* has the tile been swapped in at least once? */
+ guint outonce : 1; /* has the tile been swapped out at least once? */
+
+#endif
+
guchar bpp; /* the bytes per pixel (1, 2, 3 or 4) */
gushort ewidth; /* the effective width of the tile */
gushort eheight; /* the effective height of the tile
diff --git a/app/base/tile-swap.c b/app/base/tile-swap.c
index 1894987..b19d211 100644
--- a/app/base/tile-swap.c
+++ b/app/base/tile-swap.c
@@ -53,7 +53,6 @@
#include "gimp-intl.h"
-
typedef enum
{
SWAP_IN = 1,
@@ -116,6 +115,39 @@ static gboolean seek_err_msg = TRUE;
static gboolean read_err_msg = TRUE;
static gboolean write_err_msg = TRUE;
+#ifdef TILE_PROFILING
+static gulong tile_total_seek = 0;
+
+/* how many tiles were swapped out under cache pressure but never
+ swapped back in? This does not count idle swapped tiles, as those
+ do not contribute to any perceived load or latency */
+static gulong tile_total_wasted_swapout = 0;
+
+/* total tile flushes under cache pressure */
+gulong tile_total_zorched = 0;
+gulong tile_total_zorched_swapout = 0;
+static gulong tile_total_zorched_swapin = 0;
+
+/* total tiles swapped out to swap file (not total calls to swap out;
+ this only counts actual flushes to disk) */
+static gulong tile_total_swapout = 0;
+static gulong tile_unique_swapout = 0;
+gulong tile_idle_swapout = 0;
+
+/* total tiles swapped in from swap file (not total calls to swap in;
+ this only counts actual tile reads from disk) */
+static gulong tile_total_swapin = 0;
+static gulong tile_unique_swapin = 0;
+
+/* total dead time spent waiting to read or write */
+static glong tile_total_swapwait_sec = 0;
+static glong tile_total_swapwait_usec = 0;
+
+/* total time spent in tile cache due to cache pressure */
+glong tile_total_interactive_sec = 0;
+glong tile_total_interactive_usec = 0;
+
+#endif
#ifdef G_OS_WIN32
@@ -191,11 +223,29 @@ tile_swap_init (const gchar *path)
void
tile_swap_exit (void)
{
-#ifdef HINTS_SANITY
+
+#ifdef TILE_PROFILING
extern int tile_exist_peak;
- g_printerr ("Tile exist peak was %d Tile structs (%d bytes)",
- tile_exist_peak, tile_exist_peak * sizeof(Tile));
+ g_printerr ("\n\nPeak Tile usage: %d Tile structs\n\n",
+ tile_exist_peak);
+
+ g_printerr ("Total tiles swapped out to disk: %lu\n",tile_total_swapout);
+ g_printerr ("Unique tiles swapped out to disk: %lu\n",tile_unique_swapout);
+ g_printerr ("Total tiles swapped in from disk: %lu\n",tile_total_swapin);
+ g_printerr ("Unique tiles swapped in from disk: %lu\n",tile_unique_swapin);
+ g_printerr ("Tiles swapped out by idle swapper: %lu\n",tile_idle_swapout);
+ g_printerr ("Total seeks during swapping: %lu\n",tile_total_seek);
+ g_printerr ("Total time spent in swap: %f seconds\n\n",
+ tile_total_swapwait_sec+.000001*tile_total_swapwait_usec);
+
+ g_printerr ("Total zorched tiles: %lu\n",tile_total_zorched);
+ g_printerr ("Total zorched tiles swapped out: %lu\n",tile_total_zorched_swapout);
+ g_printerr ("Total zorched tiles swapped back in: %lu\n",tile_total_zorched_swapin);
+ g_printerr ("Total zorched tiles wasted after swapping out: %lu\n",tile_total_wasted_swapout);
+ g_printerr ("Total interactive swap/cache delay: %f seconds\n\n",
+ tile_total_interactive_sec+.000001*tile_total_interactive_usec);
+
#endif
if (tile_global_refcount () != 0)
@@ -316,14 +366,35 @@ tile_swap_default_in (SwapFile *swap_file,
{
gint nleft;
gint64 offset;
+#ifdef TILE_PROFILING
+ GTimeVal now;
+ GTimeVal later;
+#endif
if (tile->data)
return;
+#ifdef TILE_PROFILING
+ g_get_current_time(&now);
+ tile_total_swapin++;
+
+ if (tile->zorched)
+ tile_total_zorched_swapin++;
+
+ if (!tile->inonce)
+ tile_unique_swapin++;
+
+ tile->inonce = TRUE;
+#endif
+
if (swap_file->cur_position != tile->swap_offset)
{
swap_file->cur_position = tile->swap_offset;
+#ifdef TILE_PROFILING
+ tile_total_seek++;
+#endif
+
offset = LARGE_SEEK (swap_file->fd, tile->swap_offset, SEEK_SET);
if (offset == -1)
{
@@ -361,6 +432,42 @@ tile_swap_default_in (SwapFile *swap_file,
nleft -= err;
}
+#ifdef TILE_PROFILING
+ g_get_current_time(&later);
+ tile_total_swapwait_usec += later.tv_usec - now.tv_usec;
+ tile_total_swapwait_sec += later.tv_sec - now.tv_sec;
+
+ if (tile_total_swapwait_usec < 0)
+ {
+ tile_total_swapwait_usec += 1000000;
+ tile_total_swapwait_sec--;
+ }
+
+ if (tile_total_swapwait_usec > 1000000)
+ {
+ tile_total_swapwait_usec -= 1000000;
+ tile_total_swapwait_sec++;
+ }
+
+ tile_total_interactive_usec += later.tv_usec - now.tv_usec;
+ tile_total_interactive_sec += later.tv_sec - now.tv_sec;
+
+ if (tile_total_interactive_usec < 0)
+ {
+ tile_total_interactive_usec += 1000000;
+ tile_total_interactive_sec--;
+ }
+
+ if (tile_total_interactive_usec > 1000000)
+ {
+ tile_total_interactive_usec -= 1000000;
+ tile_total_interactive_sec++;
+ }
+
+ tile->zorched = FALSE;
+ tile->zorchout = FALSE;
+#endif
+
swap_file->cur_position += tile->size;
/* Do not delete the swap from the file */
@@ -377,6 +484,17 @@ tile_swap_default_out (SwapFile *swap_file,
gint nleft;
gint64 offset;
gint64 newpos;
+#ifdef TILE_PROFILING
+ GTimeVal now;
+ GTimeVal later;
+ g_get_current_time(&now);
+ tile_total_swapout++;
+
+ if (!tile->outonce)
+ tile_unique_swapout++;
+
+ tile->outonce = TRUE;
+#endif
bytes = TILE_WIDTH * TILE_HEIGHT * tile->bpp;
@@ -388,6 +506,11 @@ tile_swap_default_out (SwapFile *swap_file,
if (swap_file->cur_position != newpos)
{
+
+#ifdef TILE_PROFILING
+ tile_total_seek++;
+#endif
+
offset = LARGE_SEEK (swap_file->fd, newpos, SEEK_SET);
if (offset == -1)
@@ -420,6 +543,25 @@ tile_swap_default_out (SwapFile *swap_file,
nleft -= err;
}
+#ifdef TILE_PROFILING
+ g_get_current_time(&later);
+ tile_total_swapwait_usec += later.tv_usec - now.tv_usec;
+ tile_total_swapwait_sec += later.tv_sec - now.tv_sec;
+
+ if (tile_total_swapwait_usec < 0)
+ {
+ tile_total_swapwait_usec += 1000000;
+ tile_total_swapwait_sec--;
+ }
+
+ if (tile_total_swapwait_usec > 1000000)
+ {
+ tile_total_swapwait_usec -= 1000000;
+ tile_total_swapwait_sec++;
+ }
+
+#endif
+
swap_file->cur_position += tile->size;
/* Do NOT free tile->data because we may be pre-swapping.
@@ -445,6 +587,14 @@ tile_swap_default_delete (SwapFile *swap_file,
if (tile->swap_offset == -1)
return;
+#ifdef TILE_PROFILING
+ if (tile->zorchout)
+ tile_total_wasted_swapout++;
+
+ tile->zorched=FALSE;
+ tile->zorchout=FALSE;
+#endif
+
start = tile->swap_offset;
end = start + TILE_WIDTH * TILE_HEIGHT * tile->bpp;
tile->swap_offset = -1;
diff --git a/app/base/tile.c b/app/base/tile.c
index 0abb3ce..88d3b37 100644
--- a/app/base/tile.c
+++ b/app/base/tile.c
@@ -32,10 +32,6 @@
/* Uncomment for verbose debugging on copy-on-write logic */
/* #define TILE_DEBUG */
-/* Uncomment to enable global counters to profile the tile system. */
-/* #define TILE_PROFILING */
-
-
/* This is being used from tile-swap, but just for debugging purposes. */
static gint tile_ref_count = 0;
@@ -46,15 +42,14 @@ static gint tile_count = 0;
static gint tile_share_count = 0;
static gint tile_active_count = 0;
-static gint tile_exist_peak = 0;
-static gint tile_exist_count = 0;
+gint tile_exist_peak = 0;
+gint tile_exist_count = 0;
#endif
static void tile_destroy (Tile *tile);
-
Tile *
tile_new (gint bpp)
{
@@ -193,6 +188,9 @@ tile_destroy (Tile *tile)
{
g_free (tile->data);
tile->data = NULL;
+#ifdef TILE_PROFILING
+ tile_exist_count--;
+#endif
}
if (tile->rowhint)
{
@@ -213,8 +211,6 @@ tile_destroy (Tile *tile)
#ifdef TILE_PROFILING
tile_count--;
-
- tile_exist_count--;
#endif
}
[
Date Prev][
Date Next] [
Thread Prev][
Thread Next]
[
Thread Index]
[
Date Index]
[
Author Index]
