Well,
I managed to build xemacs with -pg on compile and link. Attached is the
output of
gprof, which is the one the system provides.
In that sample session, xemacs ran at more that 40% cpu.
I also switched window managers from wmaker to icewm. But still, xemacs
would consume a lot of
cpu in the (large) range of 20-40%.
Hope this helps.
thomas
Jerry James schrieb:
Hi Thomas,
2008/3/11 Thomas Mittelstaedt <T.Mittelstaedt(a)cadenas.de>:
> ================================================================
> Dear Bug Team!
>
> xemacs is slow on aix. Selecting things with the mouse is sluggish and
> xemacs permanently uses
> more than 30% cpu. I am running it under gdb, when i interrupt via
> control-C, bt shows me the following:
>
[snip]
> I have also attached the output of truss.
>
The truss output starts after file descriptor 8 is already defined.
Since most of the truss output consists of kioctl calls on fd 8, I'd
like to know what that is. On the other hand, I'm not sure that truss
is the right tool for the job. What we really need to see is some
profiling output. Are you able to get that for us? Thanks,
call graph profile:
The sum of self and descendents is the major sort
for this listing.
function entries:
index the index of the function in the call graph
listing, as an aid to locating it (see below).
%time the percentage of the total time of the program
accounted for by this function and its
descendents.
self the number of seconds spent in this function
itself.
descendents
the number of seconds spent in the descendents of
this function on behalf of this function.
called the number of times this function is called (other
than recursive calls).
self the number of times this function calls itself
recursively.
name the name of the function, with an indication of
its membership in a cycle, if any.
index the index of the function in the call graph
listing, as an aid to locating it.
parent listings:
self* the number of seconds of this function's self time
which is due to calls from this parent.
descendents*
the number of seconds of this function's
descendent time which is due to calls from this
parent.
called** the number of times this function is called by
this parent. This is the numerator of the
fraction which divides up the function's time to
its parents.
total* the number of times this function was called by
all of its parents. This is the denominator of
the propagation fraction.
parents the name of this parent, with an indication of the
parent's membership in a cycle, if any.
index the index of this parent in the call graph
listing, as an aid in locating it.
children listings:
self* the number of seconds of this child's self time
which is due to being called by this function.
descendent*
the number of seconds of this child's descendent's
time which is due to being called by this
function.
called** the number of times this child is called by this
function. This is the numerator of the
propagation fraction for this child.
total* the number of times this child is called by all
functions. This is the denominator of the
propagation fraction.
children the name of this child, and an indication of its
membership in a cycle, if any.
index the index of this child in the call graph listing,
as an aid to locating it.
* these fields are omitted for parents (or
children) in the same cycle as the function. If
the function (or child) is a member of a cycle,
the propagated times and propagation denominator
represent the self time and descendent time of the
cycle as a whole.
** static-only parents and children are indicated
by a call count of 0.
cycle listings:
the cycle as a whole is listed with the same
fields as a function entry. Below it are listed
the members of the cycle, and their contributions
to the time and call counts of the cycle.
granularity: each sample hit covers 4 byte(s) Time: 0.73 seconds
called/total parents
index %time self descendents called+self name index
called/total children
<spontaneous>
[1] 8.2 0.06 0.00 ._XrmInternalStringToQuark [1]
-----------------------------------------------
<spontaneous>
[2] 8.2 0.06 0.00 .__divu64 [2]
-----------------------------------------------
<spontaneous>
[3] 8.2 0.06 0.00 .__is_wctype_sb [3]
-----------------------------------------------
<spontaneous>
[4] 5.5 0.04 0.00 .strlen [4]
-----------------------------------------------
<spontaneous>
[5] 4.1 0.03 0.00 .leftmost [5]
-----------------------------------------------
<spontaneous>
[6] 2.7 0.02 0.00 .InitFds [6]
-----------------------------------------------
<spontaneous>
[7] 2.7 0.02 0.00 .XrmStringToQuarkList [7]
-----------------------------------------------
<spontaneous>
[8] 2.7 0.02 0.00 .XtAppPending [8]
-----------------------------------------------
<spontaneous>
[9] 2.7 0.02 0.00 ._ptrgl [9]
-----------------------------------------------
<spontaneous>
[10] 2.7 0.02 0.00 .free_y [10]
-----------------------------------------------
<spontaneous>
[11] 2.7 0.02 0.00 .iscntrl [11]
-----------------------------------------------
<spontaneous>
[12] 2.7 0.02 0.00 .malloc_y [12]
-----------------------------------------------
<spontaneous>
[13] 2.7 0.02 0.00 .pre_ioctl [13]
-----------------------------------------------
<spontaneous>
[14] 2.7 0.02 0.00 .splint [14]
-----------------------------------------------
<spontaneous>
[15] 2.7 0.02 0.00 .time_base_to_time [15]
-----------------------------------------------
<spontaneous>
[16] 1.4 0.01 0.00 .CallSetValues [16]
-----------------------------------------------
<spontaneous>
[17] 1.4 0.01 0.00 .GetNEntry [17]
-----------------------------------------------
<spontaneous>
[18] 1.4 0.01 0.00 .GetValues [18]
-----------------------------------------------
<spontaneous>
[19] 1.4 0.01 0.00 .MatchBranchHead [19]
-----------------------------------------------
<spontaneous>
[20] 1.4 0.01 0.00 .OptLineMetrics [20]
-----------------------------------------------
<spontaneous>
[21] 1.4 0.01 0.00 .VendorExtSetValues [21]
-----------------------------------------------
<spontaneous>
[22] 1.4 0.01 0.00 .XEventsQueued.GL [22]
-----------------------------------------------
<spontaneous>
[23] 1.4 0.01 0.00 .XFilterEvent [23]
-----------------------------------------------
<spontaneous>
[24] 1.4 0.01 0.00 .XFindContext [24]
-----------------------------------------------
<spontaneous>
[25] 1.4 0.01 0.00 .XmStringDirectionCreate [25]
-----------------------------------------------
<spontaneous>
[26] 1.4 0.01 0.00 .XtAppProcessEvent [26]
-----------------------------------------------
<spontaneous>
[27] 1.4 0.01 0.00 ._Errno.GL [27]
-----------------------------------------------
<spontaneous>
[28] 1.4 0.01 0.00 ._XInternAtom [28]
-----------------------------------------------
<spontaneous>
[29] 1.4 0.01 0.00 ._XcmsParseColorString [29]
-----------------------------------------------
<spontaneous>
[30] 1.4 0.01 0.00 ._XmRenderTableFindRendition [30]
-----------------------------------------------
<spontaneous>
[31] 1.4 0.01 0.00 ._XtGetSubresources [31]
-----------------------------------------------
<spontaneous>
[32] 1.4 0.01 0.00 ._XtOnGrabList [32]
-----------------------------------------------
<spontaneous>
[33] 1.4 0.01 0.00 .__ioctl [33]
-----------------------------------------------
<spontaneous>
[34] 1.4 0.01 0.00 ._poll.GL [34]
-----------------------------------------------
<spontaneous>
[35] 1.4 0.01 0.00 ._ptrgl [35]
-----------------------------------------------
<spontaneous>
[36] 1.4 0.01 0.00 .free.GL [36]
-----------------------------------------------
<spontaneous>
[37] 1.4 0.01 0.00 .free_y_heap [37]
-----------------------------------------------
<spontaneous>
[38] 1.4 0.01 0.00 .hesiod_init [38]
-----------------------------------------------
<spontaneous>
[39] 1.4 0.01 0.00 .kwrite.GL [39]
-----------------------------------------------
<spontaneous>
[40] 1.4 0.01 0.00 .memchr [40]
-----------------------------------------------
<spontaneous>
[41] 1.4 0.01 0.00 .read [41]
-----------------------------------------------
<spontaneous>
[42] 1.4 0.01 0.00 .read_real_time [42]
-----------------------------------------------
<spontaneous>
[43] 1.4 0.01 0.00 .splay [43]
-----------------------------------------------
flat profile:
% the percentage of the total running time of the
time program used by this function.
cumulative a running sum of the number of seconds accounted
seconds for by this function and those listed above it.
self the number of seconds accounted for by this
seconds function alone. This is the major sort for this
listing.
calls the number of times this function was invoked, if
this function is profiled, else blank.
self the average number of milliseconds spent in this
ms/call function per call, if this function is profiled,
else blank.
total the average number of milliseconds spent in this
ms/call function and its descendents per call, if this
function is profiled, else blank.
name the name of the function. This is the minor sort
for this listing. The index shows the location of
the function in the gprof listing. If the index is
in parenthesis it shows where it would appear in
the gprof listing if it were to be printed.
granularity: each sample hit covers 4 byte(s) Total time: 56.55 seconds
% cumulative self self total
time seconds seconds calls ms/call ms/call name
0.1 0.06 0.06 ._XrmInternalStringToQuark [1]
0.1 0.12 0.06 .__divu64 [2]
0.1 0.18 0.06 .__is_wctype_sb [3]
0.1 0.22 0.04 .strlen [4]
0.1 0.25 0.03 .leftmost [5]
0.0 0.27 0.02 .InitFds [6]
0.0 0.29 0.02 .XrmStringToQuarkList [7]
0.0 0.31 0.02 .XtAppPending [8]
0.0 0.33 0.02 ._ptrgl [9]
0.0 0.35 0.02 .free_y [10]
0.0 0.37 0.02 .iscntrl [11]
0.0 0.39 0.02 .malloc_y [12]
0.0 0.41 0.02 .pre_ioctl [13]
0.0 0.43 0.02 .splint [14]
0.0 0.45 0.02 .time_base_to_time [15]
0.0 0.46 0.01 .CallSetValues [16]
0.0 0.47 0.01 .GetNEntry [17]
0.0 0.48 0.01 .GetValues [18]
0.0 0.49 0.01 .MatchBranchHead [19]
0.0 0.50 0.01 .OptLineMetrics [20]
0.0 0.51 0.01 .VendorExtSetValues [21]
0.0 0.52 0.01 .XEventsQueued.GL [22]
0.0 0.53 0.01 .XFilterEvent [23]
0.0 0.54 0.01 .XFindContext [24]
0.0 0.55 0.01 .XmStringDirectionCreate [25]
0.0 0.56 0.01 .XtAppProcessEvent [26]
0.0 0.57 0.01 ._Errno.GL [27]
0.0 0.58 0.01 ._XInternAtom [28]
0.0 0.59 0.01 ._XcmsParseColorString [29]
0.0 0.60 0.01 ._XmRenderTableFindRendition [30]
0.0 0.61 0.01 ._XtGetSubresources [31]
0.0 0.62 0.01 ._XtOnGrabList [32]
0.0 0.63 0.01 .__ioctl [33]
0.0 0.64 0.01 ._poll.GL [34]
0.0 0.65 0.01 ._ptrgl [35]
0.0 0.66 0.01 .free.GL [36]
0.0 0.67 0.01 .free_y_heap [37]
0.0 0.68 0.01 .hesiod_init [38]
0.0 0.69 0.01 .kwrite.GL [39]
0.0 0.70 0.01 .memchr [40]
0.0 0.71 0.01 .read [41]
0.0 0.72 0.01 .read_real_time [42]
0.0 0.73 0.01 .splay [43]
Index by function name
[16] .CallSetValues [28] ._XInternAtom [38] .hesiod_init
[17] .GetNEntry [29] ._XcmsParseColorStr [11] .iscntrl
[18] .GetValues [30] ._XmRenderTableFind [39] .kwrite.GL
[6] .InitFds [1] ._XrmInternalString [5] .leftmost
[19] .MatchBranchHead [31] ._XtGetSubresources [12] .malloc_y
[20] .OptLineMetrics [32] ._XtOnGrabList [40] .memchr
[21] .VendorExtSetValues [2] .__divu64 [13] .pre_ioctl
[22] .XEventsQueued.GL [33] .__ioctl [41] .read
[23] .XFilterEvent [3] .__is_wctype_sb [42] .read_real_time
[24] .XFindContext [34] ._poll.GL [43] .splay
[25] .XmStringDirectionC [35] ._ptrgl [14] .splint
[7] .XrmStringToQuarkLi [9] ._ptrgl [4] .strlen
[8] .XtAppPending [36] .free.GL [15] .time_base_to_time
[26] .XtAppProcessEvent [10] .free_y
[27] ._Errno.GL [37] .free_y_heap
_______________________________________________
XEmacs-Beta mailing list
XEmacs-Beta(a)xemacs.org
http://calypso.tux.org/cgi-bin/mailman/listinfo/xemacs-beta