Commit 200325fb authored by Simon Marlow's avatar Simon Marlow
Browse files

some more profiling tests

parent d12a8bdc
......@@ -1521,6 +1521,10 @@ def normalise_prof (str):
# strip results for CAFs, these tend to change unpredictably
str = re.sub('[ \t]*CAF.*\n','',str)
# XXX Ignore Main.main. Sometimes this appears under CAF, and
# sometimes under MAIN.
str = re.sub('[ \t]*main[ \t]+Main.*\n','',str)
# We have somthing like this:
# MAIN MAIN 101 0 0.0 0.0 100.0 100.0
......
fib1 n = fib1' n
where
fib1' n = {-# SCC "nfib'" #-} nfib n -- %time: 0 (both individual and inherited)
where
nfib n = if n < 2 then 1 else nfib (n-1) + nfib (n-2)
fib2 n = fib2' n
fib2' n = nfib n -- %time: 100 (both individual and inherited)
where
nfib n = if n < 2 then 1 else nfib (n-1) + nfib (n-2)
fib3 = fib3'
fib3' n = nfib n -- %time: 100 (both individual and inherited)
where
nfib n = if n < 2 then 1 else nfib (n-1) + nfib (n-2)
main = do
print (fib1 28)
print (fib2 28)
print (fib3 28)
Wed Oct 26 13:31 2011 Time and Allocation Profiling Report (Final)
T2552 +RTS -p -RTS
total time = 1.02 secs (51 ticks @ 20 ms)
total alloc = 234,535,968 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
fib3'.nfib Main 27.5 33.3
fib2'.nfib Main 27.5 33.3
fib1.fib1'.nfib Main 27.5 33.3
fib3 Main 3.9 0.0
fib2' Main 3.9 0.0
fib1 Main 3.9 0.0
nfib' Main 2.0 0.0
fib2 Main 2.0 0.0
fib1.fib1' Main 2.0 0.0
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 102 0 0.0 0.0 100.0 100.0
CAF Main 203 0 0.0 0.0 100.0 100.0
fib3 Main 212 1 0.0 0.0 0.0 0.0
main Main 204 1 0.0 0.0 100.0 100.0
fib3 Main 213 0 3.9 0.0 31.4 33.3
fib3' Main 214 1 0.0 0.0 27.5 33.3
fib3'.nfib Main 215 1028457 27.5 33.3 27.5 33.3
fib2 Main 209 1 2.0 0.0 33.3 33.3
fib2' Main 210 1 3.9 0.0 31.4 33.3
fib2'.nfib Main 211 1028457 27.5 33.3 27.5 33.3
fib1 Main 205 1 3.9 0.0 35.3 33.3
fib1.fib1' Main 206 1 2.0 0.0 31.4 33.3
nfib' Main 207 1 2.0 0.0 29.4 33.3
fib1.fib1'.nfib Main 208 1028457 27.5 33.3 27.5 33.3
CAF GHC.Conc.Signal 200 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 190 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD 182 0 0.0 0.0 0.0 0.0
foo :: (() -> () -> [()] -> [()]) -> () -> [()] -> [()]
foo k =
\_ xs -> concatMap ($ [head xs]) [bar]
where
bar =
let k' = k undefined undefined
in \xs ->
let k'' = [k' xs]
in (() : (foldr1 (>>) k''))
k :: () -> [()] -> [()]
k = foo (\_ -> k)
--k a = foo (\_ -> k) a
-- all the work should happen in r
r :: ()
r = k undefined [] !! 4000
main = print r
Wed Oct 26 14:10 2011 Time and Allocation Profiling Report (Final)
T680 +RTS -p -RTS
total time = 0.38 secs (19 ticks @ 20 ms)
total alloc = 224,788,720 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
foo.\ Main 100.0 99.8
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 102 0 0.0 0.0 100.0 100.0
CAF Main 203 0 0.0 0.0 100.0 100.0
k Main 206 1 0.0 0.0 0.0 0.0
foo Main 207 1 0.0 0.0 0.0 0.0
foo.bar Main 211 1 0.0 0.0 0.0 0.0
foo.bar.k' Main 215 1 0.0 0.0 0.0 0.0
k.\ Main 216 1 0.0 0.0 0.0 0.0
r Main 205 1 0.0 0.0 100.0 100.0
k Main 208 0 0.0 0.0 100.0 100.0
foo Main 209 0 0.0 0.0 100.0 100.0
foo.bar Main 212 0 0.0 0.0 0.0 0.1
foo.bar.k' Main 217 0 0.0 0.0 0.0 0.0
foo.bar.\ Main 213 4001 0.0 0.1 0.0 0.1
foo.bar.\.k'' Main 214 4000 0.0 0.0 0.0 0.0
foo.\ Main 210 4001 100.0 99.8 100.0 99.8
main Main 204 1 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal 200 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 190 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD 182 0 0.0 0.0 0.0 0.0
CAF GHC.Show 170 0 0.0 0.0 0.0 0.0
-- test for #949: the -hy heap profile should not include
-- "stg_ap_2_upd" or similar
main = length xs `seq` return xs
where xs = map (+1) [1..1000000]
# Test for #1227, #1418
extra_prof_ways = ['prof_hc_hb', 'prof_hb', 'prof_hd', 'prof_hy', 'prof_hr']
extra_prof_ways = ['prof', 'prof_hc_hb', 'prof_hb', 'prof_hd', 'prof_hy', 'prof_hr']
test('heapprof001',
composes([only_ways(prof_ways + extra_prof_ways),
......@@ -22,13 +22,66 @@ test('T3001-2',
[only_ways(['prof_hb']), extra_ways(['prof_hb']), req_profiling],
compile_and_run, ['-package bytestring'])
test('scc001', [expect_broken(4414), req_profiling],
run_command, ['$MAKE -s --no-print-directory scc001'])
test('scc001', [req_profiling,
extra_ways(['prof']), only_ways(['prof'] + prof_ways)],
compile_and_run,
['-fno-state-hack']) # Note [consistent stacks]
test('scc002', [req_profiling,
extra_ways(['prof']), only_ways(['prof'] + prof_ways)],
compile_and_run,
[''])
test('scc003', [req_profiling,
extra_ways(['prof']), only_ways(['prof'] + prof_ways)],
compile_and_run,
['-fno-state-hack']) # Note [consistent stacks]
test('5314',
composes([only_ways(prof_ways + extra_prof_ways),
extra_ways(extra_prof_ways),
req_profiling]),
[ only_ways(prof_ways + extra_prof_ways),
extra_ways(extra_prof_ways),
req_profiling ],
compile_and_run,
[''])
test('T680',
[ req_profiling, extra_ways(['prof']), only_ways(['prof'] + prof_ways) ],
compile_and_run,
['-fno-full-laziness']) # Note [consistent stacks]
test('T2552',
[ req_profiling, extra_ways(['prof']), only_ways(['prof'] + prof_ways) ],
compile_and_run,
[''])
test('T949',
[ req_profiling, extra_ways(extra_prof_ways), only_ways(extra_prof_ways) ],
compile_and_run,
[''])
test('ioprof',
[ req_profiling, extra_ways(['prof']), only_ways(['prof'] + prof_ways),
exit_code(1) ],
compile_and_run,
['-fno-full-laziness -fno-state-hack']) # Note [consistent stacks]
# These two examples are from the User's Guide:
test('prof-doc-fib',
[ req_profiling, extra_ways(['prof']), only_ways(['prof'] + prof_ways) ],
compile_and_run,
[''])
test('prof-doc-last',
[ req_profiling, extra_ways(['prof']), only_ways(['prof'] + prof_ways) ],
compile_and_run,
[''])
# Note [consistent stacks]
# Certain optimisations can change the stacks we get out of the
# profiler. These flags are necessary (but perhaps not sufficient)
# to get consistent stacks:
#
# -fno-state-hack
# -fno-full-laziness
import Control.Concurrent
import Control.Exception
type S = String
newtype M s a = M { unM :: s -> (s,a) }
instance Monad (M s) where
(M m) >>= k = M $ \s -> case m s of
(s',a) -> unM (k a) s'
return a = M $ \s -> (s,a)
errorM :: String -> M s a
errorM s = M $ \_ -> error s
runM :: M s a -> s -> a
runM (M m) s = case m s of (_,a) -> a
main = print (runM (bar ["a","b"]) "state")
bar :: [String] -> M s [String]
bar xs = mapM foo xs
foo :: String -> M s String
foo x = errorM x
Wed Oct 26 14:25 2011 Time and Allocation Profiling Report (Final)
ioprof +RTS -p -RTS
total time = 0.00 secs (0 ticks @ 20 ms)
total alloc = 46,804 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
CAF GHC.IO.Handle.FD 0.0 73.0
CAF GHC.IO.Encoding.Iconv 0.0 1.5
main Main 0.0 18.2
errorM.\ Main 0.0 5.1
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 102 0 0.0 0.0 0.0 100.0
CAF Main 203 0 0.0 0.6 0.0 24.1
main Main 204 1 0.0 18.2 0.0 23.5
bar Main 206 1 0.0 0.2 0.0 0.2
foo Main 211 1 0.0 0.0 0.0 0.0
errorM Main 212 1 0.0 0.0 0.0 0.0
>>= Main 207 1 0.0 0.0 0.0 0.0
runM Main 205 1 0.0 0.0 0.0 5.1
bar Main 208 0 0.0 0.0 0.0 5.1
foo Main 213 0 0.0 0.0 0.0 5.1
errorM Main 214 0 0.0 0.0 0.0 5.1
errorM.\ Main 215 1 0.0 5.1 0.0 5.1
>>= Main 209 0 0.0 0.0 0.0 0.0
>>=.\ Main 210 1 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal 200 0 0.0 0.7 0.0 0.7
CAF GHC.Conc.Sync 199 0 0.0 0.3 0.0 0.3
CAF GHC.Exception 197 0 0.0 0.2 0.0 0.2
CAF GHC.IO.Encoding 192 0 0.0 0.4 0.0 0.4
CAF GHC.IO.Encoding.Iconv 190 0 0.0 1.5 0.0 1.5
CAF GHC.IO.Handle.FD 182 0 0.0 73.0 0.0 73.0
-- This example is from the User's Guide, so we better make sure it
-- produces the correct output.
main = print (f 30 + g 30)
where
f n = fib n
g n = fib (n `div` 2)
fib n = if n < 2 then 1 else fib (n-1) + fib (n-2)
Thu Oct 27 09:29 2011 Time and Allocation Profiling Report (Final)
fib +RTS -p -RTS
total time = 0.76 secs (38 ticks @ 20 ms)
total alloc = 247,940,020 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
fib Main 100.0 100.0
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 102 0 0.0 0.0 100.0 100.0
CAF Main 203 0 0.0 0.0 100.0 100.0
main Main 204 1 0.0 0.0 100.0 100.0
main.g Main 207 1 0.0 0.0 0.0 0.1
fib Main 208 1973 0.0 0.1 0.0 0.1
main.f Main 205 1 0.0 0.0 100.0 99.9
fib Main 206 2692537 100.0 99.9 100.0 99.9
CAF GHC.Conc.Signal 201 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 191 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD 183 0 0.0 0.0 0.0 0.0
main :: IO ()
main = do let xs = [1..1000000]
let ys = [1..2000000]
print $ {-# SCC "last_xs" #-} last xs
print $ {-# SCC "last_init_xs" #-} last $ init xs
print $ {-# SCC "last_ys" #-} last ys
print $ {-# SCC "last_init_ys" #-}last $ init ys
Thu Oct 27 09:37 2011 Time and Allocation Profiling Report (Final)
prof-doc-last +RTS -hc -p -RTS
total time = 0.34 secs (17 ticks @ 20 ms)
total alloc = 204,047,104 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
main.ys Main 35.3 39.2
main.xs Main 29.4 19.6
last_init_ys Main 23.5 27.4
last_init_xs Main 11.8 13.7
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 101 0 0.0 0.0 100.0 100.0
main Main 203 0 0.0 0.0 0.0 0.0
CAF Main 201 0 0.0 0.0 100.0 100.0
main Main 202 1 0.0 0.0 100.0 100.0
last_init_ys Main 209 1 23.5 27.4 23.5 27.4
main.ys Main 208 1 35.3 39.2 35.3 39.2
last_ys Main 207 1 0.0 0.0 0.0 0.0
last_init_xs Main 206 1 11.8 13.7 11.8 13.7
main.xs Main 205 1 29.4 19.6 29.4 19.6
last_xs Main 204 1 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal 199 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 188 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD 180 0 0.0 0.0 0.0 0.0
......@@ -14,4 +14,3 @@ g x = x
h :: Char -> Char
Just h = Just id
Fri Oct 14 16:27 2011 Time and Allocation Profiling Report (Final)
scc001 +RTS -hc -p -RTS
total time = 0.00 secs (0 ticks @ 20 ms)
total alloc = 46,020 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
MAIN MAIN 0.0 23.0
CAF GHC.IO.Encoding.Iconv 0.0 1.3
CAF GHC.IO.Handle.FD 0.0 74.2
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 101 0 0.0 23.0 0.0 100.0
CAF GHC.Show 141 0 0.0 0.3 0.0 0.3
CAF GHC.IO.Handle.FD 128 0 0.0 74.2 0.0 74.2
CAF GHC.IO.Encoding.Iconv 120 0 0.0 1.3 0.0 1.3
CAF GHC.Conc.Signal 110 0 0.0 0.7 0.0 0.7
CAF Main 107 0 0.0 0.4 0.0 0.4
(...) Main 206 1 0.0 0.0 0.0 0.0
h Main 205 1 0.0 0.0 0.0 0.0
main Main 202 1 0.0 0.0 0.0 0.0
g Main 204 1 0.0 0.0 0.0 0.0
f Main 203 1 0.0 0.0 0.0 0.0
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment