Wait and perform

Spent time reading about hardware performance counters while waiting for builds and test runs. Realised that I had built the RTS with -fvia-c before, so there are still a couple of NCG things to fix before we can do a full stage2 -fasm build.

The RTS code uses a machine op MO_WriteBarrier that compiles to a nop on i386, but uses the LWSYNC instruction on PPC. I still have to read about that and work out what to do for sparc.

Also spent some time fighting a configure problem. The configure script can detect whether the assembler supports the -x flag, that tells it whether to export local symbol names. The configure script looks at the ld in the current path, but ghc calls gcc to do the assembly. That gcc will use whatever ld /it/ was configured with, and on mavericks the Solaris linker doesn't support -x. (epic sigh). In the same vein, the Solaris assembler doesn't support the .space directive. Fixed that and my builds are running again.

Started of a full run of the testsuite with the stage1 compiler + via-c rts, but that'll take all day and all night. num012 is failing with 16 bit integer arithmetic, but that's probably no big deal.

The hardware performance counters on the T2 are exercised with the cputrack util, which I spent some time learning about. You can get counts of instrs executed, branches taken, cache misses etc. There are lots of measurements available, but you can only collect two at a time - because there are only two PICs (performance instrumentation counters) on the T2.

For example:

  benl@mavericks:~/devel/ghc/ghc-HEAD-work/nofib/spectral/boyer> 
                           cputrack -t -T 10 -c Instr_cnt,DC_miss ./boyer 200
   time lwp      event     %tick      pic0      pic1 
  3.409   1       exit 3954145530 1730642411  32277574
True

benl@mavericks:~/devel/ghc/ghc-HEAD-work/nofib/spectral/boyer> 
                          cputrack -t -T 10 -c Instr_ld,Instr_st ./boyer 200

   time lwp      event     %tick      pic0      pic1 
  3.413   1       exit 3957292767 286778987 219450322
True

benl@mavericks:~/devel/ghc/ghc-HEAD-work/nofib/spectral/boyer> 
                           cputrack -t -T 10 -c Br_completed,Br_taken ./boyer 200
   time lwp      event     %tick      pic0      pic1 
  3.411   1       exit 3952535075 281792355 190004907
True

So, it looks like we're getting about 2.3 clocks per instruction (cpi). About 30% of instructions executed are loads or stores. If those load/stores account for L1 data cache misses then about 6% of them miss. That might be wrong though - I'll have to work out whether the info tables are stored in the data or instr cache. In any event, about 30% of all instructions are loads or stores , and another 16% are branches of which 67% are taken.

I'll post some nice graphs and whatnot once my nofib run has gone through. Should probably add the performance counters to nofib-analyse as well, in the place of valgrind on sparc / solaris.

The Strap

Implemented tabled switch, and fixed a problem when converting float to integer formats. The FSTOI instruction leaves its result in a float register, but in integer format. On at least V9 you then have to copy the value to mem and back to get it into an actual int register. Later architectures have instructions to do this without going via mem, but we're sticking with V9 for now. Perhaps we could get some speedup for FP code by using the later instruction set extensions (Vis2.0?)

The genCCall problem was that calls to out-of-line float ops like sin and exp were disabled for 32 bit floats, maybe because other things were broken before.

Also fixed a 64 bit FFI problem. Closures allocated by the storage manager are 32bit aligned, but the RTS was trying to do misaligned read/writes of 64bit words. The standard SPARC load/store instructions don't support misaligned read/writes, so had to break it them up into parts.

Looking good. A few tests still fail, but they fail the same way with all ways. I'm guessing that they are problems with Solaris or other environment stuff, and not the NCG.

I tried to do build the stage2 compiler with -fasm, but I made the foolish mistake of pulling from the head beforehand, which broken the build. Did a full distclean, but will have to leave it overnight.

OVERALL SUMMARY for test run started at Wednesday, 21 January 2009  9:05:20 AM EST
    2283 total tests, which gave rise to
    8531 test cases, of which
       0 caused framework failures
    7429 were skipped

    1047 expected passes
      32 expected failures
       0 unexpected passes
      23 unexpected failures

Unexpected failures:

   cvh_unboxing(optasm)       -- fixed
   seward-space-leak(optasm)  -- fixed
   1916(optasm)               -- fixed
   expfloat(optasm)           -- fixed
   fun_insts(optasm)          -- fixed
   2594(optasm)               -- fixed
   ffi019(optasm)             -- fixed
   arith011(optasm)           -- fixed

   barton-mangler-bug(optasm) -- optc: timeout. others: ok
   joao-circular(optasm)      -- timeout

