Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Understanding cost center names in Haskell profiling reports

Tags:

haskell

I am trying to decode the meaning of various cost center names in my Haskell profiling output. Here is a sample of the .prof file

COST CENTRE                                         MODULE   no. entries  %time %alloc   %time %alloc
  ...
  runSiT.\.\.readBufResults           SiT.SiT       3487     0    0.0      46.3   51.9   
    ...
     ...
     readBuffer.(...)                 SiT.SiT       3540     1    0.0      0.2     0.0    0.2
     readBuffer.tm0_vals              SiT.SiT       3539     1    0.0      0.0     0.0    0.0
     readBuffer.\                     SiT.SiT       3499     0   18.4     12.8    31.0   27.7
     ...

It seems that a dot separates nested cost centers (e.g. readBuffer.n_threads means the binding n_threads within readBuffer), but I am unsure as to some of the other elements. And the .\.\. indicates nested lambda functions (e.g. from stuff like forM_ ... $ \arg -> do). However, what is the meaning of the (...) in readBuffer.(...)?

EDIT: As a second example I have:

statsFields.mkStr.\                  Main         3801           4    0.0    0.0     0.0    0.0
 statsFields.fmtModePct              Main         3811           2    0.0    0.0     0.0    0.0
  statsFields.fmtModePct.pct_str     Main         3815           2    0.0    0.0     0.0    0.0
   ssN                               SiT.SiT      3817           2    0.0    0.0     0.0    0.0
   statsFields.fmtPctI               Main         3816           2    0.0    0.0     0.0    0.0
  statsFields.fmtModePct.(...)       Main         3813           2    0.0    0.0     0.0    0.0
   ssMode                            SiT.SiT      3814           2    0.0    0.0     0.0    0.0
  statsFields.fmtModePct.m_fq        Main         3812           2    0.0    0.0     0.0    0.0

Source for that is:

where ...
      fmtModePct :: SiTStats -> String
      fmtModePct ss = fmtI64 m_fq ++ " (" ++ pct_str ++ ")"
        where (m_val,m_fq) = ssMode ss
              pct_str = fmtPctI m_fq (ssN ss)

      fmtF64 :: Double -> String
      fmtF64 = commafy . printf "%.1f"

      -- turns 1000 -> 1,000
      commafy :: String -> String
      commafy str
        | head str == '-' = '-':commafy (tail str)
        | otherwise = reverse (go (reverse sig)) ++ frac
        where (sig,frac) = span (/='.') str
              go (a:b:c:cs@(_:_)) = a : b : c : ',' : go cs
              go str = str
like image 300
Tim Avatar asked Feb 01 '15 00:02

Tim


1 Answers

(...) means repeatable operation something like recursive call. I have the same question when investigating my program. Look at the following simple example, I'm evaluating count and mergeAndCount recursively:

count :: [Int] -> (Int, [Int])
count []       = (0, [])
count (x:[])   = (0, [x])
count xs       =
  let halves  = splitAt (length xs `div` 2) xs
      (ac, a) = count $ fst halves
      (bc, b) = count $ snd halves
      (mc, merged) = mergeAndCount a b
  in
      (ac + bc + mc, merged)

mergeAndCount :: [Int] -> [Int] -> (Int, [Int])
mergeAndCount [] [] = (0, [])
mergeAndCount xs [] = (0, xs)
mergeAndCount [] ys = (0, ys)
mergeAndCount xs@(x:xs') ys@(y:ys') =
  let (larger, thisCount, (counted, merged))
        = if x < y
            then (x, 0,         mergeAndCount xs' ys)
            else (y, length xs, mergeAndCount xs ys')
  in
      (thisCount + counted, larger : merged)

will generate profiling output like

    count                   Invariant               103      199999    0.1    4.3    99.2   37.5
     count.merged           Invariant               118       99998    0.0    0.0     0.0    0.0
     count.a                Invariant               113       99999    0.0    0.0     0.0    0.0
     count.b                Invariant               112       99999    0.0    0.0     0.0    0.0
     count.(...)            Invariant               110       99999    0.0    0.0    99.0   25.2
      mergeAndCount         Invariant               111     1636301   98.9   25.2    99.0   25.2
       mergeAndCount.merged Invariant               122      726644    0.0    0.0     0.0    0.0
       mergeAndCount.merged Invariant               121      709659    0.0    0.0     0.0    0.0
       mergeAndCount.(...)  Invariant               120      776644    0.0    0.0     0.0    0.0
       mergeAndCount.cnt    Invariant               119      776644    0.0    0.0     0.0    0.0
       mergeAndCount.(...)  Invariant               117      759658    0.0    0.0     0.0    0.0
       mergeAndCount.cnt    Invariant               116      759658    0.0    0.0     0.0    

where count.merged indicated overall result, count.a count.b cost centers for function pattern matching. This (...) clearly visible with each inner call to mergeAndCount.

If you functions contained many different approaches to work with data, your profiling output will be different and highly related to data you have sent.

like image 175
sigrlami Avatar answered Jan 04 '23 07:01

sigrlami