Haskell › Haskell - Glasgow-haskell-bugs

[GHC] #6110: Data.Vector.Unboxed performance regression of 7.4.1 relative to 7.0.4

Classic

List

Threaded

14 messages Options

GHC

[GHC] #6110: Data.Vector.Unboxed performance regression of 7.4.1 relative to 7.0.4

#6110: Data.Vector.Unboxed performance regression of 7.4.1 relative to 7.0.4
-------------------------------------+--------------------------------------
Reporter: mdgabriel | Owner:
Type: bug | Status: new
Priority: normal | Component: Compiler
Version: 7.4.1 | Keywords: Vector Performance Regression
Os: Linux | Architecture: x86
Failure: Runtime performance bug | Testcase:
Blockedby: | Blocking:
Related: |
-------------------------------------+--------------------------------------
== Problem ==

Severe Data.Vector.Unboxed performance regression in 7.4.1 relative to
7.0.4:[[BR]]
(Sum GHC 7.4.1)/(Sum GHC 7.0.4) ~ 2.4[[BR]]

== System ==

GNU/Linux 3.2.0-24-generic 38-Ubuntu i386[[BR]]

== Compilers ==

GHC 7.0.4[[BR]]
GHC 7.4.1[[BR]]
GCC 4.6.3 for a baseline[[BR]]

== Main.hs ==

{{{
module Main where

import System.Environment (getArgs)
import qualified Data.Vector.Unboxed as U (generate, sum)

main :: IO ()
main = do args <- getArgs
if length args == 1
then putSum (read (head args) :: Int)
else error "need a count operand"

putSum :: Int -> IO ()
putSum cnt = let v = U.generate cnt (\i -> fromIntegral i :: Double)
s = U.sum v
in putStrLn ("Sum="++show s)

}}}

== GHC compilation ==

> ghc --version[[BR]]
7.4.1[[BR]]
> ghc -O2 -Wall --make -o sum Main.hs[[BR]]
[[BR]]
> ghc --version[[BR]]
7.0.4[[BR]]
> ghc -O2 -Wall --make -o sum Main.hs[[BR]]

== Baseline csum.c ==

{{{

#include <libgen.h>
#include <stdio.h>
#include <stdlib.h>

int main(int argc, char **argv)
{
unsigned long i, size;
double tot=0;

if (argc != 2)
{
(void)fprintf(stderr, "usage: %s size\n", basename(argv[0]));
return(1);
}

size = atol(argv[1]);

for(i = 0; i < size; i++) tot += (double)i;

(void)printf("Sum=%.15e\n", tot);

return(0);
}

}}}

== GCC baseline compilation ==

> gcc --version[[BR]]
4.6.3[[BR]]
> gcc -O2 -Wall csum.c -o csum[[BR]]

== Data: time sum-7.0.4 n ==

n seconds[[BR]]
100000000 0.74[[BR]]
200000000 1.46[[BR]]
300000000 2.24[[BR]]
400000000 2.94[[BR]]
500000000 3.70[[BR]]
600000000 4.40[[BR]]
700000000 5.14[[BR]]
800000000 5.89[[BR]]
900000000 6.62[[BR]]
1000000000 7.34[[BR]]

== Data: time sum-7.4.1 n ==

n seconds[[BR]]
100000000 1.74[[BR]]
200000000 3.49[[BR]]
300000000 5.24[[BR]]
400000000 6.98[[BR]]
500000000 8.73[[BR]]
600000000 10.51[[BR]]
700000000 12.22[[BR]]
800000000 13.96[[BR]]
900000000 15.75[[BR]]
1000000000 17.51[[BR]]

== Data: time csum-4.6.3 n ==

n seconds[[BR]]
100000000 1.04[[BR]]
200000000 2.10[[BR]]
300000000 3.12[[BR]]
400000000 4.19[[BR]]
500000000 5.23[[BR]]
600000000 6.26[[BR]]
700000000 7.32[[BR]]
800000000 8.37[[BR]]
900000000 9.41[[BR]]
1000000000 10.45[[BR]]

== Linear in n ==

y is in seconds[[BR]]
[[BR]]
GHC 7.0.4: y = (0.73/10^8) * n + 0.03[[BR]]
GCC 4.6.3: y = (1.04/10^8) * n + 0.03[[BR]]
GHC 7.4.1: y = (1.75/10^8) * n - 0.01[[BR]]

Severe performance regression:[[BR]]
GHC 7.4.1/GHC 7.0.4 ~ 1.75/0.73 ~ 2.4[[BR]]

== Notes ==

1/ I discovered the problem in a slightly more complicated case when I
recompiled a package that used some simple statisics. The sum of
[0..(n-1)] was the simplest case that I imagined to demonstrate the
problem.

