[racket-dev] Understanding the performance of raco make

I'm trying to improve the compilation speed of some modules, and to do that
I need to understand how raco make is spending its time.

I decided to call parallel-compile-files myself with a handler that gets
the time of start and done messages, and then turn those into a timeline
plot.

I have a attached a screen shot of what that produces.​
 Screen Shot 2014-10-28 at 8.07.42 AM.png
<https://docs.google.com/file/d/0By8GtCCnLFX9WGgyWTRpbXdMQUU/edit?usp=drive_web>
​
The problem I have found is that when one builder is building a module I
don't get insight into what it is doing while compiling that modules
dependencies that were not prefetched by a different builder. This causes
two problems. The first is that compilation time for some modules looks
very long, even though most of it is in compiling their dependencies. The
second is that I cannot tell what is going on when only the original
threads are doing processing, and so it isn't obvious why other threads
start up again.

Is there a better way to instrument raco make?

Hacky code:

Instrumented compile:
#lang racket/base

(require setup/parallel-build racket/match)
(define times (make-hash))
(parallel-compile-files (list

"/Users/endobson/proj/racket/plt/pkgs/typed-racket-pkgs/typed-racket-lib/typed-racket/core.rkt")
  #:handler
    (λ (id type path-string msg out err)
      (define time (current-inexact-milliseconds))
      (define ps (if (path? path-string) (path->string path-string)
path-string))
      (cond
        [(equal? type 'start)
         (hash-set! times (list ps id) time)]
        [(equal? type 'done)
         (hash-set! times (list ps id) (list (hash-ref times (list ps id))
time))])))
(for ([(name time) times])
  (match-define (list start stop) time)
  (match-define (list file id) name)
  (write (list id file start stop))
  (newline))



Plotter:
#lang racket/base

(require plot racket/match racket/list)
(plot-new-window? #t)

(define work-units
  (call-with-input-file* "data.rktd"
    (lambda (port)
      (let loop ([items empty])
        (define item (read port))
        (if (eof-object? item)
            items
            (loop (cons item items)))))))

(define converted-work-units
  (for/list ([work-unit (in-list work-units)])
    (match-define (list index file-name start stop) work-unit)
    (list
      (rectangles
        #:alpha 0
        (list (list (ivl start stop) (ivl (- index 1/3) (+ index 1/3)))))
      #;
      (point-label
        (list (/ (+ start stop) 2) index)
        file-name
        #:anchor 'center
        #:point-size 0))))


(plot
  #:width 1500
  converted-work-units)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.racket-lang.org/dev/archive/attachments/20141028/98b33393/attachment.html>