Performance difference - why?

I'm testing with an OO framework, and try to understand the performance difference between two implementations of a caller construct. I've narrowed the problem down to two simple tests:

Test1 where I create some simple OO construct.

(define (test1)
  (define funcs (list))
  (define func-h (make-hasheq))

  (define problem (lambda args
                    (error "No such member")))

  (define count 0)
  (hash-set! func-h 'count (lambda () count))
  (hash-set! func-h 'count! (lambda (x) (set! count x) count))

  (define (g n)
    (begin
      (set! count (+ 1 count))
      (if (> n 0)
          (+ n ((hash-ref func-h 'g problem) (- n 1))
             ((hash-ref func-h 'g problem) (- n 2)))
          n)))
  (hash-set! func-h 'g g)

  (define (t n)
    (set! count 0)
    (let ((v ((hash-ref func-h 'g) n)))
      (values v count)))
  (hash-set! func-h 't t)
  
  (define (caller f . args)
    (apply (hash-ref func-h f problem) args))

  (cons 'cl caller))

> (define o1 (test1))
> (time ((cdr o1) 't 25))
cpu time: 0 real time: 77 gc time: 0
439176
392835

Test1b where I narrow the construct down to something even more basic:

(define (test1b)
  (define count 0)
  
  (define (caller-g . args)
    (apply g args))
  
  (define (g n)
    (begin
      (set! count (+ 1 count))
      (if (> n 0)
          (+ n (caller-g (- n 1))
             (caller-g (- n 2)))
          n)))

  (define (t n)
    (set! count 0)
    (let ((v (g n)))
      (values v count)))
  
  (define (caller-t . args)
    (apply t args))

  (cons 'cl caller-t))
> (define o1b (test1b))
> (time ((cdr o1b) 25))
cpu time: 1437 real time: 2211 gc time: 0
439176
392835
> 

I don't understand the difference in performance.

Can someone explain why this difference exists?
In the following test, I made the test even smaller:

(define (test1c)
  (define count 0)
  
  (define (g n)
    (begin
      (set! count (+ 1 count))
      (if (> n 0)
          (+ n (apply g (list (- n 1)))
             (apply g (list (- n 2))))
          n)))

  (define (t n)
    (set! count 0)
    (let ((v (g n)))
      (values v count)))
  
  (define (caller-t . args)
    (apply t args))

  (cons 'cl caller-t))
> (define o1c (test1c))
> (time ((cdr o1c) 25))
cpu time: 15 real time: 93 gc time: 15
439176
392835
> 

An even simpler calling test:

(define (test1d)
  (define count 0)

  (define (caller-g n)
    (g n))
  
  (define (g n)
    (begin
      (set! count (+ 1 count))
      (if (> n 0)
          (+ n (caller-g (- n 1))
             (caller-g (- n 2)))
          n)))

  (define (t n)
    (set! count 0)
    (let ((v (g n)))
      (values v count)))
  
  (define (caller-t . args)
    (apply t args))

  (cons 'cl caller-t))
> (define o1d (test1d))
> (time ((cdr o1d) 25))
cpu time: 1484 real time: 2270 gc time: 0
439176
392835
> 

And even further narrowing down:

> (define count 0)
> (define (caller-g n) (g n))
> (define (g n)
    (begin
      (set! count (+ 1 count))
      (if (> n 0)
          (+ n (caller-g (- n 1)) (caller-g (- n 2)))
          n)))
> (define (t n)
    (set! count 0)
    (let ((v (g n)))
      (values v count)))
> (time (t 25))
cpu time: 1296 real time: 2237 gc time: 0
439176
392835
> (define (g n)
    (begin
      (set! count (+ 1 count))
      (if (> n 0)
          (+ n (g (- n 1)) (g (- n 2)))
          n)))
> (time (t 25))
cpu time: 78 real time: 128 gc time: 31
439176
392835
> 

Why is calling some function to another function so much slower?
The OO framework of DrRacket seems to have the same performance:

(define test1e
  (class object%
    (define count 0)
    
    (define/public (caller-g n)
      (send this g n))
    
    (define/public (g n)
      (if (> n 0)
          (+ n (send this caller-g (- n 1))
             (send this caller-g (- n 2)))
          n))

    (define/public (t n)
      (set! count 0)
      (let ((v (send this g n)))
        (values v count)))

    (super-new)))
> (define o1e (new test1e))
> (time (send o1e t 25))
cpu time: 1531 real time: 2548 gc time: 78
439176
392835
> 

And if I implement it like this:

(define test1f
  (class object%
    (define count 0)
    
    (define/public (g n)
      (set! count (+ 1 count))
      (if (> n 0)
          (+ n (send this g (- n 1))
             (send this g (- n 2)))
          n))

    (define/public (t n)
      (set! count 0)
      (let ((v (send this g n)))
        (values v count)))

    (super-new)))
> (define o1f (new test1f))
> (time (send o1f t 25))
cpu time: 0 real time: 93 gc time: 0
439176
392835
> 

I can’t really reproduce your result. In my tests comparing test1c and test1d, they have comparable running time when the debugging mode is turned on. When the debugging mode is turned off, test1d is obviously faster.

What Racket version are you using? How do you run Racket (DrRacket, or command-line REPL?). Is it Racket BC or Racket CS? What OS? Etc.


I'm running on Windows 11.
It's DrRacket 8.17cs
#lang racket

Figured it out. It's due to profiling.
Thanks for the suggestion.

Rule #13: Don’t measure performance inside of drracket.

Run racket from the command line and measure it via script.
Make sure the machine isn’t performing any other work.