---- noncrash fail all ways ----
   num012(optasm)
   hpc_fork(optasm)
   hClose002(optasm)
   user001(optasm)
   2910(optasm)
   tcrun007(optasm)
   T2914(optasm)
   annrun01(optasm)
   ann01(optasm)
   haddockA028(optasm)
   hpc001(optasm)
   process007(optasm)
   tough(optasm)

The Grind

Decided to address some of the other outstanding bugs before starting on genSwitch. I don't want other bugs to confuse the issue.

Did a full run of the testsuite with optasm. I added the triage comments manually.

OVERALL SUMMARY for test run started at Thursday, 15 January 2009  7:47:05 PM EST
    2283 total tests, which gave rise to
    8531 test cases, of which
       0 caused framework failures
    7429 were skipped

    1025 expected passes
      32 expected failures
       0 unexpected passes
      45 unexpected failures

Unexpected failures:
   arith004(optasm)           -- hpc: iselExpr64 panic. optasm: getRegister panic. 
   num012(optasm)             -- optasm: ppr match fail. others: wrong output
   process007(optasm)         -- hpc: iselExpr64. others: wrong output
   time003(optasm)            -- hpc: iselExpr64 panic. optasm: getRegister panic.
   bits(optasm)               -- hpc: iselExpr64 panic. optasm: getRegister panic.
   tough(optasm)              -- iselExpr64
   hpc001(optasm)             -- iselExpr64
   hpc_fork(optasm)           -- iselExpr64
   tc213(optasm)              -- getRegister

   expfloat(optasm)           -- genCCall can not reduce
   fun_insts(optasm)          -- genCCall can not reduce

   num013(optasm)             -- iselExpr64, match fail
   2388(optasm)               -- match fail
   enum02(optasm)             -- match fail
   enum03(optasm)             -- match fail
   arith011(optasm)           -- match fail
   arith017(optasm)           -- match fail
   ffi017(optasm)             -- match fail C types
   ffi018(optasm)             -- match fail 64bit ffi
   ffi019(optasm)             -- match fail 64bit ffi

   1916(optasm)               -- invalid register

   2594(optasm)               -- all ways: segv 64bit ffi

   seward-space-leak(optasm)  -- genSwitch
   simpl007(optasm)           -- genSwitch
   syn-perf(optasm)           -- genSwitch
   tup001(optasm)             -- genSwitch
   andy_cherry(optasm)        -- genSwitch
   arrowrun001(optasm)        -- genSwitch
   arrowrun004(optasm)        -- genSwitch
   barton-mangler-bug(optasm) -- genSwitch
   cg054(optasm)              -- genSwitch
   cvh_unboxing(optasm)       -- genSwitch
   drv005(optasm)             -- genSwitch
   drv006(optasm)             -- genSwitch
   drvrun014(optasm)          -- genSwitch
   joao-circular(optasm)      -- genSwitch
   jtod_circint(optasm)       -- genSwitch


   hClose002(optasm)          -- all ways: same wrong output
   user001(optasm)            -- all ways: same wrong output
   2910(optasm)               -- all ways: same wrong output
   tcrun007(optasm)           -- all ways: missing import
   T2914(optasm)              -- all ways: type error
   annrun01(optasm)           -- all ways: unknown package ghc
   ann01(optasm)              -- all ways: no TH in stage1 all ways
   haddockA028(optasm)        -- all ways: test wibble

Looking into arith004. The code to generate integer remainder / divide instructions was missing. On further investigation, old SPARC implementations didn't have hardware support for this. GHC used to call out to a library. The SPARC T2 has hardware divide, but you have to compute remainders using div/mul/sub. Added code to do so. Not sure if we still want to maintain the software mul/div path - but I'll worry about that when the rest is fixed and refactored. Also fixed code to generate 64 bit operations on 32 bit SPARC, which was the isel64Expr problem.

   arith004                   -- fixed
   bits                       -- fixed
   tc213                      -- fixed
   arith012                   -- fixed
   arith017                   -- fixed
   ffi017                     -- fixed
   ffi018                     -- fixed
   enum02                     -- fixed
   enum03                     -- fixed

   num012                     -- invalid register 64bit

   time003                    -- genSwitch

   ffi019(optasm)             -- all ways: bus error

   process007                 -- all ways: same wrong output
   tough                      -- all ways: same wrong output
   hpc001                     -- all ways: same wrong output
   hpc_fork                   -- all ways: same wrong output

