Problem with asynchronously calls

output.log

[2013-03-08 07:50:50.805:nREPL-worker-49] INFO  slam - crush called with 4 tasks...
[2013-03-08 07:50:50.808:pool-27-thread-2] INFO  slam - Starting task 1
[2013-03-08 07:50:50.808:pool-27-thread-1] INFO  slam - Starting task 0
[2013-03-08 07:50:50.808:pool-27-thread-4] INFO  slam - Starting task 3
[2013-03-08 07:50:50.808:nREPL-worker-49] INFO  slam - Finished crush in 2ms.
[2013-03-08 07:50:50.808:pool-27-thread-3] INFO  slam - Starting task 2
[2013-03-08 07:50:55.809:pool-27-thread-4] INFO  slam - Task 3 is all done
[2013-03-08 07:50:55.809:pool-27-thread-3] INFO  slam - Task 2 is all done
[2013-03-08 07:50:55.809:pool-27-thread-1] INFO  slam - Task 0 is all done
[2013-03-08 07:50:55.809:pool-27-thread-2] INFO  slam - Task 1 is all done
[2013-03-08 07:50:55.809:pool-27-thread-1] INFO  slam - Finished task in 5002ms.
[2013-03-08 07:50:55.809:pool-27-thread-3] INFO  slam - Finished task in 5002ms.
[2013-03-08 07:50:55.809:pool-27-thread-4] INFO  slam - Finished task in 5001ms.
[2013-03-08 07:50:55.809:pool-27-thread-2] INFO  slam - Finished task in 5002ms.
[2013-03-08 07:50:55.810:nREPL-worker-49] INFO  slam - Finished unbound in 5005ms.

[2013-03-08 07:51:32.310:nREPL-worker-50] INFO  slam - crush called with 4 tasks...
[2013-03-08 07:51:32.313:nREPL-worker-50] INFO  slam - Finished crush in 3ms.
[2013-03-08 07:51:32.313:pool-29-thread-1] INFO  slam - Starting task 0
[2013-03-08 07:51:32.313:pool-29-thread-2] INFO  slam - Starting task 1
[2013-03-08 07:51:37.313:pool-29-thread-1] INFO  slam - Task 0 is all done
[2013-03-08 07:51:37.313:pool-29-thread-2] INFO  slam - Task 1 is all done
[2013-03-08 07:51:37.314:pool-29-thread-1] INFO  slam - Finished task in 5002ms.
[2013-03-08 07:51:37.314:pool-29-thread-2] INFO  slam - Finished task in 5002ms.
[2013-03-08 07:51:37.314:pool-29-thread-2] INFO  slam - Starting task 2
[2013-03-08 07:51:37.314:pool-29-thread-1] INFO  slam - Starting task 3
[2013-03-08 07:51:42.316:pool-29-thread-1] INFO  slam - Task 3 is all done
[2013-03-08 07:51:42.316:pool-29-thread-2] INFO  slam - Task 2 is all done
[2013-03-08 07:51:42.316:pool-29-thread-1] INFO  slam - Finished task in 5002ms.
[2013-03-08 07:51:42.316:pool-29-thread-2] INFO  slam - Finished task in 5002ms.
[2013-03-08 07:51:42.317:nREPL-worker-50] INFO  slam - Finished bound in 10008ms.

REPL.txt

dark-magic.main=> (require 'slam :reload-all)
nil
dark-magic.main=> (slam/unbound 4)
nil
dark-magic.main=> (slam/bound 4)
nil

slam.clj

(ns slam
  (:require [dark-magic.async :refer [asynchronously with-fixed-thread-pool wait]]
            [dark-magic.logging :refer [log-execution-time!]]
            [clojure.tools.logging :refer [info infof errorf]]))

(defn task
  [i]
  (infof "Starting task %d" i)
  (. Thread (sleep 5000))
  (infof "Task %d is all done" i))

(log-execution-time! task)

(defn crush
  [n]
  (infof "crush called with %d tasks..." n)
  (doseq [i (range n)] (asynchronously (task i))))

(log-execution-time! crush)

(defn unbound
  [n]
  (crush n)
  (wait)
  (.shutdown dark-magic.async/*pool*))

(log-execution-time! unbound)

(defn bound
  [n]
  (with-fixed-thread-pool 2
    (crush n)
    (wait))
  (.shutdown dark-magic.async/*pool*))

(log-execution-time! bound)