dtrace getenv and GNOME

Thursday Mar 20, 2008

While tracking down the root cause of intermittent hangs (often > 1 second) when traversing the panel menus on GNOME 2.20.1, I found some interesting things about how GNOME works. On one of my installs, the gtk-update-icon-cache hadn't been created correctly and doing anything which read an icon crashed the application (e.g. clicking on a panel menu.) This led to me to searching for the cause of this failure. I wanted to make sure gtk-update-icon-cache wasn't unnecessarily failing on assert The code looked O.K. but I thought I'd look at the system with dtrace. This led me to a nice putenv.d dtrace script. gtk-update-icon-cache doesn't seem to set G_DEBUG so that question is answered. But I decided to make a small change to script to look at getenv during a simple launch of eog. This gave me some interesting results:

bash-3.2$  dtrace -s ./getenv.d -c "eog" 

CPU     ID                    FUNCTION:NAME
  0  66661                     getenv:entry env[LANGUAGE]= LANGUAGE

  0  66661                     getenv:entry env[NLSPATH]= NLSPATH

  0  66661                     getenv:entry env[LANGUAGE]= LANGUAGE

  0  66661                     getenv:entry env[NLSPATH]= NLSPATH

  0  66661                     getenv:entry env[G_MESSAGES_PREFIXED]= G_MESSAGES
_PREFIXED

  0  66661                     getenv:entry env[G_DEBUG]= G_DEBUG

  0  66661                     getenv:entry env[CHARSET]= CHARSET

  0  66661                     getenv:entry env[LIBCHARSET_ALIAS_DIR]= LIBCHARSE
T_ALIAS_DIR

  0  66661                     getenv:entry env[G_RANDOM_VERSION]= G_RANDOM_VERS
ION

  0  66661                     getenv:entry env[LANGUAGE]= LANGUAGE
...

Then lots of redundant getenvs.

getenv LANGUAGE 1832 times 
getenv NLSPATH 1679 times
getenv TZ 432 times

aggregating on ustack shows that a good share of these come from these backtraces:

  getenv
              libc.so.1`getenv
              libc.so.1`getsystemTZ+0x1c
              libc.so.1`mktime+0x24
              libc.so.1`__strftime_std+0x3c
              libglib-2.0.so.0.1400.4`g_time_val_to_iso8601+0x60
              libglib-2.0.so.0.1400.4`timestamp_to_iso8601+0x24
              libglib-2.0.so.0.1400.4`bookmark_item_dump+0x68
              libglib-2.0.so.0.1400.4`g_bookmark_file_dump+0x16c
              libglib-2.0.so.0.1400.4`g_bookmark_file_to_data+0x70
              libglib-2.0.so.0.1400.4`g_bookmark_file_to_file+0xbc
              144
  getenv	
              libc.so.1`getenv
              libglib-2.0.so.0.1400.4`guess_category_value+0x24
              libglib-2.0.so.0.1400.4`g_get_language_names+0x68
              libglib-2.0.so.0.1400.4`g_key_file_locale_is_interesting+0x1c
              libglib-2.0.so.0.1400.4`g_key_file_parse_key_value_pair+0x2b8
              libglib-2.0.so.0.1400.4`g_key_file_parse_line+0x178
              libglib-2.0.so.0.1400.4`g_key_file_flush_parse_buffer+0x80
              libglib-2.0.so.0.1400.4`g_key_file_parse_data+0x104
              libglib-2.0.so.0.1400.4`g_key_file_load_from_fd+0x1fc

Now, here is the weird part. The application seems to continue polling getenv when you're on an active menu. I tried this with gnome-panel. The good news is that when I'm not touching panel, it doesn't seem to be polling environment variable. But when I hold the mouse over or traversed the launch menu, it continually tried to grab ESPEAKER and DISPLAY environment variables. These were all coming from this section of code:

             libc.so.1`getenv
              libesd.so.0.2.38`esd_open_sound+0x44
              libgnome-2.so.0.1999.2`use_sound+0x48
              libgnome-2.so.0.1999.2`gnome_sound_connection_get+0x18
              libgnomeui-2.so.0.2000.1`relay_gnome_signal+0x1cc
              libgobject-2.0.so.0.1400.4`signal_emit_unlocked_R+0x69c
              libgobject-2.0.so.0.1400.4`g_signal_emit_valist+0x784
              libgobject-2.0.so.0.1400.4`g_signal_emit+0x1c
              libgtk-x11-2.0.so.0.1200.3`gtk_widget_show+0xb8
              gnome-panel`panel_util_query_tooltip_cb+0x20
              libgtk-x11-2.0.so.0.1200.3`_gtk_marshal_BOOLEAN__INT_INT_BOOLE

Whoah, I had system sounds enabled for tooltips? I checked the preferences and sure enough system sounds were enabled. I never heard any so my audio hardware must not be supported. I still don't know for certain if this was the cause of the hang, since the hang was intermittent. But if you haven't tried it already, install GNOME on a machine with dtrace capability and look around a bit. If nothing else, you may learn something new.