Re: Sun vs. Mac - gprof output

All,

> Hm, that's a new one on me. Just to eliminate the obvious:
> you did read the gprof man page? It typically needs both the
> pathname of the postgres executable and that of the gmon.out

I read it, but apparently not very well. It appears that as long as gmon.out
is in the current dir, all that's needed is the name of the executeable (with
full path). The way it's formated I read it as all that's needed is the
image-file. Anyways...

There's a ton of output, so I'm picking what appear to be the highlights.

granularity: each sample hit covers 4 byte(s) for 0.00% of 705.17 seconds

called/total parents
index %time self descendents called+self name index
called/total children

[1] 63.6 446.05 2.65 44386289+57463869 <cycle 1 as a whole> [1]
442.08 2.50 59491100+2566048020 <external> <cycle 1>
[2]
2.91 0.00 23045572+366 _fini <cycle 1> [23]
0.57 0.00 17763681 _rl_input_available
<cycle 1> [42]
0.11 0.15 478216+7 history_expand <cycle
1> [54]
0.21 0.00 7 history_tokenize_internal
<cycle 1> [56]
0.10 0.00 1071137 tilde_expand <cycle
1> [68]
0.07 0.00 397 rl_gather_tyi <cycle
1> [70]
0.00 0.00 31 qsort <cycle 1> [81]
0.00 0.00 17 rl_insert_close <cycle
1> [82]
-----------------------------------------------
<spontaneous>
[3] 32.3 0.65 227.47 rl_get_termcap [3]
226.13 1.34 22502064/44386289 <external> <cycle 1>
[2]
-----------------------------------------------
<spontaneous>
[4] 26.3 0.78 184.35 rl_stuff_char [4]
178.51 1.06 17763681/44386289 <external> <cycle 1>
[2]
4.78 0.00 17763681/17763681 rl_clear_signals [18]
-----------------------------------------------
<spontaneous>
[5] 15.8 111.61 0.00 rl_signal_handler [5]
0.00 0.00 1/44386289 <external> <cycle 1>
[2]
-----------------------------------------------
<spontaneous>
[6] 4.3 30.57 0.00 rl_sigwinch_handler [6]
-----------------------------------------------

And:

granularity: each sample hit covers 4 byte(s) for 0.00% of 705.17 seconds

% cumulative self self total
time seconds seconds calls ms/call ms/call name
15.8 111.61 111.61 rl_signal_handler [5]
4.3 142.18 30.57 rl_sigwinch_handler [6]
1.9 155.42 13.24 rl_set_sighandler [8]
1.9 168.52 13.10 rl_maybe_set_sighandler
[9]
1.1 176.37 7.85 _rl_next_macro_key [11]
0.9 182.38 6.01 rl_read_key [12]
0.8 188.07 5.69 rl_backward_kill_line [13]
0.8 193.56 5.49 rl_unix_word_rubout [14]
0.8 198.91 5.35 _rl_pop_executing_macro
[15]
0.7 203.73 4.82 _rl_fix_last_undo_of_type
[17]
0.7 208.51 4.78 17763681 0.00 0.00 rl_clear_signals [18]
0.6 212.87 4.36 rl_modifying [19]
0.6 216.95 4.08 rl_begin_undo_group [20]
0.6 221.00 4.05 rl_tilde_expand [21]
0.4 223.98 2.98 region_kill_internal [22]
0.4 226.89 2.91 23045572 0.00 0.00 _fini <cycle 1> [23]

So. Any thoughts? This looks really useful in the hands of someone who knows
what it all means. Looks like some signal handlers are using up most of the
time. Good? Bad? Am I reading that first part correctly in that a good part
of the time spent is external to Postgres? This report also seems to verify
that qsort isn't a problem since it was the 81st index, with 31 calls (not
much) and 0.00 self seconds.

Thanks much,

-X

__________________________________________________
Do you Yahoo!?
Yahoo! Mail Plus - Powerful. Affordable. Sign up now.
http://mailplus.yahoo.com