*Excruciatingly* slow (over ten seconds for `(+ 1 1)`) with language "How To Design Programs - Beginning Student"

Question

I just installed DrRacket, and tried out the language "How To Design Programs - Beginning Student".

Racket - A programmable programming language

Racket - Getting Started

I run (+ 1 1), and it takes over ten seconds for this to show up:

Welcome to DrRacket, version 6.5 [3m].
Language: Beginning Student; memory limit: 128 MB.
2
> 

As far as I can tell, my installation is pretty much "out of the box".

What I'm wondering is if my experience is unusual,
and if there's any obvious way to troubleshoot it if so
(I've looked around the settings and didn't find anything obvious to tweak),
or if maybe the whole HTDP language was quietly abandoned or something...?

EDIT 1

I have these files:

/usr/share/racket $
find -iname "*htdp*.zo"
./pkgs/htdp-lib/lang/private/compiled/create-htdp-executable_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-reader_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-beginner-abbr-reader_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-langs-save-file-prefix_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-advanced-reader_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-intermediate-lambda-reader_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-advanced_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-beginner-abbr_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-intermediate_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-intermediate-reader_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-langs_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-beginner_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-intermediate-lambda_rkt.zo
./pkgs/htdp-lib/lang/compiled/htdp-beginner-reader_rkt.zo
./pkgs/htdp-doc/scribblings/htdp-langs/compiled/htdp-langs_scrbl.zo
./pkgs/htdp-doc/scribblings/htdp-langs/compiled/htdp-ptr_scrbl.zo
./pkgs/htdp-doc/htdp/compiled/htdp_scrbl.zo
./pkgs/htdp-doc/htdp/compiled/htdp-lib_scrbl.zo
./pkgs/htdp-doc/teachpack/htdp/scribblings/compiled/htdp_scrbl.zo
./pkgs/htdp-doc/teachpack/2htdp/scribblings/compiled/2htdp_scrbl.zo

EDIT 2 - cpu and harddrive specs

CPU

$ cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model               : 28
model name      : Intel(R) Atom(TM) CPU N450   @ 1.66GHz
stepping        : 10
microcode       : 0x107
cpu MHz             : 1000.000
cache size      : 512 KB
physical id     : 0
siblings        : 2
core id             : 0
cpu cores       : 1
apicid              : 0
initial apicid  : 0
fpu                 : yes
fpu_exception   : yes
cpuid level     : 10
wp                  : yes
flags               : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts nopl aperfmperf pni dtes64 monitor ds_cpl est tm2 ssse3 cx16 xtpr pdcm movbe lahf_lm dtherm
bugs                :
bogomips        : 3325.00
clflush size    : 64
cache_alignment : 64
address sizes   : 32 bits physical, 48 bits virtual
power management:

processor       : 1
vendor_id       : GenuineIntel
cpu family      : 6
model               : 28
model name      : Intel(R) Atom(TM) CPU N450   @ 1.66GHz
stepping        : 10
microcode       : 0x107
cpu MHz             : 1000.000
cache size      : 512 KB
physical id     : 0
siblings        : 2
core id             : 0
cpu cores       : 1
apicid              : 1
initial apicid  : 1
fpu                 : yes
fpu_exception   : yes
cpuid level     : 10
wp                  : yes
flags               : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts nopl aperfmperf pni dtes64 monitor ds_cpl est tm2 ssse3 cx16 xtpr pdcm movbe lahf_lm dtherm
bugs                :
bogomips        : 3325.00
clflush size    : 64
cache_alignment : 64
address sizes   : 32 bits physical, 48 bits virtual
power management:

HD

$ sudo hdparm -I /dev/sda
/dev/sda:

ATA device, with non-removable media
    Model Number:       Hitachi HTS545016B9A300                 
    Serial Number:      100324PBPB06ECC0K6XL
    Firmware Revision:  PBBOC60F
    Transport:          Serial, ATA8-AST, SATA 1.0a, SATA II Extensions, SATA Rev 2.5, SATA Rev 2.6; Revision: ATA8-AST T13 Project D1697 Revision 0b
Standards:
    Used: unknown (minor revision code 0x0028) 
    Supported: 8 7 6 5 
    Likely used: 8
Configuration:
    Logical                 max current
    cylinders       16383   16383
    heads                   16  16
    sectors/track   63      63
    --
    CHS current addressable sectors:   16514064
    LBA    user addressable sectors:  268435455
    LBA48  user addressable sectors:  312581808
    Logical/Physical Sector size:           512 bytes
    device size with M = 1024*1024:      152627 MBytes
    device size with M = 1000*1000:      160041 MBytes (160 GB)
    cache/buffer size  = 7208 KBytes (type=DualPortCache)
    Form Factor: 2.5 inch
    Nominal Media Rotation Rate: 5400
