The Observation Deck

Close this search box.

Using DTrace to understand GNOME

July 11, 2005

I read with some interest about
the GNOME startup bounty.
Stephen O’Grady
pointed out
, this problem is indeed perfect for
To get a feel for the problem, I wrote a very simple D script:

#!/usr/sbin/dtrace -s
#pragma D option quiet
/execname == "gnome-session"/
start = timestamp;
go = 1;
printf("%10d { -> I/O %d %s %s %s }\n",
(timestamp - start) / 1000000, pid, execname,
args[0]->b_flags & B_READ ? "reads" : "writes",
printf("%10d { fi_pathname);
/go && ((struct buf *)arg0)->b_file != NULL &&
((struct buf *)arg0)->b_file->v_path == NULL/
printf("%10s   (vp %p)\n", "", ((struct buf *)arg0)->b_file);
@apps[execname] = count();
@files[args[2]->fi_pathname] = count();
@appsfiles[execname, args[2]->fi_pathname] = count();
self->parent = execname;
/self->parent != NULL/
printf("%10d -> %d %s (from %d %s)\n",
(timestamp - start) / 1000000, pid, execname,
curpsinfo->pr_ppid, self->parent);
self->parent = NULL;
printf("%10d pr_flag & PR_IDLE)/
printf("%10d [ idle ]\n",
(timestamp - start) / 1000000);
printf("\n  %-72s %s\n", "APPLICATION", "I/Os");
printa("  %-72s %@d\n", @apps);
printf("\n  %-72s %s\n", "FILE", "I/Os");
printa("  %-72s %@d\n", @files);
printf("\n  %-16s %-55s %s\n", "APPLICATION", "FILE", "I/Os");
printa("  %-16s %-55s %@d\n", @appsfiles);

This script uses a combination of CPU sampling and I/O tracing to determine
roughly what’s going on over the course of logging in. I ran the above
script on on my
Acer Ferrari 3400
laptop running
OpenSolaris by dropping to the
command-line login
after a reboot and running:

# nohup ./login.d > /var/tmp/login.out &

I then logged in, and made sure that the first thing I did was launch a
gnome-terminal to pkill dtrace.
(This could obviously be made quite a bit more precise, but it works as
a crude way of indicating the completion of login.)
Here is
the output from performing this experiment.
The first column is the millisecond offset from the start of gnome-session.
CPU samples are contained within square brackets, launched programs
are contained withing curly braces, and I/O is explicitly noted.
An I/O summary is provided at the end.
A couple of observations:

  • Nearly one third of all I/O is to shared object text and read-only data.
    This is classic death-of-a-thousand-cuts, and it’s hard to see that there’s
    an easy way to fix this. But perhaps text could be reordered to save some
    I/O? More investigation is probably merited here.

  • Over a quarter of all I/O is from
    — and many of these are from
    wandering around an expansive directory hierarchy looking for configuration
    information. It is well-known that the XML backend is a big performance
    problem, and a better backend is apparently being worked on. At any rate,
    solving this problem is clearly in
    GConf’s future.

  • Of the remaining I/O, a bunch
    is to icon files.
    Glynn Foster
    pointed out that this looks to be addressed by the
    GTK+ gtk-update-icon-cache, new in
    GTK+ 2.6 and contained within
    GNOME 2.10, so this experiment will obviously need to
    be repeated on
    GNOME 2.10.

  • CPU utilization doesn’t look like a big issue — or it’s one that is at
    least dwarfed by the cost of performing I/O. That said, gconfd-2 looks to
    be a bit piggy in this department as well. We’re only using CPU sampling —
    and we’re using a pretty coarse grained sample — and gconfd-2 still
    showed up. More precise investigation into CPU utilization can be
    performed with the sched provider and its on-cpu and
    off-cpu probes.

And an end-note: you might note many files named “<unknown>” in the
This is due to I/Os being induced by lookups that are going through
directories and/or symlinks that haven’t been explicitly opened. For these
I/Os, my script also gives you the pointer to the vnode structure in
the kernel; you can get the path to these by using ::vnode2path
in MDB:

# mdb -k
Loading modules: [ unix krtld genunix specfs dtrace ufs ip
sctp usba uhci s1394 random nca lofs nfs audiosup sppp ptm ipc ]
> ffffffff8f6851c0::vnode2path

Yes, having to do this sucks a bit, and

a known issue
And rumor has
it that
Eric even has a workspace
with the fix, so stay tuned…

Update: Eric pointed me to a prototype with the fix, and I reran the script on
a GNOME cold start;
here is the output
from that run
. Interestingly, because the symlinks now show up, a little postprocessing
reveals that we chased nearly eighty symlinks on startup! From the output, reading many
of these took 10 to 20 milliseconds; we might be spending as much as one second of GNOME
startup blocked on I/O just to chase symlinks! Ouch! Again, it’s not clear how one
would fix this; having an app link to and not is clearly a Good Thing, and having this be a symlink
instead of a hardlink is clearly a Good Thing — but all of that goodness leaves you
with a read dependency that’s hard to work around. Anyway, be looking for Eric’s fix
in OpenSolaris and then in an upcoming Solaris Express release;
it makes this kind of analysis much easier — and thanks Eric for the quick prototype!

Technorati tags:

8 Responses

  1. If I understand correctly crle(1) could be used to create a cache for the resolutions of gnome-session’s and gconfd-2’s library dependencies, and their dependencies, and so on. And if a significant part of that text/data I/O is for object relocation then dldump(3C)ed objects can be cached as well.

  2. [b]香港会计事务所

  3. 登尼特北京香港公司注册

  4. 登尼特香港公司注册咨询

  5. 日聪专业提供深圳注册香港公司服务:*注册香港公司咨询,*注册香港公司服务,本公司提供一切条件方便客户;
    登尼特注册香港公司 香港登尼特:专业注册公司、注册香港公司,注册上海公司,注册美国公司,注册深圳公司,中国及海外公司,香港公司注册,深圳公司注册,上海公司注册,中国公司注册。[b]
    怎样抓住中东市场新机会,作为浙江企业中开拓中东市场比较成功的典型,宁波燎原灯具股份公司今年1至4月出口中东地区的销售额已达300多万美元。该公司董事长邵云蒸说:“中东地区的市场有三个特点:一是中东地区消费者平均年龄相当年轻;二是中东国家的家庭成员人数比发达国家多;三 …

  6. [b]香港登尼特专业注册公司提供注册公司咨询0755-82143181

  7. [b]香港日聪专业公司注册提供注册公司咨询0755-82143181

Leave a Reply

Recent Posts

November 18, 2023
November 27, 2022
October 11, 2020
July 31, 2019
December 16, 2018
September 18, 2018
December 21, 2016
September 30, 2016
September 26, 2016
September 13, 2016
July 29, 2016
December 17, 2015
September 16, 2015
January 6, 2015
November 10, 2013
September 3, 2013
June 7, 2012
September 15, 2011
August 15, 2011
March 9, 2011
September 24, 2010
August 11, 2010
July 30, 2010
July 25, 2010
March 10, 2010
November 26, 2009
February 19, 2009
February 2, 2009
November 10, 2008
November 3, 2008
September 3, 2008
July 18, 2008
June 30, 2008
May 31, 2008
March 16, 2008
December 18, 2007
December 5, 2007
November 11, 2007
November 8, 2007
September 6, 2007
August 21, 2007
August 2, 2007
July 11, 2007
May 20, 2007
March 19, 2007
October 12, 2006
August 17, 2006
August 7, 2006
May 1, 2006
December 13, 2005
November 16, 2005
September 13, 2005
September 9, 2005
August 21, 2005
August 16, 2005