GNOME.org
 

Signal emission far to slow

I have for some time now had a bad feeling about the performance of
Gtk+ 2 and Gnome 2. As GObject becomes more used in all kinds of
situation (not just UI stuff) the performance of GType/GObject, and in
particular the signal emission performance, affects the total system
performance in a large way. For instance, I'm using GObject to
implement the document model in my private project, and a poorly
performing GObject would mean that the core of the program is
inheritly slow, and I might have to reconsider if I really want to use
GObject.

So, I set out to do some performance measurments on the current CVS
version of glib signal emission versus the Gtk+ 1.2 signal emission. I
wrote an app (attached) that compiles both under 1.2 and 2.0. It uses
the GtkObject wrappers instead of GObject/GSignal, but that shouldn't
affect performance in any major way, and it is in fact the way most of
the current Gtk+ code uses signals.

The test program derives GtkTest from GtkObject and adds three
signals. One that takes no parameter, one that takes an int and one
that takes a string. Then it proceeds to emit these signals 100000
times each, by name and by id, for the case of 0, 1 and 10 connected
handlers.

Note that i compiled both glib and gtk+ from CVS using
--enable-debug=minimum so that it shows the performance a stable Gtk+
2 release would have.

Here is the output from the Gtk+ 1.2 version:

Testing signal emissions with no installed handlers
===================================================
100000 nop emits by name in 221 milliseconds
100000 integer emits by name in 228 milliseconds
100000 string emits by name in 226 milliseconds
100000 nop emits by id in 98 milliseconds
100000 integer emits by id in 102 milliseconds
100000 string emits by id in 103 milliseconds

Testing signal emissions with one null handler
==============================================
100000 nop emits by name in 341 milliseconds
100000 integer emits by name in 345 milliseconds
100000 string emits by name in 337 milliseconds
100000 nop emits by id in 191 milliseconds
100000 integer emits by id in 193 milliseconds
100000 string emits by id in 194 milliseconds

Testing signal emissions with ten null handlers
===============================================
100000 nop emits by name in 794 milliseconds
100000 integer emits by name in 787 milliseconds
100000 string emits by name in 756 milliseconds
100000 nop emits by id in 632 milliseconds
100000 integer emits by id in 629 milliseconds
100000 string emits by id in 603 milliseconds

Here is the output from the Gtk+ 2 version:

Testing signal emissions with no installed handlers
===================================================
100000 nop emits by name in 1434 milliseconds
100000 integer emits by name in 1696 milliseconds
100000 string emits by name in 1769 milliseconds
100000 nop emits by id in 956 milliseconds
100000 integer emits by id in 1180 milliseconds
100000 string emits by id in 1648 milliseconds

Testing signal emissions with one null handler
==============================================
100000 nop emits by name in 1663 milliseconds
100000 integer emits by name in 2010 milliseconds
100000 string emits by name in 2100 milliseconds
100000 nop emits by id in 1178 milliseconds
100000 integer emits by id in 1541 milliseconds
100000 string emits by id in 2129 milliseconds

Testing signal emissions with ten null handlers
===============================================
100000 nop emits by name in 2847 milliseconds
100000 integer emits by name in 3747 milliseconds
100000 string emits by name in 3901 milliseconds
100000 nop emits by id in 2354 milliseconds
100000 integer emits by id in 3280 milliseconds
100000 string emits by id in 3914 milliseconds

Lets inspect the nop signal emitted by id a bit closer.
In Gtk+ 1.2 emission with no handler takes 98 ms, and with 10 handlers
534 ms more. I 2.0 emission takes 956 ms, and 10 handlers an
additional 1398 ms.

This seems to imply that raw signal emission is ten times slower in
Gtk+ 2, and calling signal handlers is 2.6 times slower.

The fact that the null signal emission (no handlers executed) is so
expensive will cause performance problems with the current design of
my private project, and I sincerely hope this can be fixed.

Another interesting problem that can be seen here is the large
difference in performance when emitting the nop versus the string
signal in with ten handlers. Passing (and probably duplication) of the
string in the string signal emission makes calling the string handler
twice as slow as the nop one.

Wanting to get a grip on the cause of these problems I ran the test
program under a sampling profiler. Watching the profiler shows the
huge difference in complexity between the signal systems, but gives no
obvious bottle neck for the GObject case.

For 1.2 we have:
(this is basically the whole profile, except main and startup):
gtk_signal_emit_by_name - 26%
gtk_signal_emit - 20%
gtk_signal_real_emit - 19%
g_quark_try_string 5%
gtk_signal_lookup 5%

