Confused by profiling

Ian Lynagh igloo@earth.li
Thu, 13 Sep 2001 18:42:52 +0100


Hi all

I am confused by the GHC profiling output. I have put some abstracts
below to illustrate my confusion.

I compiled my code with:
HFLAGS="-Wall -package lang -prof -auto-all" hmake -ghc main
and then ran it with:
./main -t +RTS -p < test5.hs

Here is some of main.prof:
                                              individual     inherited
COST CENTRE              MODULE     entries  %time %alloc   %time %alloc

[...]
  parse                  Parser           1    0.0   0.0     81.4  62.3
   p_module              Parser           0    0.0   0.0     81.4  62.3
    <|>                  PC_base      69517   20.3   5.7     81.4  62.3
[...]
     p_aexp_list         Parser           0    0.0   0.0      0.0   0.3
      con2tag_Token#     Tokens         880    0.0   0.0      0.0   0.0
      pIfThing           PC_base        896    0.0   0.0      0.0   0.0
      <$                 PC               0    0.0   0.0      0.0   0.3
       <$>               PC               0    0.0   0.0      0.0   0.3
        pSucceed         PC_base        896    0.0   0.3      0.0   0.3
        <*>              PC_base        896    0.0   0.0      0.0   0.0
      <*>                PC_base        896    0.0   0.0      0.0   0.0
     p_aexp_tuple        Parser           0    0.0   0.0      0.0   0.3
[...]

and here is the code for p_aexp_list:

p_aexp_list :: Parser Token Aexp
p_aexp_list = (Aexp_list . get_rights)
          <$  pIfThing ((==) (Special '['))
          <*> pSList False p_comma p_exp
          <*  pIfThing ((==) (Special ']'))

Now basically my problem is how things under p_aexp_list can be entered
896 times if p_aexp_list is entered 0 times - am I reading it wrong?

And the only place p_aexp_list is called from is

p_aexp_init = p_aexp_qvar <|> p_aexp_gcon <|> p_aexp_literal
          <|> p_aexp_paren <|> p_aexp_tuple <|> p_aexp_list
          <|> p_aexp_arith <|> p_aexp_listcomp <|> p_aexp_left
          <|> p_aexp_right

but my reading of the profile output shows it as being called from <|>
which is in turn called from p_module (all lines in the second [...] are
indented with at least "     ").

Am I missing something obvious?


Thanks
Ian