[racket-dev] weirdness with racket or typed racket module requiring startup time?

From: Danny Yoo (dyoo at cs.wpi.edu)
Date: Wed Sep 28 13:23:39 EDT 2011

>> I'm observing about a 100ms cost here for something that I expected to
>> be a no-op, because the module has already been required.
>>
>
> You think you could be taking a small GC hit then?  "PLTSTDERR=debug"
> environment variable might show GC info.  Or add debugging printfs that dump
> "(current-gc-milliseconds)" at each step in program.



Possibly.  Here's what I see on one of my older machines when I invoke
one of the entry-point modules into Whalesong.


dyoo at kfisler-ra1:~/work/whalesong$ PLTSTDERR=debug time racket
whalesong-helpers.rkt
GC [0:minor] at 1,713K(+238K)[+152K]; freed 857K(-4,953K) in 4 msec
GC [0:minor] at 1,965K(+4,082K)[+156K]; freed 558K(-1,854K) in 4 msec
GC [0:minor] at 3,454K(+4,993K)[+172K]; freed 877K(-877K) in 8 msec
GC [0:minor] at 5,504K(+3,471K)[+172K]; freed 1,250K(-2,546K) in 8 msec
GC [0:minor] at 7,311K(+3,312K)[+188K]; freed 1,196K(-6,588K) in 16 msec
GC [0:minor] at 10,370K(+6,253K)[+192K]; freed 2,064K(-7,456K) in 16 msec
GC [0:minor] at 13,768K(+8,679K)[+328K]; freed 2,947K(-4,243K) in 28 msec
GC [0:minor] at 17,891K(+6,716K)[+580K]; freed 3,724K(-14,508K) in 44 msec
GC [0:minor] at 22,335K(+13,536K)[+736K]; freed 3,952K(-6,544K) in 40 msec
GC [0:minor] at 28,611K(+11,564K)[+816K]; freed 4,591K(-16,671K) in 48 msec
GC [0:minor] at 38,072K(+17,831K)[+1,196K]; freed 8,097K(-28,369K) in 44 msec
GC [0:minor] at 46,609K(+29,566K)[+1,696K]; freed 12,936K(-13,960K) in 112 msec
GC [0:minor] at 51,924K(+25,275K)[+2,932K]; freed 11,081K(-16,265K) in 92 msec
GC [0:minor] at 65,100K(+18,835K)[+3,616K]; freed 16,881K(-22,065K) in 96 msec
GC [0:MAJOR] at 75,231K(+16,560K)[+4,568K]; freed 23,374K(-53,342K) in 296 msec
GC [0:minor] at 79,301K(+42,458K)[+4,752K]; freed 23,269K(-25,861K) in 40 msec
3.10user 0.28system 0:04.85elapsed 70%CPU (0avgtext+0avgdata 463504maxresident)k
0inputs+0outputs (0major+47826minor)pagefaults 0swaps




As an experiment, I have a branch in my repository where I try to
switch over all uses of #lang typed/racket/base to
typed/racket/base/no-check to measure performance differences.  See:

    https://github.com/dyoo/whalesong/tree/no-check


Unfortunately, this is failing unexpectedly.

#############################################################

dyoo at kfisler-ra1:~/work/whalesong$ raco make whalesong-helpers.rkt &&
time racket whalesong-helpers.rkt
procedure application: expected procedure, given: #f; arguments were: 2

 === context ===
/home/dyoo/work/whalesong/compiler/compiler.rkt:1305:0:
compile-statically-known-lam-application
/home/dyoo/work/whalesong/compiler/compiler.rkt:904:0: compile-lambda-bodies
/home/dyoo/work/whalesong/compiler/compiler.rkt:34:0: -compile
/home/dyoo/work/whalesong/compiler/bootstrapped-primitives.rkt:89:4:
make-bootstrapped-primitive-code
/home/dyoo/work/whalesong/compiler/bootstrapped-primitives.rkt:145:0:
get-bootstrapping-code
/home/dyoo/work/whalesong/make/make-structs.rkt: [running body]
/home/dyoo/work/whalesong/js-assembler/package.rkt: [traversing imports]
/home/dyoo/work/whalesong/whalesong-helpers.rkt: [traversing imports]


real	0m2.274s
user	0m1.940s
sys	0m0.248s

#############################################################

I'm seeing a runtime error by switching over to #lang
typed/racket/base/no-check, with the error highlight over my
definition of arity-matches?.  The definition for atomic-arity-list?
seems to not be bound, nor is natural?, both of which I define using
define-predicate.  Even when I try to hack in definitions for these,
I'm still receiving other error messages.

I'll send a bug report about no-check.



Posted on the dev mailing list.