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