1 -----------------------------------------------------------------------------
3 -- (c) Simon Marlow 1997-2005
5 -----------------------------------------------------------------------------
7 module Slurp (Status(..), Results(..), ResultTable, parse_log) where
10 import qualified Data.Map as Map
16 -----------------------------------------------------------------------------
17 -- This is the structure into which we collect our results:
19 type ResultTable = Map String Results
30 data Results = Results {
31 compile_time :: Map String Float,
32 module_size :: Map String Int,
33 binary_size :: Maybe Int,
34 link_time :: Maybe Float,
37 mut_elapsed_time :: [Float],
38 instrs :: Maybe Integer,
39 mem_reads :: Maybe Integer,
40 mem_writes :: Maybe Integer,
41 cache_misses :: Maybe Integer,
42 gc_work :: Maybe Integer,
44 gc_elapsed_time :: [Float],
46 gc0_elapsed_time :: [Float],
48 gc1_elapsed_time :: [Float],
50 allocs :: Maybe Integer,
52 compile_status :: Status
55 emptyResults :: Results
56 emptyResults = Results {
57 compile_time = Map.empty,
58 module_size = Map.empty,
59 binary_size = Nothing,
63 mut_elapsed_time = [],
67 cache_misses = Nothing,
71 gc0_elapsed_time = [],
73 gc1_elapsed_time = [],
77 compile_status = NotDone,
81 -----------------------------------------------------------------------------
87 ==nofib== awards: size of QSort.o follows...
88 ==nofib== banner: size of banner follows...
89 ==nofib== awards: time to link awards follows...
90 ==nofib== awards: time to run awards follows...
91 ==nofib== boyer2: time to compile Checker follows...
94 -- NB. the hyphen must come last (or first) inside [...] to stand for itself.
96 banner_re = mkRegex "^==nofib==[ \t]+([A-Za-z0-9_-]+):[ \t]+(size of|time to link|time to run|time to compile|time to compile & run)[ \t]+([A-Za-z0-9_-]+)(\\.o)?[ \t]+follows"
99 This regexp for the output of "time" works on FreeBSD, other versions
100 of "time" will need different regexps.
103 time_re :: String -> Maybe (Float, Float, Float)
104 time_re s = case matchRegex re s of
105 Just [real, user, system] ->
106 Just (read real, read user, read system)
107 Just _ -> error "time_re: Can't happen"
109 where re = mkRegex "^[ \t]*([0-9.]+)[ \t]+real[ \t]+([0-9.]+)[ \t]+user[ \t]+([0-9.]+)[ \t]+sys[ \t]*$"
111 time_gnu17_re :: String -> Maybe (Float, Float, String)
112 time_gnu17_re s = case matchRegex re s of
113 Just [user, system, elapsed] ->
114 Just (read user, read system, elapsed)
115 Just _ -> error "time_gnu17_re: Can't happen"
117 where re = mkRegex "^[ \t]*([0-9.]+)user[ \t]+([0-9.]+)system[ \t]+([0-9.:]+)elapsed"
118 -- /usr/bin/time --version reports: GNU time 1.7
119 -- notice the order is different, and the elapsed time
122 size_re :: String -> Maybe (Int, Int, Int)
123 size_re s = case matchRegex re s of
124 Just [text, datas, bss] ->
125 Just (read text, read datas, read bss)
126 Just _ -> error "size_re: Can't happen"
128 where re = mkRegex "^[ \t]*([0-9]+)[ \t]+([0-9]+)[ \t]+([0-9]+)"
131 <<ghc: 5820820 bytes, 0 GCs, 0/0 avg/max bytes residency (0 samples), 41087234 bytes GC work, 0.00 INIT (0.05 elapsed), 0.08 MUT (0.18 elapsed), 0.00 GC (0.00 elapsed) :ghc>>
133 = (bytes, gcs, avg_resid, max_resid, samples, gc_work,
134 init, init_elapsed, mut, mut_elapsed, gc, gc_elapsed)
136 ghc1_re = pre GHC 4.02
137 ghc2_re = GHC 4.02 (includes "xxM in use")
138 ghc3_re = GHC 4.03 (includes "xxxx bytes GC work")
139 ghc5_re = GHC 6.9 (includes GC(0) and GC(1) times)
142 ghc1_re :: String -> Maybe (Integer, Integer, Integer, Integer, Integer, Integer, Float, Float, Float, Float, Float, Float)
143 ghc1_re s = case matchRegex re s of
144 Just [allocations, gcs, avg_residency, max_residency, samples, gc_work', initialisation, initialisation_elapsed, mut, mut_elapsed, gc, gc_elapsed] ->
145 Just (read allocations, read gcs, read avg_residency, read max_residency, read samples, read gc_work', read initialisation, read initialisation_elapsed, read mut, read mut_elapsed, read gc, read gc_elapsed)
146 Just _ -> error "ghc1_re: Can't happen"
148 where re = mkRegex "^<<ghc:[ \t]+([0-9]+)[ \t]+bytes,[ \t]*([0-9]+)[ \t]+GCs,[ \t]*([0-9]+)/([0-9]+)[ \t]+avg/max bytes residency \\(([0-9]+) samples\\), ([0-9]+) bytes GC work, ([0-9.]+) INIT \\(([0-9.]+) elapsed\\), ([0-9.]+) MUT \\(([0-9.]+) elapsed\\), ([0-9.]+) GC \\(([0-9.]+) elapsed\\) :ghc>>"
150 ghc2_re :: String -> Maybe (Integer, Integer, Integer, Integer, Integer, Integer, Float, Float, Float, Float, Float, Float)
151 ghc2_re s = case matchRegex re s of
152 Just [allocations, gcs, avg_residency, max_residency, samples, in_use, initialisation, initialisation_elapsed, mut, mut_elapsed, gc, gc_elapsed] ->
153 Just (read allocations, read gcs, read avg_residency, read max_residency, read samples, read in_use, read initialisation, read initialisation_elapsed, read mut, read mut_elapsed, read gc, read gc_elapsed)
154 Just _ -> error "ghc2_re: Can't happen"
156 where re = mkRegex "^<<ghc:[ \t]+([0-9]+)[ \t]+bytes,[ \t]*([0-9]+)[ \t]+GCs,[ \t]*([0-9]+)/([0-9]+)[ \t]+avg/max bytes residency \\(([0-9]+) samples\\), ([0-9]+)M in use, ([0-9.]+) INIT \\(([0-9.]+) elapsed\\), ([0-9.]+) MUT \\(([0-9.]+) elapsed\\), ([0-9.]+) GC \\(([0-9.]+) elapsed\\) :ghc>>"
158 ghc3_re :: String -> Maybe (Integer, Integer, Integer, Integer, Integer, Integer, Integer, Float, Float, Float, Float, Float, Float)
159 ghc3_re s = case matchRegex re s of
160 Just [allocations, gcs, avg_residency, max_residency, samples, gc_work', in_use, initialisation, initialisation_elapsed, mut, mut_elapsed, gc, gc_elapsed] ->
161 Just (read allocations, read gcs, read avg_residency, read max_residency, read samples, read gc_work', read in_use, read initialisation, read initialisation_elapsed, read mut, read mut_elapsed, read gc, read gc_elapsed)
162 Just _ -> error "ghc3_re: Can't happen"
164 where re = mkRegex "^<<ghc:[ \t]+([0-9]+)[ \t]+bytes,[ \t]*([0-9]+)[ \t]+GCs,[ \t]*([0-9]+)/([0-9]+)[ \t]+avg/max bytes residency \\(([0-9]+) samples\\), ([0-9]+) bytes GC work, ([0-9]+)M in use, ([0-9.]+) INIT \\(([0-9.]+) elapsed\\), ([0-9.]+) MUT \\(([0-9.]+) elapsed\\), ([0-9.]+) GC \\(([0-9.]+) elapsed\\) :ghc>>"
166 ghc4_re :: String -> Maybe (Integer, Integer, Integer, Integer, Integer, Integer, Integer, Float, Float, Float, Float, Float, Float, Integer, Integer, Integer, Integer)
167 ghc4_re s = case matchRegex re s of
168 Just [allocations, gcs, avg_residency, max_residency, samples, gc_work', in_use, initialisation, initialisation_elapsed, mut, mut_elapsed, gc, gc_elapsed, instructions, memory_reads, memory_writes, l2_cache_misses] ->
169 Just (read allocations, read gcs, read avg_residency, read max_residency, read samples, read gc_work', read in_use, read initialisation, read initialisation_elapsed, read mut, read mut_elapsed, read gc, read gc_elapsed, read instructions, read memory_reads, read memory_writes, read l2_cache_misses)
170 Just _ -> error "ghc4_re: Can't happen"
172 where re = mkRegex "^<<ghc-instrs:[ \t]+([0-9]+)[ \t]+bytes,[ \t]*([0-9]+)[ \t]+GCs,[ \t]*([0-9]+)/([0-9]+)[ \t]+avg/max bytes residency \\(([0-9]+) samples\\), ([0-9]+) bytes GC work, ([0-9]+)M in use, ([0-9.]+) INIT \\(([0-9.]+) elapsed\\), ([0-9.]+) MUT \\(([0-9.]+) elapsed\\), ([0-9.]+) GC \\(([0-9.]+) elapsed\\), ([0-9]+) instructions, ([0-9]+) memory reads, ([0-9]+) memory writes, ([0-9]+) L2 cache misses :ghc-instrs>>"
174 ghc5_re :: String -> Maybe (Integer, Integer, Integer, Integer, Integer, Integer, Integer, Float, Float, Float, Float, Float, Float,Float,Float,Float,Float,Float)
175 ghc5_re s = case matchRegex re s of
176 Just [allocations, gcs, avg_residency, max_residency, samples, gc_work', in_use, initialisation, initialisation_elapsed, mut, mut_elapsed, gc, gc_elapsed, gc0, gc0_elapsed, gc1, gc1_elapsed, bal] ->
177 Just (read allocations, read gcs, read avg_residency, read max_residency, read samples, read gc_work', read in_use, read initialisation, read initialisation_elapsed, read mut, read mut_elapsed, read gc, read gc_elapsed, read gc0, read gc0_elapsed, read gc1, read gc1_elapsed, read bal)
178 Just _ -> error "ghc3_re: Can't happen"
180 where re = mkRegex "^<<ghc:[ \t]+([0-9]+)[ \t]+bytes,[ \t]*([0-9]+)[ \t]+GCs,[ \t]*([0-9]+)/([0-9]+)[ \t]+avg/max bytes residency \\(([0-9]+) samples\\), ([0-9]+) bytes GC work, ([0-9]+)M in use, ([0-9.]+) INIT \\(([0-9.]+) elapsed\\), ([0-9.]+) MUT \\(([0-9.]+) elapsed\\), ([0-9.]+) GC \\(([0-9.]+) elapsed\\), ([0-9.]+) GC\\(0\\) \\(([0-9.]+) elapsed\\), ([0-9.]+) GC\\(1\\) \\(([0-9.]+) elapsed\\), ([0-9.]+) balance :ghc>>"
182 wrong_exit_status, wrong_output, out_of_heap, out_of_stack :: Regex
183 wrong_exit_status = mkRegex "^\\**[ \t]*expected exit status ([0-9]+) not seen ; got ([0-9]+)"
184 wrong_output = mkRegex "^expected (stdout|stderr) not matched by reality$"
185 out_of_heap = mkRegex "^\\+ Heap exhausted;$"
186 out_of_stack = mkRegex "^\\+ Stack space overflow:"
188 parse_log :: String -> ResultTable
190 = combine_results -- collate information
192 . map process_chunk -- get information from each chunk
193 . tail -- first chunk is junk
194 . chunk_log [] [] -- break at banner lines
197 combine_results :: [(String,Results)] -> Map String Results
198 combine_results = foldr f Map.empty
200 f (prog,results) fm = Map.insertWith (flip combine2Results) prog results fm
202 combine2Results :: Results -> Results -> Results
204 Results{ compile_time = ct1, link_time = lt1,
206 run_time = rt1, mut_time = mt1,
207 mut_elapsed_time = me1,
208 instrs = is1, mem_reads = mr1, mem_writes = mw1,
210 gc_time = gt1, gc_elapsed_time = ge1, gc_work = gw1,
211 gc0_time = g0t1, gc0_elapsed_time = g0e1,
212 gc1_time = g1t1, gc1_elapsed_time = g1e1,
214 binary_size = bs1, allocs = al1,
215 run_status = rs1, compile_status = cs1 }
216 Results{ compile_time = ct2, link_time = lt2,
218 run_time = rt2, mut_time = mt2,
219 mut_elapsed_time = me2,
220 instrs = is2, mem_reads = mr2, mem_writes = mw2,
222 gc_time = gt2, gc_elapsed_time = ge2, gc_work = gw2,
223 gc0_time = g0t2, gc0_elapsed_time = g0e2,
224 gc1_time = g1t2, gc1_elapsed_time = g1e2,
226 binary_size = bs2, allocs = al2,
227 run_status = rs2, compile_status = cs2 }
228 = Results{ compile_time = Map.unionWith (flip const) ct1 ct2,
229 module_size = Map.unionWith (flip const) ms1 ms2,
230 link_time = lt1 `mplus` lt2,
231 run_time = rt1 ++ rt2,
232 mut_time = mt1 ++ mt2,
233 mut_elapsed_time = me1 ++ me2,
234 instrs = is1 `mplus` is2,
235 mem_reads = mr1 `mplus` mr2,
236 mem_writes = mw1 `mplus` mw2,
237 cache_misses = cm1 `mplus` cm2,
238 gc_time = gt1 ++ gt2,
239 gc_elapsed_time= ge1 ++ ge2,
240 gc0_time = g0t1 ++ g0t2,
241 gc0_elapsed_time= g0e1 ++ g0e2,
242 gc1_time = g1t1 ++ g1t2,
243 gc1_elapsed_time= g1e1 ++ g1e2,
245 gc_work = gw1 `mplus` gw2,
246 binary_size = bs1 `mplus` bs2,
247 allocs = al1 `mplus` al2,
248 run_status = combStatus rs1 rs2,
249 compile_status = combStatus cs1 cs2 }
251 combStatus :: Status -> Status -> Status
252 combStatus NotDone y = y
253 combStatus x NotDone = x
256 chunk_log :: [String] -> [String] -> [String] -> [([String],[String])]
257 chunk_log header chunk [] = [(header,chunk)]
258 chunk_log header chunk (l:ls) =
259 case matchRegex banner_re l of
260 Nothing -> chunk_log header (l:chunk) ls
261 Just stuff -> (header,chunk) : chunk_log stuff [] ls
263 process_chunk :: ([String],[String]) -> [(String,Results)]
264 process_chunk (progName : what : modName : _, chk) =
266 "time to compile" -> parse_compile_time progName modName chk
267 "time to run" -> parse_run_time progName (reverse chk) emptyResults NotDone
268 "time to compile & run" -> parse_compile_time progName modName chk
269 ++ parse_run_time progName (reverse chk) emptyResults NotDone
270 "time to link" -> parse_link_time progName chk
271 "size of" -> parse_size progName modName chk
272 _ -> error ("process_chunk: "++what)
273 process_chunk _ = error "process_chunk: Can't happen"
275 parse_compile_time :: String -> String -> [String] -> [(String, Results)]
276 parse_compile_time _ _ [] = []
277 parse_compile_time progName modName (l:ls) =
279 Just (_real, user, _system) ->
280 let ct = Map.singleton modName user
282 [(progName, emptyResults{compile_time = ct})];
285 case time_gnu17_re l of {
286 Just (user, _system, _elapsed) ->
287 let ct = Map.singleton modName user
289 [(progName, emptyResults{compile_time = ct})];
293 Just (_, _, _, _, _, _, initialisation, _, mut, _, gc, _) ->
295 time = (initialisation + mut + gc) :: Float
296 ct = Map.singleton modName time
298 [(progName, emptyResults{compile_time = ct})];
302 Just (_, _, _, _, _, _, initialisation, _, mut, _, gc, _) ->
303 let ct = Map.singleton modName (initialisation + mut + gc)
305 [(progName, emptyResults{compile_time = ct})];
309 Just (_, _, _, _, _, _, _, initialisation, _, mut, _, gc, _) ->
310 let ct = Map.singleton modName (initialisation + mut + gc)
312 [(progName, emptyResults{compile_time = ct})];
316 Just (_, _, _, _, _, _, _, initialisation, _, mut, _, gc, _, _, _, _, _) ->
317 let ct = Map.singleton modName (initialisation + mut + gc)
319 [(progName, emptyResults{compile_time = ct})];
322 parse_compile_time progName modName ls
325 parse_link_time :: String -> [String] -> [(String, Results)]
326 parse_link_time _ [] = []
327 parse_link_time prog (l:ls) =
329 Just (_real, user, _system) ->
330 [(prog,emptyResults{link_time = Just user})];
333 case time_gnu17_re l of {
334 Just (user, _system, _elapsed) ->
335 [(prog,emptyResults{link_time = Just user})];
338 parse_link_time prog ls
342 -- There might be multiple runs of the program, so we have to collect up
343 -- all the results. Variable results like runtimes are aggregated into
344 -- a list, whereas the non-variable aspects are just kept singly.
345 parse_run_time :: String -> [String] -> Results -> Status
346 -> [(String, Results)]
347 parse_run_time _ [] _ NotDone = []
348 parse_run_time prog [] res ex = [(prog, res{run_status=ex})]
349 parse_run_time prog (l:ls) res ex =
351 Just (allocations, _, _, _, _, _, initialisation, _, mut, mut_elapsed, gc, gc_elapsed) ->
352 got_run_result allocations initialisation mut mut_elapsed gc gc_elapsed [] [] [] [] []
353 Nothing Nothing Nothing Nothing Nothing;
357 Just (allocations, _, _, _, _, _, initialisation, _, mut, mut_elapsed, gc, gc_elapsed) ->
358 got_run_result allocations initialisation mut mut_elapsed gc gc_elapsed [] [] [] [] []
359 Nothing Nothing Nothing Nothing Nothing;
364 Just (allocations, _, _, _, _, gc_work', _, initialisation, _, mut, mut_elapsed, gc, gc_elapsed) ->
365 got_run_result allocations initialisation mut mut_elapsed gc gc_elapsed [] [] [] [] []
366 (Just gc_work') Nothing Nothing Nothing Nothing;
371 Just (allocations, _, _, _, _, gc_work', _, initialisation, _, mut, mut_elapsed, gc, gc_elapsed, is, mem_rs, mem_ws, cache_misses') ->
372 got_run_result allocations initialisation mut mut_elapsed gc gc_elapsed [] [] [] [] []
373 (Just gc_work') (Just is) (Just mem_rs)
374 (Just mem_ws) (Just cache_misses');
379 Just (allocations, _, _, _, _, gc_work', _, initialisation, _, mut, mut_elapsed, gc, gc_elapsed, gc0, gc0_elapsed, gc1, gc1_elapsed, bal) ->
380 got_run_result allocations initialisation mut mut_elapsed gc gc_elapsed
381 [gc0] [gc0_elapsed] [gc1] [gc1_elapsed] [bal]
382 (Just gc_work') Nothing Nothing Nothing Nothing;
386 case matchRegex wrong_output l of {
388 parse_run_time prog ls res (combineRunResult WrongStdout ex);
390 parse_run_time prog ls res (combineRunResult WrongStderr ex);
391 Just _ -> error "wrong_output: Can't happen";
394 case matchRegex wrong_exit_status l of {
395 Just [_wanted, got] ->
396 parse_run_time prog ls res (combineRunResult (Exit (read got)) ex);
397 Just _ -> error "wrong_exit_status: Can't happen";
400 case matchRegex out_of_heap l of {
402 parse_run_time prog ls res (combineRunResult OutOfHeap ex);
405 case matchRegex out_of_stack l of {
407 parse_run_time prog ls res (combineRunResult OutOfStack ex);
409 parse_run_time prog ls res ex;
413 got_run_result allocations initialisation mut mut_elapsed gc gc_elapsed gc0 gc0_elapsed gc1 gc1_elapsed bal gc_work' instrs' mem_rs mem_ws cache_misses'
414 = -- trace ("got_run_result: " ++ initialisation ++ ", " ++ mut ++ ", " ++ gc) $
416 time = initialisation + mut + gc
417 res' = combine2Results res
418 emptyResults{ run_time = [time],
420 mut_elapsed_time = [mut_elapsed],
422 gc_elapsed_time = [gc_elapsed],
424 gc0_elapsed_time = gc0_elapsed,
426 gc1_elapsed_time = gc1_elapsed,
429 allocs = Just allocations,
433 cache_misses = cache_misses',
437 parse_run_time prog ls res' Success
439 combineRunResult :: Status -> Status -> Status
440 combineRunResult OutOfHeap _ = OutOfHeap
441 combineRunResult _ OutOfHeap = OutOfHeap
442 combineRunResult OutOfStack _ = OutOfStack
443 combineRunResult _ OutOfStack = OutOfStack
444 combineRunResult (Exit e) _ = Exit e
445 combineRunResult _ (Exit e) = Exit e
446 combineRunResult exit _ = exit
448 parse_size :: String -> String -> [String] -> [(String, Results)]
449 parse_size _ _ [] = []
450 parse_size progName modName (l:ls) =
452 Nothing -> parse_size progName modName ls
453 Just (text, datas, _bss)
454 | progName == modName ->
455 [(progName,emptyResults{binary_size =
457 compile_status = Success})]
459 let ms = Map.singleton modName (text + datas)
461 [(progName,emptyResults{module_size = ms})]