2/ I tried a similar experiment with Data.List, Data.Array.Unboxed,
Data.Vector.Storable.MMap, and Foreign.Marshal.Alloc. In all cases,
the GHC 7.4.1 version was faster than the GHC 7.0.4 version.

3/ It is the same Data.Vector.Unboxed code in both cases compilied and
installed separately for each version of the GHC compiler. Thus, the
problem appears to be the interaction between Data.Vector.Unboxed and the
7.4.1 compiler that causes the performance regression.

4/ I am impressed that the GHC 7.0.4 sum is faster than the GCC 4.6.3 sum.
I expected it to be close, but not faster. Given this
impressive result, I certainly would hope that the same result can be
recovered once again.

--
Ticket URL: <http://hackage.haskell.org/trac/ghc/ticket/6110>
GHC <http://www.haskell.org/ghc/>
The Glasgow Haskell Compiler

_______________________________________________
Glasgow-haskell-bugs mailing list
[hidden email]
http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs

GHC

In reply to this post by GHC

GHC

Re: [GHC] #6110: Data.Vector.Unboxed performance regression of 7.4.1 relative to 7.0.4

In reply to this post by GHC

#6110: Data.Vector.Unboxed performance regression of 7.4.1 relative to 7.0.4
----------------------------------------------+-----------------------------
Reporter: mdgabriel | Owner: pcapriotti
Type: bug | Status: infoneeded
Priority: high | Milestone: 7.4.3
Component: Compiler | Version: 7.4.1
Keywords: Vector Performance Regression | Os: Linux
Architecture: x86 | Failure: Runtime performance bug
Difficulty: Unknown | Testcase:
Blockedby: | Blocking:
Related: #6111 |
----------------------------------------------+-----------------------------

Comment(by mdgabriel):

'''Profiling'''

