Пожалуйста, помогите мне разобраться в этих трассировках Clojure Hprof

У меня есть код Clojure, который моделирует, а затем обрабатывает числовые данные. Данные в основном представляют собой векторы с двойными значениями; обработка в основном включает суммирование их значений различными способами. Я включу некоторый код ниже, но мой вопрос (я думаю) более общий - я просто не знаю, как интерпретировать результаты hprof.

В любом случае, мой тестовый код:

(defn spin [n]
  (let [c 6000
        signals (spin-signals c)]
      (doseq [_ (range n)] (time (spin-voxels c signals)))))

(defn -main []
  (spin 4))

где спин-вокселы должны быть дороже, чем спин-сигналы (особенно при многократном повторении). Я могу дать подпрограммы более низкого уровня, но я думаю, что этот вопрос больше касается того, что я не понимаю основ трассировки (ниже).

Когда я компилирую это с помощью lein, а затем выполняю простое профилирование:

> java -cp classes:lib/clojure-1.3.0-beta1.jar -agentlib:hprof=cpu=samples,depth=10,file=hprof.vec com.isti.compset.stack
"Elapsed time: 14118.772924 msecs"
"Elapsed time: 10082.015672 msecs"
"Elapsed time: 9212.522973 msecs"
"Elapsed time: 12968.23877 msecs"
Dumping CPU usage by sampling running threads ... done.

и трассировка профиля выглядит так:

CPU SAMPLES BEGIN (total = 4300) Sun Aug 28 15:51:40 2011
rank   self  accum   count trace method
   1  5.33%  5.33%     229 300791 clojure.core$seq.invoke
   2  5.21% 10.53%     224 300786 clojure.core$seq.invoke
   3  5.05% 15.58%     217 300750 clojure.core$seq.invoke
   4  4.93% 20.51%     212 300787 clojure.lang.Numbers.add
   5  4.74% 25.26%     204 300799 clojure.core$seq.invoke
   6  2.60% 27.86%     112 300783 clojure.lang.RT.more
   7  2.51% 30.37%     108 300803 clojure.lang.Numbers.multiply
   8  2.42% 32.79%     104 300788 clojure.lang.RT.first
   9  2.37% 35.16%     102 300831 clojure.lang.RT.more
  10  2.37% 37.53%     102 300840 clojure.lang.Numbers.add

, что довольно круто. До сих пор я счастлив. Я вижу, что трачу время на общую обработку числовых значений.

Я смотрю свой код и решаю, что в качестве первого шага я заменю vec на d-vec :

(defn d-vec [collection]
  (apply conj (vector-of :double) collection))

Я не уверен, что этого будет достаточно - Я подозреваю, что мне также нужно будет добавить некоторые аннотации типов в разных местах - но это похоже на хорошее начало. Итак, я снова компилирую и профилирую:

> java -cp classes:lib/clojure-1.3.0-beta1.jar -agentlib:hprof=cpu=samples,depth=10,file=hprof.d-vec com.isti.compset.stack
"Elapsed time: 15944.278043 msecs"
"Elapsed time: 15608.099677 msecs"
"Elapsed time: 16561.659408 msecs"
"Elapsed time: 15416.414548 msecs"
Dumping CPU usage by sampling running threads ... done.

Ewww. Так что это значительно медленнее. А профиль?

CPU SAMPLES BEGIN (total = 6425) Sun Aug 28 15:55:12 2011
rank   self  accum   count trace method
   1 26.16% 26.16%    1681 300615 clojure.core.Vec.count
   2 23.28% 49.45%    1496 300607 clojure.core.Vec.count
   3  7.74% 57.18%     497 300608 clojure.lang.RT.seqFrom
   4  5.59% 62.77%     359 300662 clojure.core.Vec.count
   5  3.72% 66.49%     239 300604 clojure.lang.RT.first
   6  3.25% 69.74%     209 300639 clojure.core.Vec.count
   7  1.91% 71.66%     123 300635 clojure.core.Vec.count
   8  1.03% 72.68%      66 300663 clojure.core.Vec.count
   9  1.00% 73.68%      64 300644 clojure.lang.RT.more
  10  0.79% 74.47%      51 300666 clojure.lang.RT.first
  11  0.75% 75.22%      48 300352 clojure.lang.Numbers.double_array
  12  0.75% 75.97%      48 300638 clojure.lang.RT.more
  13  0.64% 76.61%      41 300621 clojure.core.Vec.count
  14  0.62% 77.23%      40 300631 clojure.core.Vec.cons
  15  0.61% 77.84%      39 300025 java.lang.ClassLoader.defineClass1
  16  0.59% 78.43%      38 300670 clojure.core.Vec.cons
  17  0.58% 79.00%      37 300681 clojure.core.Vec.cons
  18  0.54% 79.55%      35 300633 clojure.lang.Numbers.multiply
  19  0.48% 80.03%      31 300671 clojure.lang.RT.seqFrom
  20  0.47% 80.50%      30 300609 clojure.lang.Numbers.add

Я добавил сюда больше строк, потому что это та часть, которую я не понимаю.

Почему на Земле так часто появляется Vec.count ? Это метод, который возвращает размер вектора. Однострочный поиск атрибута.

Я предполагаю, что я работаю медленнее, потому что я все еще прыгаю между Double и Double, и что ситуация может снова улучшиться, когда я добавлю больше аннотаций типов. Но я не понимаю, что у меня есть сейчас, поэтому я не уверен, что промахи дальше имеют смысл.

Кто-нибудь может в общих чертах объяснить приведенный выше дамп? Я обещаю, что не буду постоянно вызывать count - вместо этого у меня есть много карт и сокращений и несколько явных циклов.

Я подумал, не сбивает ли меня с толку JIT? Может быть, мне не хватает кучи информации, потому что функции встраиваются? О, и я использую 1.3.0-beta1, потому что в нем более разумная обработка чисел.

[ ОБНОВЛЕНИЕ ] Я обобщил свой опыт на http://www.acooke.org/cute/Optimising1.html - получил 5-кратное ускорение (фактически было 10-кратное после очистки некоторых больше и переход на 1.3), хотя никогда этого не понимал.