Info tables

The info tables are getting broken for some reason. The Cmm code has:

sEl_ret()
        { [const Main.$wf_srt-sEl_info;, const 1;, const 2228231;]
        }

-fvia-c gives:

    .text
        .align 4
        .long Main_zdwf_srt - sEl_info
        .long 1
        .long 2228231
sEl_info:
        ....

but -fasm gives:

    .text
        .align 4
        .long Main_zdwf_srt+0         <---------- lost sE1_info
        .long 1
        .long 2228231
sEl_info:
        ....

some time later..

#if sparc_TARGET_ARCH
-- ToDo: This should really be fixed in the PIC support, but only
-- print a for now.
pprImm (ImmConstantDiff a b) = pprImm a 
#else
pprImm (ImmConstantDiff a b) = pprImm a <> char '-'
                            <> lparen <> pprImm b <> rparen
#endif

!!!! .... sigh.

Fixed that, but it still doesn't work. Here's the code for a whole closure:

    .data                        <-------------------------------- data
    .align 8
        .global Main_a_srt
    Main_a_srt:
        .long Main_lvl_closure
        .long base_GHCziHandle_stdout_closure
        .long base_GHCziIO_a28_closure
    .data
        .align 8
        .global Main_a_closure
    Main_a_closure:
        .long Main_a_info
        .long 0
    .text                              <-------------------------------- text
        .align 4
        .long Main_a_srt-(Main_a_info)+0        <-------- offset text to data
        .long 196609
        .long 0
        .long 983047
        .global Main_a_info
    Main_a_info:
    .LcGp:
        sethi %hi(base_GHCziHandle_stdout_closure),%l2
        or %l2,%lo(base_GHCziHandle_stdout_closure),%l2
        sethi %hi(Main_lvl_closure),%l3
        or %l3,%lo(Main_lvl_closure),%l3
        call base_GHCziIO_a28_info,0
        nop

SRTs (Static Resource Table?) are supposibly used for garbage collecting CAFs, but the GHC commentary page on them seems out of date, or missing. In any event, the assembler can't make an offset between labels in .text and .data segments. In some architectures .text and .data use entirely separate address spaces. This probably got broken in a previous GHC release when info tables were moved to be next to the code. Checking against x86 reveals it does the same thing, but the x86 assembler is ok with cross segment offsets.

I ended up just changing the pretty printer so it prints out ReadOnlyData segments as .text, which is a bit nasty. I'll be able to handle this in a nicer way when the sparc NCG is factored out into its own set of modules.

Win!

      56 expected passes
       1 expected failures
       0 unexpected passes
       3 unexpected failures

Unexpected failures:
   2080(optasm)      -- wrong output
   cg015(optasm)     -- unknown unary match op
   cg054(optasm)     -- genSwitch

That seems to have fixed the seg faulting ones.

Working on 2080.hs

-- cmm code is
        _sFv::I32 = %MO_UU_Conv_W8_W32(I8[R2]);   <--- load unsigned
        _sFx::I32 = _sFv::I32;
        _cG7::I32 = %MO_S_Le_W32(_sFx::I32, 127);
        if (_cG7::I32 >= 1) goto cGa;

-- -fvia-c gives:
        ldub [%l2], %g1                           <--- load unsigned
        cmp %g1, 127
        ble,pt %icc, .LL5
         sethi %hi(ghczmprim_GHCziBool_True_closure), %g1
        ...

-- -fasm gives:
        ldsb [%l2],%l0                            <--- load signed
        srl %l0,0,%l0                             <--- nop
        cmp %l0,127
        ble .LcGa
        nop
        ...

This was an easy operand format problem. However, I did notice that the Cmm code only ever loads unsigned data, like I8[R2]. If you were going to load signed data it would be better to use the sparc ldsb instruction which sign extends the byte in one go, versus doing an unsigned load then sign extending it separately. Another task for a simple peephole optimizer....

Also fixed the unknown unary match op problem - sign extension code was unfinished. genSwitch here we come.

Liveness lies

Yesterday I fixed the linear allocator to handle floating point register twinning, or at least I thought I did. The output code looked ok, but the programs I tried still crashed. I ended up spending the rest of the day writing a tool (mayet) to compare the -fasm and -fvia-c versions. Mayet takes the two .s files and splits them up into parts belonging to the individual closures. It then slowly substitutes the dubious -fasm sections for the known good -fvia-c sections.