Capabilities:
    LBA, IORDY(can be disabled)
    Queue depth: 32
    Standby timer values: spec'd by Vendor, no device specific minimum
    R/W multiple sector transfer: Max = 16  Current = 16
    Advanced power management level: 254
    Recommended acoustic management value: 128, current value: 254
    DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 udma5 *udma6 
         Cycle time: min=120ns recommended=120ns
    PIO: pio0 pio1 pio2 pio3 pio4 
         Cycle time: no flow control=120ns  IORDY flow control=120ns
Commands/features:
    Enabled Supported:
       *    SMART feature set
            Security Mode feature set
       *    Power Management feature set
       *    Write cache
       *    Look-ahead
       *    Host Protected Area feature set
       *    WRITE_BUFFER command
       *    READ_BUFFER command
       *    NOP cmd
       *    DOWNLOAD_MICROCODE
       *    Advanced Power Management feature set
            Power-Up In Standby feature set
       *    SET_FEATURES required to spinup after power up
            SET_MAX security extension
            Automatic Acoustic Management feature set
       *    48-bit Address feature set
       *    Device Configuration Overlay feature set
       *    Mandatory FLUSH_CACHE
       *    FLUSH_CACHE_EXT
       *    SMART error logging
       *    SMART self-test
       *    General Purpose Logging feature set
       *    WRITE_{DMA|MULTIPLE}_FUA_EXT
       *    64-bit World wide name
       *    IDLE_IMMEDIATE with UNLOAD
       *    WRITE_UNCORRECTABLE_EXT command
       *    {READ,WRITE}_DMA_EXT_GPL commands
       *    Segmented DOWNLOAD_MICROCODE
       *    Gen1 signaling speed (1.5Gb/s)
       *    Gen2 signaling speed (3.0Gb/s)
       *    Native Command Queueing (NCQ)
       *    Host-initiated interface power management
       *    Phy event counters
       *    NCQ priority information
            Non-Zero buffer offsets in DMA Setup FIS
       *    DMA Setup Auto-Activate optimization
            Device-initiated interface power management
            In-order data delivery
       *    Software settings preservation
       *    SMART Command Transport (SCT) feature set
       *    SCT Write Same (AC2)
       *    SCT Error Recovery Control (AC3)
       *    SCT Features Control (AC4)
       *    SCT Data Tables (AC5)
Security: 
    Master password revision code = 65534
        supported
    not enabled
    not locked
        frozen
    not expired: security count
        supported: enhanced erase
    64min for SECURITY ERASE UNIT. 66min for ENHANCED SECURITY ERASE UNIT. 
Logical Unit WWN Device Identifier: 5000cca5ffc040a7
    NAA             : 5
    IEEE OUI    : 000cca
    Unique ID   : 5ffc040a7
Checksum: correct

EDIT 3 command-line times

ran (+ 1 1) in HTDP-beginner 3 times -- Over 5 seconds.

$ time racket -t racket_HTDP_beginner.rkt
2
5.60user 1.04system 0:08.46elapsed 78%CPU (0avgtext+0avgdata 127968maxresident)k
5496inputs+0outputs (46major+40955minor)pagefaults 0swaps

$ time racket -t racket_HTDP_beginner.rkt
2
5.51user 0.67system 0:06.71elapsed 92%CPU (0avgtext+0avgdata 128124maxresident)k
24inputs+0outputs (0major+41790minor)pagefaults 0swaps

$ time racket -t racket_HTDP_beginner.rkt
2
5.41user 0.67system 0:06.55elapsed 92%CPU (0avgtext+0avgdata 128180maxresident)k
0inputs+0outputs (0major+36683minor)pagefaults 0swaps

ran (+ 1 1) in #lang racket 3 times -- A bit over 2 seconds.

$ time racket -t racket_lang_racket.rkt
2
2.13user 0.25system 0:02.71elapsed 87%CPU (0avgtext+0avgdata 64996maxresident)k
0inputs+0outputs (0major+12437minor)pagefaults 0swaps

$ time racket -t racket_lang_racket.rkt
2
2.15user 0.25system 0:02.63elapsed 91%CPU (0avgtext+0avgdata 61700maxresident)k
0inputs+0outputs (0major+15853minor)pagefaults 0swaps

