dtrace discuss - Dec 2005 - Learning dtrace; trying to diagnose problem with xft/libfreetype2

Hi everyone,

I''m really new at all of this, so if I''m asking stupid
questions, I
apologize!  I''m trying to isolate an issue with Xft on my Solaris 10
box.
I had noticed some significant startup problems on a graphical program on
my box, and traced it down to its call to XftInit().


So I constructed the following test program, and to my surprise, it
doesn''t appear to terminate.  (At least, it keeps running for minutes
on
end without appearing to stop.)

/*************************/
#include <X11/Xlib.h>
#include <X11/Xft/Xft.h>
int main() {
  XftInit(NULL);
}
/*************************/

Since I heard dtrace was an awesome tool to try to debug this, I thought
it might be useful to learn Dtrace and debug this problem at the same
time.  (Maybe that''s not such a good idea.  *grin*)


I''m trying the following:

######
bash-3.00$ dtrace -n ''pid$target:::entry{@[probefunc] =
count()}''\
                  -c ./test
######


After waiting for a few minutes, I Control-C''ed it, and the last few
elements in the statistics output looks like this:

#####################################################################
  strcmp                                                       141317
  FcStrCaseWalkerInit                                          144892
  strlen                                                       154474
  FT_Stream_ReadLongLE                                         165472
  FcStrCaseWalkerNext                                          166700
  FT_QAlloc                                                    167092
  FT_Stream_ReadFields                                         167452
  FT_Stream_EnterFrame                                         167846
  FT_Stream_ExitFrame                                          167846
  FT_Free                                                      181577
  free                                                         185802
  malloc                                                       187821
  _free_unlocked                                               187934
  _malloc_unlocked                                             189959
  strchr                                                       265337
  lmutex_lock                                                  383527
  lmutex_unlock                                                383527
  FT_Stream_GetShortLE                                         399610
#####################################################################


So I see that there''s some heavy use of functions from libfreetype2. 
I''m
not exactly sure what to do next to get a clearer idea of the real
problem, though.  What else can I do to help debug this?  Again, I''m a
bit
of a dtrace newbie, so pointers to relevant tutorial material would be
great.


Other details: my package of libfreetype2 and xft come from blastwave.
I''m using one of those shiny new Ultra 20 workstations with Solaris 10.


Thanks for any help on this!

> > So I see that there''s some heavy use of functions from
libfreetype2.
> > I''m not exactly sure what to do next to get a clearer idea of
the real
> > problem, though.  What else can I do to help debug this?  Again,
I''m a
> > bit of a dtrace newbie, so pointers to relevant tutorial material
> > would be great.
> >
> >
> Large number of calls from small set of routines, some kind of looping
> is going on. Run ''pstack PID'' couple times, see what
stack(s) you''re
> getting, that will give you some idea what to look for in the code.

Hi Tao,

That makes sense.  I tried pstack, but it didn''t give much useful
information as far as I could tell:

######
bash-3.00$ gcore 3369
gcore: core.3369 dumped
bash-3.00$ pstack core.3369
core ''core.3369'' of 3369:       ./test
 fee928bb ???????? (65464, fe978000, 8062ca8, 0, fee764cd, 80b74b0)
 00065464 ???????? (c18000, 48080106, 216508, 2a1d094c, 4c800844, 90e7442)
 93818ccc ???????? ()
######

Ugh.  No symbols.  Where in the world have I jumped off?  *grin*


I''m now trying dtrace with ustack, with some more information:

######
bash-3.00$ dtrace -n ''pid$target:::entry{@[ustack()] =
count()}'' -c ./test
######



There are a few stacks that come up frequently high.  After letting this
run for a few minutes, I ^C''ed it, and see:

######
              libfreetype.so.6.3.8`FT_QAlloc
              libfreetype.so.6.3.8`FT_Stream_EnterFrame+0x30
              0x108
           165040

              libc.so.1`_malloc_unlocked
              libc.so.1`malloc+0x34
              libfreetype.so.6.3.8`0xfee76481
              0x108
           165040

              libfreetype.so.6.3.8`FT_Free
              libfreetype.so.6.3.8`FT_Stream_ExitFrame+0x28
           167092

              libfreetype.so.6.3.8`FT_Stream_ExitFrame
              libfreetype.so.6.3.8`FT_Stream_ReadFields+0x215
           167452

              libc.so.1`free
              libfreetype.so.6.3.8`0xfee764c8
           172533

              libc.so.1`lmutex_unlock
              libc.so.1`free+0x30
              libfreetype.so.6.3.8`0xfee764c8
           172533

              libc.so.1`_free_unlocked
              libc.so.1`free+0x28
              libfreetype.so.6.3.8`0xfee764c8
           172533

              libc.so.1`lmutex_lock
              libc.so.1`free+0x1d
              libfreetype.so.6.3.8`0xfee764c8
           172533
######

Weird.  Something funny is going on with the libfreetype library
functions; I lose the rest of the stack.  I wonder what that means!
Perhaps this corresponds to the output that pstack is giving me, since
some of these are also three levels deep.



Oh!  So there''s something definitely fishy with the blastwave
libraries.
If I do:

######
bash-3.00$ LD_LIBRARY_PATH=/usr/sfw/lib ./test
######