Last night I got enough of it working to find a bad -fasm closure in cg034, which tests out floating point math. Curiously, the closure itself didn't do any float or double math. This morning I hand adjusted the -fvia-c version to look like the -fasm one until it exhibited the same problem.

After some wibbling around found this:

             ld [%l1+12],%vI_s1GO
                    # born:    %vI_s1GO
                     
             cmp %vI_s1GO,0
                    # r_dying: %vI_s1GO       <--------- LIES
                     
             bne .Lc2cm

                ......
                ......
        c2cm:
             ld [%l1+8],%vI_n2cH
                    # born:    %vI_n2cH
                     
             st %vI_n2cH,[%i0-12]
                    # r_dying: %vI_n2cH
                     
             sethi %hi(base_GHCziFloat_a_closure),%l2
                     
             or %l2,%lo(base_GHCziFloat_a_closure),%l2
                     
             or %g0,%vI_s1GO,%l3
                    # r_dying: %vI_s1GO       <---------

This is a dump of register liveness information. The line marked LIES shows that the allocator thinks that variable %vI_s1G0 isn't used after the cmp instruction. Unfortuntately, after the branch, it's used in an or. The vreg %vI_n2cH got allocated to the same register as %vI_s1G0, clobbering the contained value and causing the crash.

Turns out the register liveness determinator wasn't treating BI and BF as though they were branch instructions, so liveness information wasn't being propagated across the basic blocks properly.

Fixing that problem stopped cg034 from crashing, though it still gave the wrong answer. During debugging, noticed that if ghc is executed with -v or -ddump-reg-liveness then the top level labels emitted in the .s file change - which confuses mayet. Hmm.. let that be a lesson to all of us: changing compiler flags should not change top level names, if at all possible.

