Re: Dispatch of GObject virtual functions in GtkMM



On 1/27/07, Murray Cumming <murrayc murrayc com> wrote:
Did you ever get this to work?

I really like to know if there really are performance problems
associated with the callbacks, so we can fix them if necessary.

On Fri, 2007-01-12 at 21:58 +0100, Murray Cumming wrote:
> On Thu, 2007-01-11 at 08:20 -0600, Matt Hoosier wrote:
> > Oh, sorry; typographical errors didn't make my meaning very clear.
> >
> > The test program which I attached earlier
>
> Of course I had to comment out the on_expose_event() method, because it
> calls the now non-existant Window::on_expose_event(). I found it rather
> odd that it called Main::quit() anyway.
>
> >  hangs forever on the
> > Window::add() call.
>
> It works for me. It shows a matrix of buttons and checkboxes.
>
> I built glibmm with
>   --enable-vfuncs=no --enable-default-signal-handlers=no
> and then I rebuilt gtkmm with
>   --enable-demos=no --enable-examples=no
>
> Could you post your exact test case and also the stacktrace, please.
>
> Another thought: If these slowdowns are real and significant, then you
> could invesigate them with a tool such as kcachegrind (after getting the
> data from valgrind). kcachegrind isn't useful for IO-bound performance
> problems, but should be fine for this.
>
> >  When I take a look at the stacktrace in a
> > debugger, the results make no sense:
> >
> > There's only one thread, and none of the frames in its stack are
> > resolvable to any known symbol. Not even the bottommost one, which
> > should be main().
> >
> > This is the exact set of symptoms that showed up when I was debugging
> > the problem in glibmm which turned out to be caused by a wrong
> > C_GNUC_NORETURN annotation.
> >
> > But none of the various overrides of Container::add() seems to put
> > that annotation on, so I'm out of obvious suspects to consider.

Okay, I've got this all figured out. For some reason the glibc dynamic
loader on my target ARM hardware wasn't respecting  the value of
LD_LIBRARY_PATH nor the contents of /etc/ld.so.conf. So my custom
build of glibmm/gtkmm that had default signal handlers removed wasn't
found at runtime, and the C++ vtables and class layouts were all
messed up w.r.t. the sizes known at compile-time.

Just a refresher: the example program is one which instantiates a few
tens of compound widgets (each internally having buttons, labels,
alignments, etc) and adds them into a table. I wrote both a Gtk and
Gtkmm version of this to test the overhead imposed by the virtual
function dispatch needed to allow overriding things like
Widget::on_expose_event().

In the following data sets, the timestamp appearing on the left of
each output line is the second and millisecond at which some milestone
occurred:

Gtk+ 2.8.20:
------------
# ./forker ./gtk-table
810.636: forking...
810.706: main gets control
810.830: starting construction
811.102: construction finished
811.742: first expose

 Time to construct and add all widgets: 811.102 - 810.830 = .272 seconds

Gtkmm without default signal handlers:
--------------------------------

# ./forker gtkmm-table
443.456: forking...
443.799: main gets control
443.995: starting construction
444.366: construction finished
445.093: first expose

 Time to construct and add all widgets: 444.366 - 443.995 = .371 seconds

Gtkmm with default signal handlers:
-----------------------------

# ./forker ./gtkmm-table
736.275: forking...
736.604: main gets control
736.801: starting construction
737.253: construction finished
738.074: first expose

 Time to construct and add all widgets: .452 seconds

So here I think my original claim (that default signal handlers almost
double [.452 ~= 2 * .272] the time to perform method calls on the
widgets). The phase that I'm most interested in was the time to
instantiate widgets and add them into the parents. Removing the
default signal handlers helped matters a little: the overhead dropped
by .8 sec, but it's still significantly higher than the equivalent
Gtk+ vfunc calls by a full sec (.272 vs. .371).

I don't want to belabor things too much, but it might also be worth
nothing that Gtk+ on _this_ (isolated, not perhaps very
representative) test case is close to the magical 200 ms threshold
which is generally regarded as the "tolerable" delay in UI's.
Calibrating things as a delta from that point, gtkmm method dispatch
can impose significant perceptible delay.

I'm re-attaching the sources to the program used to generate the
metric above. Murray: to answer your earlier confusion about callling
"gtk_main_quit()" inside the expose handlers, I did this just to
automate the closing of the window. None of the timing information
after first on-screen appearance is relevant for this test.

--Matt
>
--
Murray Cumming
murrayc murrayc com
www.murrayc.com
www.openismus.com


#include <gtk/gtkbox.h>
#include <gtk/gtkbutton.h>
#include <gtk/gtkcheckbutton.h>
#include <gtk/gtkmain.h>
#include <gtk/gtktable.h>
#include <gtk/gtkwindow.h>

#include <sys/time.h>

#define ROWS    5
#define COLUMNS 5

static GtkWidget *
create_table_item (guint index)
{
    GtkWidget * item = NULL;
    gchar * label = g_strdup_printf ("%d", index);

    item = gtk_vbox_new (FALSE, 0);

    GtkWidget * top = gtk_hbox_new (FALSE, 0);
    GtkWidget * bottom = gtk_hbox_new (FALSE, 0);

    gtk_container_add (GTK_CONTAINER (item), top);
    gtk_container_add (GTK_CONTAINER (item), bottom);

    gtk_container_add (GTK_CONTAINER (top),
                       gtk_button_new_with_label (label));
    gtk_container_add (GTK_CONTAINER (top),
                       gtk_alignment_new (0.5, 0.5, 0.0, 0.0));
    gtk_container_add (GTK_CONTAINER (bottom),
                       gtk_label_new (""));
    gtk_container_add (GTK_CONTAINER (bottom),
                       gtk_check_button_new ());

    g_free (label);
    return item;
}