SCC was used for profiling ghc 7.0.4 and 7.4.1:
{{{
putSum :: Int -> IO ()
putSum cnt = let f = {-# SCC "fromIntegral" #-} (\i -> fromIntegral i ::
Double)
v = {-# SCC "U.generate" #-} U.generate cnt f
s = {-# SCC "U.sum" #-} U.sum v
in putStrLn ("Sum="++show s)
}}}

Profiling using '-prof -auto-all' with ghc 7.0.4:
{{{
Fri Jun 22 19:00 2012 Time and Allocation Profiling Report
(Final)

sum704prof +RTS -p -RTS 100000000

total time = 45.54 secs (2277 ticks @ 20 ms)
total alloc = 14,800,016,380 bytes (excludes profiling overheads)

COST CENTRE MODULE %time %alloc

U.generate Main 46.9 35.1
U.sum Main 31.2 40.5
fromIntegral Main 21.9 24.3

individual inherited
COST CENTRE MODULE
no. entries %time %alloc %time %alloc

MAIN MAIN
1 0 0.0 0.0 100.0 100.0
CAF Main
300 2 0.0 0.0 100.0 100.0
main Main
306 1 0.0 0.0 100.0 100.0
putSum Main
307 1 0.0 0.0 100.0 100.0
U.sum Main
310 1 31.2 40.5 31.2 40.5
U.generate Main
309 1 46.9 35.1 46.9 35.1
fromIntegral Main
308 100000000 21.9 24.3 21.9 24.3
CAF GHC.Float
277 1 0.0 0.0 0.0 0.0
CAF Text.Read.Lex
266 4 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD
236 2 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv
194 2 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal
191 1 0.0 0.0 0.0 0.0
CAF Data.Vector.Unboxed
182 1 0.0 0.0 0.0 0.0
}}}

Profiling using '-prof -auto-all' with ghc 7.4.1:
{{{
Fri Jun 22 19:09 2012 Time and Allocation Profiling Report
(Final)

sum741prof +RTS -p -RTS 100000000

total time = 44.55 secs (44550 ticks @ 1000 us, 1
processor)
total alloc = 15,600,082,056 bytes (excludes profiling overheads)

COST CENTRE MODULE %time %alloc

U.sum Main 34.3 38.5
U.generate Main 31.0 38.5
putSum.f.\ Main 24.9 23.1
putSum.f Main 5.8 0.0
fromIntegral Main 3.9 0.0

individual
inherited
COST CENTRE MODULE no. entries %time %alloc
%time %alloc

MAIN MAIN 67 0 0.0 0.0
100.0 100.0
CAF Main 133 0 0.0 0.0
100.0 100.0
main Main 134 1 0.0 0.0
100.0 100.0
putSum Main 135 1 0.0 0.0
100.0 100.0
putSum.f Main 140 1 0.0 0.0
0.0 0.0
fromIntegral Main 141 1 0.0 0.0
0.0 0.0
putSum.v Main 138 1 0.0 0.0
65.7 61.5
U.generate Main 139 1 31.0 38.5
65.7 61.5
putSum.f Main 142 0 5.8 0.0
34.7 23.1
fromIntegral Main 143 0 3.9 0.0
28.9 23.1
putSum.f.\ Main 144 100000000 24.9 23.1
24.9 23.1
putSum.s Main 136 1 0.0 0.0
34.3 38.5
U.sum Main 137 1 34.3 38.5
34.3 38.5
CAF GHC.Conc.Signal 111 0 0.0 0.0
0.0 0.0
CAF Text.Read.Lex 104 0 0.0 0.0
0.0 0.0
CAF GHC.Float 101 0 0.0 0.0
0.0 0.0
CAF GHC.IO.Encoding 100 0 0.0 0.0
0.0 0.0
CAF GHC.IO.Encoding.Iconv 94 0 0.0 0.0
0.0 0.0
CAF GHC.IO.Handle.FD 92 0 0.0 0.0
0.0 0.0
}}}

'''Statistics'''

Statistics for sum compiled with ghc 7.0.4:
{{{
./sum704 1000000000 +RTS -ssum704-stats.txt
74,836 bytes allocated in the heap
1,440 bytes copied during GC
42,316 bytes maximum residency (1 sample(s))
23,220 bytes maximum slop
1 MB total memory in use (0 MB lost due to fragmentation)

Generation 0: 0 collections, 0 parallel, 0.00s, 0.00s elapsed
Generation 1: 1 collections, 0 parallel, 0.00s, 0.00s elapsed

INIT time 0.00s ( 0.00s elapsed)
MUT time 7.42s ( 7.46s elapsed)
GC time 0.00s ( 0.00s elapsed)
EXIT time 0.00s ( 0.00s elapsed)
Total time 7.43s ( 7.46s elapsed)

%GC time 0.0% (0.0% elapsed)

Alloc rate 10,078 bytes per MUT second

Productivity 100.0% of total user, 99.5% of total elapsed
}}}

Statistics for sum compiled with ghc 7.4.1:
{{{
./sum741 1000000000 +RTS -ssum741-stats.txt
87,864 bytes allocated in the heap
1,756 bytes copied during GC
42,632 bytes maximum residency (1 sample(s))
18,808 bytes maximum slop
1 MB total memory in use (0 MB lost due to fragmentation)

Tot time (elapsed) Avg pause Max
pause
Gen 0 0 colls, 0 par 0.00s 0.00s 0.0000s
0.0000s
Gen 1 1 colls, 0 par 0.00s 0.00s 0.0002s
0.0002s

INIT time 0.00s ( 0.00s elapsed)
MUT time 17.55s ( 17.69s elapsed)
GC time 0.00s ( 0.00s elapsed)
EXIT time 0.00s ( 0.00s elapsed)
Total time 17.55s ( 17.69s elapsed)

%GC time 0.0% (0.0% elapsed)

Alloc rate 5,006 bytes per MUT second

Productivity 100.0% of total user, 99.2% of total elapsed
}}}

--
Ticket URL: <http://hackage.haskell.org/trac/ghc/ticket/6110#comment:13>
GHC <http://www.haskell.org/ghc/>
The Glasgow Haskell Compiler

_______________________________________________
Glasgow-haskell-bugs mailing list
[hidden email]
http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs

GHC

Re: [GHC] #6110: Data.Vector.Unboxed performance regression of 7.4.1 relative to 7.0.4

In reply to this post by GHC

#6110: Data.Vector.Unboxed performance regression of 7.4.1 relative to 7.0.4
--------------------------------------+-------------------------------------
Reporter: mdgabriel | Owner: pcapriotti
Type: bug | Status: closed
Priority: high | Milestone: 7.4.3
Component: Compiler | Version: 7.4.1
Resolution: fixed | Keywords: Vector Performance Regression
Os: Linux | Architecture: x86
Failure: Runtime performance bug | Difficulty: Unknown
Testcase: | Blockedby:
Blocking: | Related: #6111
--------------------------------------+-------------------------------------
Changes (by mdgabriel):

* status: infoneeded => closed
* resolution: => fixed

Comment:

@pcapriotti and @igloo:

I built the head of GHC with the changeset
c7a8941b04541789e60950bb126902effae0ccab of #6110, and this recovered the
vast majority of the performance difference that I observed between 7.0.4
and 7.4.1.

The version 7.4.1 is still slower than 7.0.4 for me, but I most likely
would not have noticed this difference if the above changeset had already
been in place. For me, this ticket is closed.

--
Ticket URL: <http://hackage.haskell.org/trac/ghc/ticket/6110#comment:14>
GHC <http://www.haskell.org/ghc/>
The Glasgow Haskell Compiler

_______________________________________________
Glasgow-haskell-bugs mailing list
[hidden email]
http://www.haskell.org/mailman/listinfo/glasgow-haskell-bugs