Profiling trouble

24 Jan 2003

      Hello,

Please help me understanding GHC 5.02.2 profiling output!
Here is the root of my program (Show.hs):

\begin{code}
showData                        :: BaseVector a => Params -> Operator a -> String
showData params pot             =  unlines ["Version 3.1",
					    "",
					    showParams pot params,
					    "tcsdim: " ++ tcsDim,
					    "",
					    "conformal energies:",
					    diagonals,
					    "perturbation matrix:"] ++
                                   matrixElements
    where
    cutStates                   =  {-# SCC "showData1" #-} getStates params
    tcsDim                      =  {-# SCC "showData2" #-} show (length cutStates)
    diagonals                   =  {-# SCC "showData3" #-} unlines $ map (show . energy) cutStates
    matrixElements              =  {-# SCC "showData4" #-} unlines $ map unwords off
    off                         =  {-# SCC "showData5" #-} [map (myShow . pot outV) (take i cutStates)
                                    | (outV,i) <- zip cutStates [1..]]

main                            =  do params <- option
				      putStr $ showData params (superPot params)
\end{code}

If I compile it via

ghc -package util -o show --make Show.hs -prof -auto-all

I get in show.prof:

	Fri Jan 24 17:46 2003 Time and Allocation Profiling Report  (Final)

	   show +RTS -p -RTS -c 5 -s R -p 0 -t 0 -r 3

	total time  =       94.54 secs   (4727 ticks @ 20 ms)
	total alloc = 2,313,980,136 bytes  (excludes profiling overheads)

COST CENTRE          MODULE     %time %alloc

showData1            Main        86.1   88.5
cutAbove4            Tcsa         3.6    1.5
ncEps                Epsilon      3.3    3.1
GC                   GC           2.2    0.0
vopMode              Boson        1.5    1.1
ncVop                Boson        1.2    1.0
getStates            Tcsa         0.6    1.2

                                              individual     inherited
COST CENTRE              MODULE     entries  %time %alloc   %time %alloc

MAIN                     MAIN             0    0.0   0.0    100.0 100.0
 main                    Main             0    0.1   0.0    100.0 100.0
  [...]
  showData               Main             1    0.0   0.0     91.1  91.9
   showData5             Main             1    0.0   0.0      0.3   0.4
    myShow               Main          9453    0.3   0.3      0.3   0.3
   showData4             Main             1    0.0   0.1      0.0   0.1
   showData3             Main             1    0.1   0.1      0.1   0.1
   showData1             Main             1   86.1  88.5     90.8  91.4
    cutAbove             Tcsa            28    0.0   0.0      3.6   1.5
     cutAbove2           Tcsa             1    0.0   0.0      0.0   0.0
     cutAbove3           Tcsa            27    0.0   0.0      0.0   0.0
     cutAbove4           Tcsa            28    3.6   1.5      3.6   1.5
    spinSelect           Tcsa             1    0.0   0.0      0.0   0.0
    getStates            Tcsa             1    0.6   1.2      1.0   1.4
     incrementalBase     Fermion          1    0.3   0.2      0.4   0.2
      fermionNumber      Fermion      77664    0.1   0.0      0.1   0.0
     allTowers           Boson            1    0.0   0.0      0.0   0.0
      inModule           Boson           17    0.0   0.0      0.0   0.0
     mergeUp             Boson            6    0.0   0.0      0.0   0.0
   showData2             Main             1    0.0   0.0      0.0   0.0
  [...]

My question: showData1 is a single function call, how can it
still have such a big individual share?  Where is the
program spending its time?  Sorry if it is a trivial
question, functional profiling is new to me.

                                    Thanks: Feri.

Profiling trouble

Ferenc Wagner