Wildly inaccurate profiling results
I have a program, compiled with cost-center profiling on, that takes about 5 minutes, 30 seconds to run (measured with a stopwatch), but the resulting .prof file reports the total time as 34 seconds. I know that this number doesn't include overhead due to profiling, but surely the overhead can't be that much! (Also, the program runs about as long when run without -P.) I'm using a copy of GHC built from sources checked out around July 1. I'd include the program, but it's very large and I'm not sure how to minimize it and preserve the same behavior. Any ideas as to what the problem might be? Thanks, Kirsten -- Kirsten Chevalier * [EMAIL PROTECTED] * Often in error, never in doubt ___ Glasgow-haskell-bugs mailing list [EMAIL PROTECTED] http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs
RE: Wildly inaccurate profiling results
I have a program, compiled with cost-center profiling on, that takes about 5 minutes, 30 seconds to run (measured with a stopwatch), but the resulting .prof file reports the total time as 34 seconds. I know that this number doesn't include overhead due to profiling, but surely the overhead can't be that much! (Also, the program runs about as long when run without -P.) I'm using a copy of GHC built from sources checked out around July 1. I'd include the program, but it's very large and I'm not sure how to minimize it and preserve the same behavior. Any ideas as to what the problem might be? I think the profiler only measures CPU time, so if the program is waiting for I/O or sleeping a lot of the time, that won't be included in the profile. Also, the overhead due to heap rofiling can sometimes be a lot, because it includes the time to scan the heap and collect the census data. Retainer profiling (+RTS -hr) is also especially expensive. You should see the profiling overheads drop considerably when not doing heap profiling, though. Cheers, Simon ___ Glasgow-haskell-bugs mailing list [EMAIL PROTECTED] http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs
Re: Wildly inaccurate profiling results
On Tue, Oct 21, 2003 at 05:21:37PM +0100, Simon Marlow wrote: I think the profiler only measures CPU time, so if the program is waiting for I/O or sleeping a lot of the time, that won't be included in the profile. I don't think that's the issue -- when I run the program with debugging flags on that print out what it's doing, I can tell that it spends at most the first minute reading in files, and at most the last minute writing files (out of 5.5 minutes). Also, top shows that the program is using around 97% of the CPU for most of its run. Also, the overhead due to heap rofiling can sometimes be a lot, because it includes the time to scan the heap and collect the census data. Retainer profiling (+RTS -hr) is also especially expensive. You should see the profiling overheads drop considerably when not doing heap profiling, though. I'm not doing any heap profiling -- the only profiling flag I'm using is -P. When I recompiled the program without any profiling and ran it again, it took about 4 minutes as opposed to 5.5, suggesting that the 34 seconds reported by profiling really is inaccurate. -- Kirsten Chevalier * [EMAIL PROTECTED] * Often in error, never in doubt I wish people weren't so set on being themselves, when that means being a bastard. -- Robertson Davies http://www.cs.berkeley.edu/~krc/ ___ Glasgow-haskell-bugs mailing list [EMAIL PROTECTED] http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs
Re: Wildly inaccurate profiling results
I think I understand what's going on: GC time isn't counted as part of the time reported by profiling. This seems misleading to me, since if your program is spending 4 times as much time doing GC as doing actual work (such as mine is), you'd want to know about it... but I suppose you can always just get the GC stats with -t anyway. -- Kirsten Chevalier * [EMAIL PROTECTED] * Often in error, never in doubt There is no such thing as a weird human being. It's just that some people require more understanding than others.--Tom Robbins http://www.cs.berkeley.edu/~krc/ ___ Glasgow-haskell-bugs mailing list [EMAIL PROTECTED] http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs
Wildly inaccurate profiling results
[Sorry if this shows up twice -- I accidentally posted from the wrong address and left something out.] I have a program, compiled with cost-center profiling on, that takes about 5 minutes, 30 seconds to run (measured with a stopwatch), but the resulting .prof file reports the total time as 34 seconds. I know that this number doesn't include overhead due to profiling, but surely the overhead can't be that much! (Also, the program runs about as long when run without -P.) I'm using a copy of GHC built from sources checked out around July 1. Also, using top I've observed that the program takes up about 120MB of memory, and I have much more memory than that, so there's no swapping going on. I'd include the program, but it's very large and I'm not sure how to minimize it and preserve the same behavior. Any ideas as to what the problem might be? Thanks, Kirsten -- Kirsten Chevalier * [EMAIL PROTECTED] * Often in error, never in doubt I always feel I have to take a stand, and there's always someone on hand to hate me for standing there / I always feel I have to open my mouth, and every time I do, I offend someone somewhere...--Ani DiFranco http://www.cs.berkeley.edu/~krc/ ___ Glasgow-haskell-bugs mailing list [EMAIL PROTECTED] http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs
