Opened 23 months ago

Last modified 21 months ago

#11542 new bug

Profiling call count frequently 0 when it shouldn't be

Reported by: augustss Owned by:
Priority: normal Milestone:
Component: Profiling Version: 7.8.3
Keywords: Cc: j.waldmann
Operating System: Unknown/Multiple Architecture: Unknown/Multiple
Type of failure: None/Unknown Test Case:
Blocked By: Blocking:
Related Tickets: Differential Rev(s):
Wiki Page:

Description

Here's an example (lines shortened):

FUNCTION         MODULE                       CALLS
addinMTypeM      Cortex.Stem.Exp.Addin 212462 56309 0.0 0.0 0.1 0.0
 addinMTypeM''   Cortex.Stem.Exp.Addin 212463     0 0.0 0.0 0.1 0.0
  memoize        Cortex.Utils.Memo     212464     0 0.0 0.0 0.1 0.0
   memoizeIO     Cortex.Utils.Memo     212465     0 0.0 0.0 0.1 0.0
    addinMTypeM' Cortex.Stem.Exp.Addin 212467 13799 0.0 0.0 0.1 0.0

Maybe I don't understand the profile info, but here is my interpretation. addinMTypeM is called 56309 times, and then it calls addinMTypeM 0 times, which calls memoize 0 times, which calls memoizeIO 0 times, which calls addinMType' 13799.

How can a function that was called 0 times call another function 13799 times? My profile are full of the 0 entries.

Change History (3)

comment:1 Changed 23 months ago by j.waldmann

Cc: j.waldmann added

comment:2 Changed 23 months ago by thomie

Component: CompilerProfiling

comment:3 Changed 21 months ago by nad

I don't know if this is related, but I've encountered an example where the entries count is 0, but the individual %time and %alloc numbers are substantial. This is using GHC 7.10.3.

I found a report of a similar problem: Profiling trouble by Ferenc Wagner (https://mail.haskell.org/pipermail/glasgow-haskell-users/2003-January/004727.html).

The code attached to the report compiles if you modify some haskell98 imports:

sed -ri -e 's/import Complex/import Data.Complex/' -e 's/import qualified List/import qualified Data.List as List/' *hs
ghc --make Show2.hs -O -auto-all -prof
./Show2 +RTS -p

When I ran this sequence of commands now I obtained a profiling report with the following line:

 main                           Main                    109           0   10.5    0.8    10.5    0.8
Note: See TracTickets for help on using tickets.