to bring the sfw libraries up front, then the program appears to finish
fine (although it still takes much longer than I expected).  But if I do:

######
bash-3.00$ LD_LIBRARY_PATH=/opt/csw/lib ./test
######

then I see the non-terminating behavior.


Anyway, thanks for the advice on looking at the stack; at least I have
some more avenues to look at.

Danny Yoo wrote:
> Weird.  Something funny is going on with the libfreetype library
> functions; I lose the rest of the stack.  I wonder what that means!
> Perhaps this corresponds to the output that pstack is giving me, since
> some of these are also three levels deep.
> 
> 
> 
> Oh!  So there''s something definitely fishy with the blastwave
libraries.
> If I do:
> 
> ######
> bash-3.00$ LD_LIBRARY_PATH=/usr/sfw/lib ./test
> ######
> 
> to bring the sfw libraries up front, then the program appears to finish
> fine (although it still takes much longer than I expected).  But if I do:
> 
> ######
> bash-3.00$ LD_LIBRARY_PATH=/opt/csw/lib ./test
> ######
> 
> then I see the non-terminating behavior.
> 
> 
> Anyway, thanks for the advice on looking at the stack; at least I have
> some more avenues to look at.
> 
The blastwave libs may be compiled with the option to omit the
framepointer save ; this is a really shortsighted optimization since it
means you cannot walk the thread stack w/o using auxiliary
information (dwarf stuff) that isn''t mapped by default and is 
untouchable from dtrace probe context...

The version of GCC we ship on Solaris doesn''t enable this opt.
by default to avoid this misfeature; we feel that being able to
debug and understand program behavior far outweighs the trivial
performance boost omitting the frame pointer affords.

- Bart


-- 
Bart Smaalders			Solaris Kernel Performance
barts at cyber.eng.sun.com		http://blogs.sun.com/barts

Danny Yoo wrote:
> I''m really new at all of this, so if I''m asking stupid
questions, I
> apologize!  I''m trying to isolate an issue with Xft on my Solaris
10 box.
> I had noticed some significant startup problems on a graphical program on
> my box, and traced it down to its call to XftInit().
Though it doesn''t help you learn dtrace, I''ll bet
that''s because you need to
run fc-cache as root to build the fontconfig caches - otherwise XftInit has
to go scan all the directories with fonts in and read all the font files to
build the list of available fonts.
> Other details: my package of libfreetype2 and xft come from blastwave.
> I''m using one of those shiny new Ultra 20 workstations with
Solaris 10.
Solaris 10 already includes libfreetype2, fontconfig & Xft, and the
fontconfig
in Solaris automatically builds the fc-cache files for you to avoid this very
problem.

-- 
	-Alan Coopersmith-           alan.coopersmith at sun.com
	 Sun Microsystems, Inc. - X Window System Engineering

> > I''m really new at all of this, so if I''m asking
stupid questions, I
> > apologize!  I''m trying to isolate an issue with Xft on my
Solaris 10
> > box. I had noticed some significant startup problems on a graphical
> > program on my box, and traced it down to its call to XftInit().
>
> Though it doesn''t help you learn dtrace, I''ll bet
that''s because you
> need to run fc-cache as root to build the fontconfig caches - otherwise
> XftInit has to go scan all the directories with fonts in and read all
> the font files to build the list of available fonts.
That''s it!  That fixes things for me.  It looks, though, like
blastwave''s
version of fc-cache screws up on my CJKV fonts.  Ok, that clarifies what
causes this problem.

> > Other details: my package of libfreetype2 and xft come from blastwave.
> > I''m using one of those shiny new Ultra 20 workstations with
Solaris
> > 10.
>
> Solaris 10 already includes libfreetype2, fontconfig & Xft, and the
> fontconfig in Solaris automatically builds the fc-cache files for you to
> avoid this very problem.
Ok, I''m going to go through and remove those blastwave packages.  I
didn''t
realize I''d run into so many issues with blastwave.


Thanks again for everyone''s help!  I''ll try to pick a more
interesting
candidate for dtrace next time.

Danny Yoo wrote:
> Ok, I''m going to go through and remove those blastwave packages. 
I didn''t
> realize I''d run into so many issues with blastwave.
Blastwave builds software to run on Solaris 8 and later, so it includes 
libraries like these that weren''t in Solaris 8 for the benefit of
Solaris 8
users and ends up duplicating libraries that were added in later Solaris
releases.   Usually it''s just taking up extra disk space and not
causing
problems like this.

-- 
	-Alan Coopersmith-           alan.coopersmith at sun.com
	 Sun Microsystems, Inc. - X Window System Engineering

Can you explain the issue with running fc-cache as root please ?  I have just
build JDS using the Gnome 2.12 sources and this has broken Scribus now.  During
the JDS build I had some installation errors related to a fc-cache service which
I fixed somehow and I wonder if my Scribus problems are related to this.

Anyway I ran Scribus as root and it seems to work OK so I assumed that the
problems are related to needing to run fc-cache as root.

How then do I set things up in order to run Scribus as a normal user ?

Thanks
This message posted from opensolaris.org

Scratch that - I fixed my problem by deleting the .scribus directory so I guess
it had nothing to do with fc-cache !
This message posted from opensolaris.org