For 2.0 we get a much larger profile, but it starts like this:
signal_emit_R - 10%
g_signal_emit_valist - 9%
g_value_peek_pointer - 7%
gtk_signal_emitv - 7%
gtk_signal_emit_by_name - 6%
g_signal_emitv - 5%
g_value_type_compatible - 5%
g_type_value_table_peek - 5%
g_closure_invoke - 5%
gtk_signal_emit - 4%
_type_check_value_holds - 4%
g_value_unset - 3.5%
g_value_init - 3%
g_type_check_value - 3%
g_type_is_a 3%
g_value_set_object - 2.5%
g_object_unref - 2.5%
g_hash_table_unref - 2.5%
.... and a lot more function under 2.5%

There is no obvious target here, except the fact that there seems to
be a whole lot of g_value shuffling going on that might be possible to
get rid of (I think tim mentioned this at GUADEC).

/ Alex


#include <sys/time.h>
#include <unistd.h>

#include <gtk/gtkobject.h>
#include <gtk/gtksignal.h>

#define NUMEMITS 100000

#define GTK_TYPE_TEST            (gtk_test_get_type ())
#define GTK_TEST(obj)            (GTK_SEPARATOR_CAST ((obj), GTK_TYPE_TEST, GtkTest))
#define GTK_TEST_CLASS(klass)    (GTK_SEPARATOR_CLASS_CAST ((klass), GTK_TYPE_TEST, GtkTestClass))
#define GTK_IS_TEST(obj)         (GTK_SEPARATOR_TYPE ((obj), GTK_TYPE_TEST))
#define GTK_IS_TEST_CLASS(klass) (GTK_SEPARATOR_CLASS_TYPE ((klass), GTK_TYPE_TEST))
#define GTK_TEST_GET_CLASS(obj)  (GTK_SEPARATOR_GET_CLASS ((obj), GTK_TYPE_TEST, GtkTestClass))

enum {
  NOP,
  INTEGER,
  STRING,
  LAST_SIGNAL
};

static guint signals[LAST_SIGNAL] = { 0 };

typedef struct _GtkTest       GtkTest;
typedef struct _GtkTestClass  GtkTestClass;

struct _GtkTest
{
  GtkObject object;
};

struct _GtkTestClass
{
  GtkObjectClass parent_class;

  void (*nop) (GtkTest *test);
  void (*integer) (GtkTest *test, int i);
  void (*string) (GtkTest *test, char *string);
};


GtkType	   gtk_test_get_type	   (void) G_GNUC_CONST;
GtkObject* gtk_test_new	           (void);

static void gtk_test_class_init (GtkTestClass *klass);

static GtkObjectClass *parent_class;

GtkType
gtk_test_get_type (void)
{
  static GtkType type = 0;

  if (!type)
    {
#ifdef GTK2
      static const GTypeInfo test_info =
      {
	sizeof (GtkTestClass),
	NULL,           /* base_init */
	NULL,           /* base_finalize */
	(GClassInitFunc) gtk_test_class_init,
	NULL,           /* class_finalize */
	NULL,           /* class_data */
	sizeof (GtkTest),
	16,             /* n_preallocs */
	(GInstanceInitFunc) NULL,
      };

      type = g_type_register_static (GTK_TYPE_OBJECT, "GtkTest", &test_info, 0);
#else
      static GtkTypeInfo info = {
	"GtkTest",
	sizeof (GtkTest),
	sizeof (GtkTestClass),
	(GtkClassInitFunc)gtk_test_class_init,
	(GtkObjectInitFunc)NULL,
	NULL,
	NULL,
	NULL
      };
      
      type = gtk_type_unique (GTK_TYPE_OBJECT, &info);
#endif
    }

  return type;
}

static void
gtk_test_class_init (GtkTestClass *klass)
{
  parent_class = gtk_type_class (gtk_menu_item_get_type ());

  signals[NOP] =
    gtk_signal_new ("nop",
		    GTK_RUN_LAST,
		    GTK_TYPE_TEST,
		    GTK_SIGNAL_OFFSET (GtkTestClass, nop),
		    gtk_marshal_NONE__NONE,
		    GTK_TYPE_NONE, 0);
  signals[INTEGER] =
    gtk_signal_new ("integer",
		    GTK_RUN_LAST,
		    GTK_TYPE_TEST,
		    GTK_SIGNAL_OFFSET (GtkTestClass, integer),
		    gtk_marshal_NONE__INT,
		    GTK_TYPE_NONE, 1,
		    GTK_TYPE_INT);
  signals[STRING] =
    gtk_signal_new ("string",
		    GTK_RUN_LAST,
		    GTK_TYPE_TEST,
		    GTK_SIGNAL_OFFSET (GtkTestClass, string),
#ifdef GTK2
		    gtk_marshal_VOID__STRING,
#else
		    gtk_marshal_NONE__STRING,
#endif
		    GTK_TYPE_NONE, 1,
		    GTK_TYPE_STRING);

#if GTK12
  gtk_object_class_add_signals (GTK_OBJECT_CLASS (klass),
				signals, LAST_SIGNAL);
#endif
}

