15.1% 0 + 1711 java.lang.reflect.Array.setInt Is definitely pointing at the aset-int as being the time gobbler, I think the expression in the macro should be this
(aset-int (ints arr#) i# (int (~mask-fn (. buf# (~get-fn))))) to be extra safe. On Tue, Mar 31, 2009 at 10:00 PM, Vincent Foley <vfo...@gmail.com> wrote: > > I tried it just now; it made no difference. Nevertheless, thank you > for you help and time! > > On Mar 31, 9:38 pm, David Nolen <dnolen.li...@gmail.com> wrote: > > Did you try > > (int (mask8 (. buf__2572__auto__ (get)))) > > > > ? > > > > Your macro should like this: > > > > (defmacro make-reader > > [get-fn mask-fn] > > `(fn [#^ByteBuffer buf# len#] > > (if (= len# 1) > > (~mask-fn (. buf# (~get-fn))) > > (let [#^"[I" arr# (int-array len#)] > > (dotimes [i# len#] > > (aset-int arr# i# (int (~mask-fn (. buf# (~get-fn)))))) > > arr#)))) > > > > On Tue, Mar 31, 2009 at 9:09 PM, Vincent Foley <vfo...@gmail.com> wrote: > > > > > I tried surrounding the call to the (. buf# (get)) method and putting > > > the coercion directly inside the mask8 and mask16 functions. Neither > > > worked. I want to mention at this point that I have *warn-on- > > > reflection* set to true for the little script that uses the library > > > and it doesn't report any call to methods that it can't resolve. > > > > > Here's the complete -Xprof output, if it helps. > > > > > Flat profile of 176.10 secs (11351 total ticks): main > > > > > Interpreted + native Method > > > 4.5% 511 + 0 java.lang.Integer.hashCode > > > 1.4% 160 + 0 java.lang.Integer.intValue > > > 0.8% 91 + 0 starcraft.replay.unpack > > > $decode_command_block__94.invoke > > > 0.7% 80 + 0 clojure.lang.Numbers.int_array > > > 0.2% 25 + 0 clojure.lang.PersistentVector.pushTail > > > 0.1% 15 + 2 java.lang.ClassLoader.defineClass1 > > > 0.1% 16 + 0 > > > hu.belicza.andras.bwhf.control.BinReplayUnpacker.esi28 > > > 0.1% 4 + 11 clojure.core__init.load > > > 0.1% 10 + 0 clojure.lang.PersistentVector.cons > > > 0.1% 8 + 0 starcraft.replay.actions$fn__71.invoke > > > 0.1% 8 + 0 > > > hu.belicza.andras.bwhf.control.BinReplayUnpacker.unpackSection > > > 0.1% 0 + 7 java.lang.reflect.Array.setInt > > > 0.1% 7 + 0 clojure.lang.PersistentHashMap > > > $BitmapIndexedNode.create > > > 0.1% 7 + 0 clojure.lang.RestFn.invoke > > > 0.1% 7 + 0 clojure.lang.RestFn.invoke > > > 0.1% 7 + 0 starcraft.replay.unpack > > > $decode_commands__99.invoke > > > 0.1% 7 + 0 starcraft.replay.parse > > > $parse_buffer__53$fn__56.invoke > > > 0.1% 6 + 0 clojure.lang.AFn.applyToHelper > > > 0.1% 6 + 0 clojure.lang.PersistentArrayMap.assoc > > > 0.1% 6 + 0 clojure.lang.PersistentHashMap > > > $BitmapIndexedNode.assoc > > > 0.0% 0 + 5 java.lang.reflect.Array.newArray > > > 0.0% 0 + 5 java.lang.Class.forName0 > > > 0.0% 0 + 5 java.util.zip.Inflater.inflateBytes > > > 0.0% 5 + 0 java.lang.AbstractStringBuilder.<init> > > > 0.0% 5 + 0 java.util.Arrays.copyOfRange > > > 10.9% 1157 + 76 Total interpreted (including elided) > > > > > Compiled + native Method > > > 10.4% 1183 + 1 starcraft.replay.parse$fn__23$fn__49.invoke > > > 10.0% 1123 + 17 starcraft.replay.unpack > > > $decode_command_block__94.invoke > > > 9.2% 1043 + 0 clojure.core$next__3096.invoke > > > 8.9% 1014 + 0 starcraft.replay.parse > > > $parse_buffer__53$fn__56.invoke > > > 5.5% 626 + 0 clojure.lang.PersistentArrayMap.assoc > > > 4.3% 474 + 17 clojure.lang.PersistentArrayMap.assoc > > > 4.1% 464 + 7 clojure.lang.RestFn.invoke > > > 2.9% 333 + 0 clojure.lang.Cons.next > > > 2.5% 288 + 0 clojure.lang.RT.seq > > > 2.4% 269 + 0 clojure.lang.AFn.applyToHelper > > > 2.2% 249 + 0 > > > hu.belicza.andras.bwhf.control.BinReplayUnpacker.unpackRepChunk > > > 1.8% 202 + 0 clojure.core$seq__3112.invoke > > > 1.6% 174 + 3 clojure.lang.RestFn.applyTo > > > 1.3% 140 + 2 clojure.lang.APersistentMap.cons > > > 1.2% 130 + 1 clojure.core$spread__3225.invoke > > > 1.1% 127 + 0 clojure.lang.PersistentStructMap.valAt > > > 0.8% 93 + 0 clojure.core$reduce__3304.invoke > > > 0.6% 66 + 2 starcraft.replay.unpack > > > $decode_commands__99.invoke > > > 0.6% 63 + 0 clojure.lang.PersistentArrayMap.valAt > > > 0.1% 13 + 1 clojure.core$conj__3100.invoke > > > 0.1% 9 + 0 clojure.lang.APersistentMap.invoke > > > 0.1% 3 + 6 starcraft.replay.parse > > > $fn__23$read_shorts__37.invoke > > > 0.1% 8 + 0 clojure.core$nthnext__4405.invoke > > > 0.1% 0 + 7 clojure.lang.ArraySeq.next > > > 0.0% 0 + 5 clojure.lang.APersistentVector.assoc > > > 72.3% 8126 + 76 Total compiled (including elided) > > > > > Stub + native Method > > > 15.1% 0 + 1711 java.lang.reflect.Array.setInt > > > 1.2% 0 + 135 java.lang.System.arraycopy > > > 0.3% 0 + 31 java.lang.reflect.Array.set > > > 0.1% 0 + 15 java.io.FileInputStream.readBytes > > > 0.1% 0 + 13 java.lang.reflect.Array.get > > > 0.1% 0 + 7 java.lang.Object.getClass > > > 0.0% 0 + 1 java.lang.Thread.currentThread > > > 16.9% 0 + 1913 Total stub > > > > > Thread-local ticks: > > > 0.0% 1 Class loader > > > 0.0% 2 Unknown: no last frame > > > > > Flat profile of 0.01 secs (1 total ticks): DestroyJavaVM > > > > > Thread-local ticks: > > > 100.0% 1 Blocked (of total) > > > > > Global summary of 176.12 seconds: > > > 100.0% 11603 Received ticks > > > 2.1% 246 Received GC ticks > > > 4.3% 495 Compilation > > > 0.0% 2 Other VM operations > > > 0.0% 1 Class loader > > > 0.0% 2 Unknown code > > > 176.257 secs > > > > > On Mar 31, 8:57 pm, David Nolen <dnolen.li...@gmail.com> wrote: > > > > Thanks to cl-format: > > > > > > (fn > > > > [buf__2572__auto__ len__2573__auto__] > > > > (if (= len__2573__auto__ 1) > > > > (mask8 (. buf__2572__auto__ (get))) > > > > (let [arr__2574__auto__ (int-array len__2573__auto__)] > > > > (dotimes > > > > [i__2575__auto__ len__2573__auto__] > > > > (aset-int > > > > arr__2574__auto__ > > > > i__2575__auto__ > > > > (mask8 (. buf__2572__auto__ (get))))) > > > > arr__2574__auto__))) > > > > > > This is the expansion for (make-reader get mask8), where were you > > > attempting > > > > putting the int coercion to to the mask-fn? > > > > > > David > > > > > > On Tue, Mar 31, 2009 at 11:38 AM, Vincent Foley <vfo...@gmail.com> > > > wrote: > > > > > > > I tried using aset-int and I tried using int to coerce the result > of > > > > > mask-fn, the input argument to mask-fn and few other things, but > none > > > > > of that seems to make a difference so far. Mind you, this is an > > > > > aspect of Clojure that I find a little confusing, so I'm just > putting > > > > > int calls here and there and looking at what happens. > > > > > > > On Mar 31, 10:46 am, Christophe Grand <christo...@cgrand.net> > wrote: > > > > > > Did you try to coerce the result of (~mask-fn ...) with int? > > > > > > (or use aset-int as suggested by David) > > > > > > > > On Tue, Mar 31, 2009 at 4:17 PM, Vincent Foley <vfo...@gmail.com > > > > > wrote: > > > > > > > > > No, but in my defense I did not know such a function existed :) > > > I'll > > > > > > > give it a whirl and report back! > > > > > > > > > On Mar 31, 9:57 am, David Nolen <dnolen.li...@gmail.com> > wrote: > > > > > > > > Did you try using aset-int instead of aset? > > > > > > > > > > On Tue, Mar 31, 2009 at 8:25 AM, Vincent Foley < > vfo...@gmail.com > > > > > > > wrote: > > > > > > > > > > > For those interested, I managed to improve the performance > of > > > my > > > > > > > > > original program from 2 minutes 40 seconds to decode 1000+ > > > files > > > > > down > > > > > > > > > to 2 minutes. I'm still far from my goal, but it's an > > > improvement, > > > > > > > > > especially since the code is shorter and (IMO) cleaner. > You > > > can > > > > > see > > > > > > > > > it here: > > > > > > > > http://bitbucket.org/gnuvince/clj-starcraft/src/tip/src/starcraft/rep. > > > > > > > .. > > > > > > > > > > > And here's another question, running the program with > -Xprof > > > shows > > > > > > > > > that nearly 20% of my execution time is spent calling > > > > > > > > > java.lang.reflect.Array.set. Is there something wrong with > the > > > way > > > > > I > > > > > > > > > type hint my array in make-reader? > > > > > > > > > > > Thanks, > > > > > > > > > > > Vincent. > > > > > > > > > > > On Mar 19, 8:12 pm, Vincent Foley <vfo...@gmail.com> > wrote: > > > > > > > > > > Hello, > > > > > > > > > > > > For the past few days, I've been trying, unsuccessfully, > to > > > make > > > > > an > > > > > > > > > > application I wrote faster. A Java program that > performs, > > > more > > > > > or > > > > > > > > > > less, the same task takes 12 seconds (on my machine) to > parse > > > > > 1000 > > > > > > > > > > files; my Clojure program takes nearly 3 minutes. This > more > > > than > > > > > an > > > > > > > > > > order of magnitude slower! Using the profiling tools > > > available > > > > > with > > > > > > > > > > the JVM, I quickly determined which function was the > > > costliest. > > > > > I > > > > > > > > > > copied it into a simple script file to profile it in > > > isolation. > > > > > I > > > > > > > > > > have made the script and the profile results (long!) > > > available at > > > > > > > this > > > > > > > > > > URL:http://gist.github.com/82136 > > > > > > > > > > > > I'm finding the results puzzling: is dereferencing a var > > > *that* > > > > > > > > > > expensive? Can anyone tell me if they see something > > > > > fundamentally > > > > > > > > > > wrong with my approach that would explain this abysmal > > > > > performance? > > > > > > > > > > > > Thank you, > > > > > > > > > > > > Vincent. > > > > > > > > > > > > P.S.: I am using Sun's JVM 1.6.0_10 as shipped in Ubuntu > > > Ibex. > > > > > My > > > > > > > > > > machine is an Athlon 64 X2 4200+ with 3 GB of RAM. > > > > > > > --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Clojure" group. To post to this group, send email to clojure@googlegroups.com To unsubscribe from this group, send email to clojure+unsubscr...@googlegroups.com For more options, visit this group at http://groups.google.com/group/clojure?hl=en -~----------~----~----~----~------~----~------~--~---