$ time racket -t racket_lang_racket.rkt
2
2.28user 0.29system 0:02.89elapsed 89%CPU (0avgtext+0avgdata 61500maxresident)k
0inputs+0outputs (0major+15015minor)pagefaults 0swaps

EDIT 4

Running free -h every second while DrRacket is running (+ 1 1) in lang HTDP-beginner
(not running any other applications besides DrRacket and my basic system (ie window manager etc))
(this is fish shell, by the way):

http://pastebin.com/2RdZAuXj

At that point I had to kill DrRacket cuz everything was freezing up.

Anyway, yeah, it's leaking, obviously.

Everytime I re-ran the code in DrRacket, memory usage went up and stayed up.

I had only run it about twenty...two-ish (?) more times
(so maybe thirty-ish in total?)
by the point where it started getting near the limit
and I killed it to unfreeze the system.

I guess I should try this with normal #lang racket and see what happens...

EDIT 5

Yup, it leaks the same way:

http://pastebin.com/373PNnY7

Homomorphism

I confirm that it's much slower than #lang racket which could compute the result instantly, though for my case the beginning student language takes only 3 seconds. 10 seconds seems to be really bad... – Diarchy

Have you tried increasing the memory limit? (Racket -> limit Memory). I am using it on Windows XP (dual hamster pc) and it is fine after a program restart. – Urbanism

@SoraweePorncharoenwase Actually I just tested it on a computer with a better harddrive (ie a SSD rather than ancient spinning rust), and it gets about ~3 seconds for "HTDP beginner" rather than that >10 seconds, so... any idea why it might be reading from the drive so ridiculously heavily? (summary: bad hd: (htdp: >10 secs, racket: ~3 secs), better hd: (htdp: ~3 secs, racket: ~1 secs) ; normal performance?) – Homomorphism

@RyanVincent it takes over ten seconds to do "one plus one" because 128 MB of memory isn't enough...? >:? – Homomorphism

Ya, I have to agree here, I'm almost certain that Racket doesn't need 128 MB to add 1+1. @Owen_R, does it take that amount of time just once, or every time you want to run the program? – Holub

Every time (see my comments on soegaard's answer -- I thought I was clear, but I should've been more explicit than just using the verb form "takes" rather than "took" xD). – Homomorphism

@soegaard not sure if you saw Owen_R's above comment -- (summary: bad hd: (htdp: >10 secs, racket: ~3 secs), better hd: (htdp: ~3 secs, racket: ~1 secs) ; normal performance?), but it doesn't seem to be about Gentoo package. I think there are two things to investigate: why is it unacceptably really slow on a bad hd, and why does beginning student language is slower than normal racket (regardless of any hardware)? – Diarchy

@Owen_R How much total memory is in the machine? – Undeceive

@SoraweePorncharoenwase With regards to being slow an a computer with a bad hd: Requiring a module will load it the corresponding zo-file as well as all zo-files needed by that file. For things like the Beginning Language, a lot zo-files will read from disk. Each zo-file is stored as an individual file, so a slow hd can (it seems) become a bottle neck. Some time ago it was discussed whether it was worth trying to store all (or some) zo-file in one large file. That should improve loading times. – Undeceive

@SoraweePorncharoenwase I think I was wrong about it reading the HD a bunch. I initially thought I saw a bunch of HD writing from DrRacket in iotop -ao while it was running the "one plus one" code, but I can't get it to happen again (like, I'm not getting any writing before/during/after the run). So @Undeceive I think maybe the zo-files were a red herring. Like, even if I'm not just completely wrong about seeing the writing initially, it was a one-time thing that had no subjectively noticeable effect, and is unrelated to the consistently reproducible slowness. – Homomorphism

@Undeceive As for total memory, about 1.9G. I'll put the results of free -h in EDIT4. – Homomorphism

@Undeceive Okay well, that got a bit more involved than I was expecting. So! ...It's a really bad memory leak, then? – Homomorphism

Based on the comments I'm seeing here, it looks like Jens Soegaard's original comments stand: that is, it looks like the racket that's a part of the gentoo distro was improperly packaged. Have you tried installing from the package available directly from www.racket-lang.org ? – Knighthood

@JohnClements "here" meaning the comment thread on my question? You should also read the comment thread on his answer. This problem happens identically with the gentoo package and both of the packages from racket-lang.org ("Linux x86_64" and "Unix source + built packages"). If you look at the pastebin links in my question, you can see it's a very fast memory leak by DrRacket, right? – Homomorphism

@JohnClements I mean, what happens if you do that test? (Run (+ 1 1) in DrRacket over and over again while looking at the output of a loop that doesfree -hevery second.) Can you see the memory usage keep going up? Or does it not do that for you? – Homomorphism