More digging

        (_s1Ri::F32,) = foreign "ccall" 
               __encodeFloat((_c2sm::I32, `signed'), (_c2sn::I32, PtrHint),
                             (_c2so::I32, `signed'))[_unsafe_call_];
        F32[Sp] = _s1Ri::F32;

Is translated to:

        call __int_encodeFloat,2
        nop

        st %f28,[%i0]         <- BOGUS %f28

A floating point return value should be placed in %f0, but for some reason the GHC code that does just that was missing. Fixed that, and it almost works... just gives the wrong answer.

Loading of doubles looks broken.

via-c says:

        ld [%l1+3], %f8
        fitod %f8, %f2

but the NGC does:

        ld [%l1+3],%l0
        st %l0,[%o6-8]
        ld [%o6-8],%f10
        fitos %f10,%f10

Hmm.

Remember that comment from a few days ago:

-- ToDo: Verify correctness

Turns out it wasn't correct.. Who would have known :P

That fixed cg034 and cg035. Now we're down to:

Unexpected failures:
   2080(optasm)   -- segv
   cg015(optasm)  -- unknown unary match op
   cg021(optasm)  -- segv
   cg022(optasm)  -- segv
   cg026(optasm)  -- segv 
   cg044(optasm)  -- segv
   cg046(optasm)  -- segv
   cg054(optasm)  -- genSwitch 
   cg058(optasm)  -- segv
   cg060(optasm)  -- segv

Bootstrapping 7

I'm still chasing down the source of that bug from last time. Spent some time re-reading the STG paper, and trolling through the RTS code.

Running the program with +RTS -DS didn't help, but I noticed a flag -Da that checks the format of closures while the program runs. However, it seemed to be disabled, or unused. There is code for it is in the RTS, but it doesn't show up in +RTS --help. Running the program with +RTS -Da gives:

benl@mavericks:~/devel/ghc/ghc-HEAD-native/tmp> ./Main +RTS -DS -Da
stg_ap_v_ret... PAP/1(3f5212, 3ef238)
stg_ap_0_ret... Bus error (core dumped)

Went chasing through the RTS code looking for the source of the Bus Error. -Da causes Printer.c:printClosure to be invoked print out a description of each closure, but the pointers passed to it are misaligned. That is, misaligned / containing pointer tag bits. Reread the dynamic pointer tagging paper, then fixed the RTS code.

Ended up doing a binary-ish search to find the problem. Starting with a known good .s file generated with -fvia-c, slowly copied dubious sections of the -fasm version into it, testing along the way. This works because in the current STG -> Cmm translation, top level STG functions only share data via pinned registers. This is sort of like a standard calling convention for GHC functions, so it doesn't matter if GHC and GCC do register allocation a little differently. It might be worthwhile automating this process if I hit similar problems in the future.

Anyway, it turn's out there's a world of difference between
mov %l1, %l2 and mov %l2, %l1...

With that fixed, ran the should_run codeGen tests and got

OVERALL SUMMARY for test run started at Monday, 12 January 2009  5:23:10 PM EST
      61 total tests, which gave rise to
     427 test cases, of which
       0 caused framework failures
     367 were skipped

      42 expected passes
       1 expected failures
       0 unexpected passes
      17 unexpected failures

Unexpected failures:
   1852(optasm)        -- regalloc
   1861(optasm)        -- regalloc
   2080(optasm)        -- wrong output
   cg015(optasm)       -- unknown unary match op
   cg018(optasm)       -- regalloc
   cg021(optasm)       -- segv
   cg022(optasm)       -- segv
   cg024(optasm)       -- regalloc
   cg026(optasm)       -- regalloc
   cg028(optasm)       -- regalloc
   cg034(optasm)       -- regalloc
   cg035(optasm)       -- regalloc
   cg044(optasm)       -- regalloc
   cg046(optasm)       -- segv
   cg054(optasm)       -- genSwitch not implemented
   cg058(optasm)       -- segv
   cg060(optasm)       -- segv

The ones marked spill die with:

ghc: panic! (the 'impossible' happened)
  (GHC version 6.11.20090110 for sparc-sun-solaris2):
        RegAllocLinear.allocRegsAndSpill: no spill candidates

Repaired the rot in the linear register allocator. The free register map only worked for x86(_64) and PPC. Now we've got:

   2080(optasm)    -- wrong output
   cg015(optasm)   -- unknown unary match op
   cg021(optasm)   -- segv
   cg022(optasm)   -- segv
   cg026(optasm)   -- segv
   cg034(optasm)   -- regalloc FF64
   cg035(optasm)   -- regalloc FF64
   cg044(optasm)   -- regalloc FF64
   cg046(optasm)   -- segv
   cg054(optasm)   -- genSwitch
   cg058(optasm)   -- segv
   cg060(optasm)   -- segv

The others marked regalloc are dying because the allocator is messing up the float register twinning. That'll be tomorrow's problem.

Bootstrapping 6

The build with the SPARC native code generator went through. Tried to run the test suite. For some reason when the compiler panics, the test framework runs off and tries to consume all available memory - like a fork bomb. Not sure why, maybe it was built wrong. Ended up just running individual tests by hand.

Ah, the joy of debugging assembly code. Fixed one problem where bad instructions were being generated. If you have LD [%f26 + ... ], %l1 then that's easy to find, because you can't use float regs for addressing.

Found a program from the test suite that seg faulted and spent some time reducing it to a smaller test case.

main = print (dude (1, 2))
dude xx
 = case xx of
   (x, y)    -> y

Seems to work, but

main = sum2 [1,2]
sum2 xx
 = case xx of
    []        -> 0
    (x:xs)    -> x + sum2 xs

always returns 0, no matter what size the list being summed is.

Spent about an hour staring at the STG, Cmm and NCG code, but couldn't see anything obviously wrong. Noticed that the current NCG doesn't use branch delay slots, there's a comment in the code saying that doing so would confuse the register allocator. This'll be a first port of call for optimization once the NCG is working again.

On the other hand, to compile the sum2 program above with -O0, GCC used 420 instructions but the NCG used only 361 (doesn't actually work though).

I'm finding it hugely useful to have the via-c path still in place. Besides the obvious fact that I can still compile the libraries with it, it's comforting to know that the Cmm code is good, and I can just concentrate on the Cmm -> Asm pass. All the tricky dynamic pointer tagging and whatnot is expressed in Cmm, which makes life a lot easier for me. It's also good to have multiple -O flags, because it's an easy way to create wibbles in the Cmm code when diagnosing bugs.

Got bored staring at assembly code, and went back to find a better test case. Ended up with:

main = print (up 0)
up x
 = case x of
  0 -> x

Note that up also takes a Num dictionary. Got:

Main: internal error: stg_ap_pp_ret
    (GHC version 6.11.20090105 for sparc_sun_solaris2)
    Please report this as a GHC bug:  http://www.haskell.org/ghc/reportabug
Abort (core dumped)

Bingo! Assertions in the RTS code are my new best friends.