GtkObject*
gtk_test_new (void)
{
  return GTK_OBJECT (gtk_type_new (gtk_test_get_type ()));
}

static int
duration (struct timeval *t1, struct timeval *t2)
{
  return (t2->tv_sec-t1->tv_sec)*1000 + (t2->tv_usec - t1->tv_usec)/1000;
}

static void
do_tests (GtkObject *test)
{
  int i;
  guint id;
  struct timeval t1, t2;
  
  /* By name: */
  
  gettimeofday (&t1, NULL);
  for (i=0;i<NUMEMITS;i++)
    gtk_signal_emit_by_name (test, "nop");
  gettimeofday (&t2, NULL);
  g_print ("%d nop emits by name in %d milliseconds\n",
	   NUMEMITS, duration (&t1, &t2));
  
  gettimeofday (&t1, NULL);
  for (i=0;i<NUMEMITS;i++)
    gtk_signal_emit_by_name (test, "integer", 42);
  gettimeofday (&t2, NULL);
  g_print ("%d integer emits by name in %d milliseconds\n",
	   NUMEMITS, duration (&t1, &t2));
  
  gettimeofday (&t1, NULL);
  for (i=0;i<NUMEMITS;i++)
    gtk_signal_emit_by_name (test, "string", "A string of normal length");
  gettimeofday (&t2, NULL);
  g_print ("%d string emits by name in %d milliseconds\n",
	   NUMEMITS, duration (&t1, &t2));

  /* By id: */

  id = gtk_signal_lookup ("nop", GTK_TYPE_TEST);
  gettimeofday (&t1, NULL);
  for (i=0;i<NUMEMITS;i++)
    gtk_signal_emit (test, id);
  gettimeofday (&t2, NULL);
  g_print ("%d nop emits by id in %d milliseconds\n",
	   NUMEMITS, duration (&t1, &t2));
  
  id = gtk_signal_lookup ("integer", GTK_TYPE_TEST);
  gettimeofday (&t1, NULL);
  for (i=0;i<NUMEMITS;i++)
    gtk_signal_emit (test, id, 42);
  gettimeofday (&t2, NULL);
  g_print ("%d integer emits by id in %d milliseconds\n",
	   NUMEMITS, duration (&t1, &t2));
  
  id = gtk_signal_lookup ("string", GTK_TYPE_TEST);
  gettimeofday (&t1, NULL);
  for (i=0;i<NUMEMITS;i++)
    gtk_signal_emit (test, id, "A string of normal length");
  gettimeofday (&t2, NULL);
  g_print ("%d string emits by id in %d milliseconds\n",
	   NUMEMITS, duration (&t1, &t2));
}


static void
nop_handler (GtkTest *test, gpointer data)
{
  /*g_print ("nop handler\n");*/
}
     
static void
int_handler (GtkTest *test, int integer, gpointer data)
{
  /*g_print ("integer handler %d\n", integer);*/
}
     
static void
string_handler (GtkTest *test, char *string, gpointer data)
{
  /*g_print ("string handler %s\n", string);*/
}
     

int
main (int argc, char *argv)
{
  GtkObject *test;
  int i;
  
#ifdef GTK2
  gtk_type_init (0);
#else
  gtk_type_init ();
#endif

  test = gtk_test_new ();

  g_print ("Testing signal emissions with no installed handlers\n");
  g_print ("===================================================\n");
  do_tests (test);

  g_print ("\n");
  g_print ("Testing signal emissions with one null handler\n");
  g_print ("==============================================\n");
  gtk_signal_connect (test, "nop", nop_handler, NULL);
  gtk_signal_connect (test, "integer", int_handler, NULL);
  gtk_signal_connect (test, "string", string_handler, NULL);
  do_tests (test);
  
  g_print ("\n");
  g_print ("Testing signal emissions with ten null handlers\n");
  g_print ("===============================================\n");
  for (i=0;i<9;i++)
    {
      gtk_signal_connect (test, "nop", nop_handler, NULL);
      gtk_signal_connect (test, "integer", int_handler, NULL);
      gtk_signal_connect (test, "string", string_handler, NULL);
    }
  do_tests (test);
}

all: perf2 perf12

perf2: perftest.c
	gcc `pkg-config --cflags --libs gtk+-2.0` -O2 -DGTK2 perftest.c -o perf2

perf12: perftest.c
	gcc `gtk-config --cflags --libs` -O2 -DGTK12 perftest.c -o perf12
[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]