Answer 1

I am 90% sure that the reason you had to wait was that your installation of Racket wasn't done properly.

During installation the program setup-plt needs to be run. It precompiles all racket files (.rkt) into so-called zo-files. If this step is omitted, then DrRacket do the compilation for you the first time a file is needed.

In your case (I am guessing) it it your first time using the Beginner language, so all files relating to it needs to be compiled. And that takes a while.

The best solution is to use the official installers from http://download.racket-lang.org/ they all include precompiled zo-files.

If you happen to have used such an installer, then try again - and if the problem persist - do file a bug report (use the bug report in the Help menu in DrRacket).

Undeceive

To clarify, (you phrased it "had to wait" maybe implying it was only once, even though I said "takes" not "took") this happens every time I run it. I edited my question to add a list of the .zo files I have... Do you still think this answer might apply? – Homomorphism

Do you have more information on your system? Is it Linux? Did you use the official installer from download.racket-lang.org ? – Undeceive

gentoo, installed through portage... Looking at the comments on the question, I'm now wondering if it's because it's reading ridiculously heavily from the harddrive for some reason...? – Homomorphism

I think something went wrong when Racket was packed for Gentoo. I highly recommend using the official installer: Either the "Linux x86_64" or the "Unix source + built packages" installer. – Undeceive

Tried both of em, both DrRackets take over 10 seconds. Saving it to a file and running from the command-line was faster, but still pretty slow time racket -t htdp.rkt 2 4.27user 0.58system 0:05.52elapsed 88%CPU (0avgtext+0avgdata 147744maxresident)k 0inputs+0outputs (0major+29609minor)pagefaults 0swaps. (Think I was wrong about it reading the HD a bunch. Initially thought I saw that, but can't get it to happen again in iotop -ao.) – Homomorphism

Anyway, I'm suspicious that DrRacket/Racket is maybe just written such that it's really slow, and on a less powerful system like my netbook here, the absolute time just gets really noticeable? (Ever normal racket takes 3 seconds to return on "one plus one".) I added the specs on the computer's HD and CPU in case anyone wants to know, but I think I've lost interest... – Homomorphism

Thanks for testing this. We will look into whether something needs to be done to the Gentoo package. – Undeceive

Yeah, thanks for trying to help anyway... but to be clear (since you just mentioned the Gentoo package), I did try the Gentoo package and both the "Linux x86_64" and the "Unix source + built packages", and got the same results on all three. – Homomorphism

If I understood correctly all three were slow for you - but the Gentoo version used extra time the first time you used it. We'd like to make sure the Gentoo version ships with precompiled zo-files. – Undeceive

No, you misunderstood. For all three install versions of DrRacket, the behavior was identical. They all take over 10 seconds to return on (+ 1 1) in HTDP-beginner. They also all take about 3 seconds to return on it in just normal #lang racket in DrRacket. It's a bit better using just racket from the command-line, but still pretty bad. 5 seconds and (HTDP) and 2 seconds (lang racket). Check EDIT 3 in my answer details. – Homomorphism

Are you sure it isn't just that racket has really bad performance on my hardware? Like, you're sure these times aren't just normal for racket on equivalent hardware (no matter how racket is installed)? – Homomorphism

I mean, DrRacket takes up 611 megs of memory, just sitting there doing nothing after being freshly started. Is that normal? – Homomorphism

I think that's normal. @Owen_R Could I persuade you to submit a bug report through DrRacket and include a link to this SO question? In the help menu there is "Submit bug report" menu item. – Undeceive

As for "Are you sure it isn't just that racket has really bad performance on my hardware? " No, I am not sure. I thought the Gentoo package performed differently than the others. Now I am a bit puzzled. – Undeceive

I submitted the bug report through DrRacket like you said. bugs.racket-lang.org/query/?cmd=view&pr=15308 – Homomorphism

Thanks. I hope there is a solution. – Undeceive

But this DrRacket memory leak problem is (I think) separate from the slowness of the command-line. Like I said, 5 seconds to return on HTDP-beginner and 2 seconds on #lang racket. Do you know if that's normal performance on this kind of hardware? – Homomorphism

Not sure. Btw - there are couple of things you can do to make DrRacket faster. Most importantly: Open Preferences. In the "Background Expansion" tab disable "Enable background expansion" and disable "show blue boxes". – Undeceive

Also: In the tab "Tools" you can disable all tools apart from "Check Syntax", "How to Design Programs" and "The Stepper". – Undeceive