static struct timeval first_expose_tv;

static gboolean
window_expose_cb (GtkWindow * win, GdkEventExpose * e)
{
    gettimeofday (&first_expose_tv, NULL);
    gtk_main_quit ();
    return FALSE;
}

int
main (int argc, char * argv[])
{
    struct timeval t1, t2;
    guint i, j;

    gettimeofday (&t1, NULL);
    printf ("%03d.%03d: main gets control\n",
            (int) (t1.tv_sec % 1000),
            (int) (t1.tv_usec / 1000));

    gtk_init (&argc, &argv);

    gettimeofday (&t1, NULL);

    GtkWidget * window = gtk_window_new (GTK_WINDOW_TOPLEVEL);
    GtkWidget * table = gtk_table_new (ROWS, COLUMNS, FALSE);

    for (i = 0; i < ROWS; i++)
    {
        for (j = 0; j < COLUMNS; j++)
        {
            GtkWidget * item = create_table_item (i * COLUMNS + j);
            gtk_table_attach_defaults (GTK_TABLE (table),
                                       item,
                                       j,
                                       j + 1,
                                       i,
                                       i + 1);

        }
    }

    gettimeofday (&t2, NULL);

    printf ("%03d.%03d: starting construction\n",
            (int) (t1.tv_sec % 1000),
            (int) (t1.tv_usec / 1000));
    printf ("%03d.%03d: construction finished\n",
            (int) (t2.tv_sec % 1000),
            (int) (t2.tv_usec / 1000));

    gtk_container_add (GTK_CONTAINER (window), table);
    gtk_widget_show_all (window);

    g_signal_connect (G_OBJECT (window), "expose-event",
                      G_CALLBACK (window_expose_cb), NULL);

    gtk_main ();

    printf ("%03d.%03d: first expose\n",
            (int) (first_expose_tv.tv_sec % 1000),
            (int) (first_expose_tv.tv_usec / 1000));

    return 0;
}
#include <gtkmm/alignment.h>
#include <gtkmm/box.h>
#include <gtkmm/button.h>
#include <gtkmm/checkbutton.h>
#include <gtkmm/label.h>
#include <gtkmm/main.h>
#include <gtkmm/table.h>
#include <gtkmm/window.h>

#include <sys/time.h>

#define ROWS    5
#define COLUMNS 5

using namespace Gtk;

static struct timeval first_expose_tv;

class window : public Window
{
    public:
        window()
            : Window (WINDOW_TOPLEVEL)
        {
        }

    protected:
#ifdef GLIBMM_DEFAULT_SIGNAL_HANDLERS_ENABLED
        virtual bool on_expose_event (GdkEventExpose* e)
        {
            gettimeofday (&first_expose_tv, NULL);
            Main::quit ();
            return Window::on_expose_event (e);
        }
#endif
};

#ifndef GLIBMM_DEFAULT_SIGNAL_HANDLERS_ENABLED
static gboolean
window_expose_cb (GtkWindow* win, GdkEventExpose* e)
{
    gettimeofday (&first_expose_tv, NULL);
    Gtk::Main::quit ();
    return FALSE;
}
#endif

static Widget*
create_table_item (unsigned int index)
{
    gchar * label = g_strdup_printf ("%d", index);

    VBox * item = new VBox (false, 0);
    HBox * top = new HBox (false, 0);
    HBox * bottom = new HBox (false, 0);

    item->add (*manage (top));
    item->add (*manage (bottom));

    top->add (*manage (new Button (label)));
    top->add (*manage (new Alignment (0.5, 0.5, 0.0, 0.0)));
    bottom->add (*manage (new Label ("")));
    bottom->add (*manage (new CheckButton ("")));

    g_free (label);
    return item;
}

int
main (int argc, char * argv[])
{
    struct timeval t1, t2;

    gettimeofday (&t1, NULL);
    printf ("%03d.%03d: main gets control\n",
            (int) (t1.tv_sec % 1000),
            (int) (t1.tv_usec / 1000));

    Main loop (argc, argv);

    gettimeofday (&t1, NULL);

    window w;
    Table table (ROWS, COLUMNS, false);

    for (unsigned i = 0; i < ROWS; i++)
    {
        for (unsigned j = 0; j < COLUMNS; j++)
        {
            Widget* item = create_table_item (i * COLUMNS + j);
            Gtk::manage (item);

            table.attach (*item, j, j + 1, i, i + 1);
        }
    }

    gettimeofday (&t2, NULL);

    printf ("%03d.%03d: starting construction\n",
            (int) (t1.tv_sec % 1000),
            (int) (t1.tv_usec / 1000));
    printf ("%03d.%03d: construction finished\n",
            (int) (t2.tv_sec % 1000),
            (int) (t2.tv_usec / 1000));

    w.add (table);
    w.show_all ();

#ifndef GLIBMM_DEFAULT_SIGNAL_HANDLERS_ENABLED
    g_signal_connect (G_OBJECT (w.gobj ()), "expose-event",
                      G_CALLBACK (window_expose_cb), NULL);
#endif

    loop.run ();
    printf ("%03d.%03d: first expose\n",
            (int) (first_expose_tv.tv_sec % 1000),
            (int) (first_expose_tv.tv_usec / 1000));
    return 0;
}


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]