On 24-03-2012 09:26, Marco Schulze wrote: > I finally got freenet.jar compiled and profiled. First, size-related > numbers: > > Number of lines removed: ~5000 > freenet.jar shrink: ~200k > > And profiling data (see below for details): > > freenet.support.FileLoggerHook$WriterThread.run: 8,35% (3) Oops. Most of the method's time is 'spent' inside Object.wait(). As far as I can gather with my limited Java profiling experience, this figure is actually between 2% and 3%. I've attached the output of another, 3 minute run (HPROF w/ cpu=times).
> > freenet.support.Log.isLoggable: 0.09% (17) > freenet.support.Log.write: 0,03% (26) > > These numbers come from a sanity check run, and _do not_ represent > what would happen in a real test run. Both were run in an empty > directory for a few minutes and then shut down. Of special note is the > lack of the seed nodes list, leaving out, I'd guess, 80% of fred code. > Also, lazy evaluation isn't used, so Log.write()'s share can be > expected to rise. > > There are still a few things to do before I can say whether predicates > are indispensable or not. > > On 18-03-2012 20:40, Marco Schulze wrote: >> One thing has been bothering me: those 'if (logMINOR) >> Logger.minor(...', and the mess that logging is inside fred. I've >> written a very simple replacement for Logger + associated classes >> with the following changes: >> >> - Log level (renamed to severity) filtering is done by Logging.log(); >> - Specific writer classes are replaced by a simple OutputStream, >> which defaults to System.err. Formatting is also unified; >> - Severity cases are broadened (FATAL, ERROR, WARNING, INFO, DEBUG >> and TRACE), MINOR is mapped to DEBUG, and NORMAL is mapped to INFO; >> - No logging method accepts an Object parameter - hashCode() is not >> exactly useful. >> >> Additionally, log rotation will be moved outside (possibly inside Node). >> >> Currently, the log format is '<severity>\t<message>'. -------------- next part -------------- CPU TIME (ms) BEGIN (total = 1676345) Sun Mar 25 13:54:57 2012 rank self accum count trace method 1 10,74% 10,74% 3 306148 freenet.support.PooledExecutor$MyThread.realRun 2 10,72% 21,46% 1 306331 freenet.support.FileLoggerHook$WriterThread.run 3 10,56% 32,02% 354 303612 freenet.io.NetworkInterface.accept 4 10,03% 42,05% 1680 305239 freenet.node.PacketSender.realRun 5 10,00% 52,05% 4346 305240 freenet.support.PrioritizedTicker.realRun 6 9,94% 61,99% 1 306286 java.net.AbstractPlainDatagramSocketImpl.receive 7 9,63% 71,62% 90 305699 freenet.client.async.DatastoreChecker.realRun 8 9,54% 81,16% 16 306056 freenet.node.DNSRequester.realRun 9 7,72% 88,88% 3 303235 java.lang.Object.wait 10 7,72% 96,60% 2330 303243 java.lang.ref.ReferenceQueue.remove 11 0,84% 97,43% 1 305391 org.tanukisoftware.wrapper.WrapperManager$4.run 12 0,31% 97,74% 36 304762 freenet.client.async.USKManager.subscribe 13 0,25% 97,99% 19 304873 freenet.client.async.USKFetcher.schedule 14 0,18% 98,17% 1846080 303770 sun.security.provider.SHA2.lf_S 15 0,17% 98,34% 3205 303778 sun.security.provider.SHA2.implCompress 16 0,14% 98,48% 9 306294 java.lang.Thread.join 17 0,11% 98,58% 205120 303774 sun.security.provider.SHA2.lf_sigma1 18 0,10% 98,69% 205120 303776 sun.security.provider.SHA2.lf_sigma0 19 0,09% 98,77% 153840 303773 sun.security.provider.SHA2.lf_delta0 20 0,08% 98,85% 153840 303772 sun.security.provider.SHA2.lf_delta1 21 0,06% 98,91% 1 306334 org.tanukisoftware.wrapper.WrapperManager.stopCommon 22 0,03% 98,94% 1 306332 freenet.support.FileLoggerHook$CloserThread.run 23 0,03% 98,97% 1 306345 org.tanukisoftware.wrapper.WrapperManager.dispose 24 0,03% 99,00% 307680 303771 sun.security.provider.SHA2.lf_R 25 0,02% 99,02% 42831 300120 java.lang.AbstractStringBuilder.append 26 0,02% 99,04% 205120 303775 sun.security.provider.SHA2.lf_ch 27 0,02% 99,07% 205120 303777 sun.security.provider.SHA2.lf_maj 28 0,02% 99,09% 40 303514 freenet.crypt.DiffieHellman.checkDHExponentialValidity 29 0,02% 99,10% 40919 303500 java.math.BigInteger.testBit 30 0,02% 99,12% 1131 300767 java.lang.ClassLoader.defineClass 31 0,01% 99,13% 1 306343 org.tanukisoftware.wrapper.WrapperManager.signalStopped 32 0,01% 99,15% 11837 305291 freenet.client.async.ClientRequestSelector.removeFirstAccordingToPriorities 33 0,01% 99,16% 18303 300177 java.util.HashMap.get 34 0,01% 99,17% 45574 303826 java.lang.Long.compareTo 35 0,01% 99,18% 45574 303825 java.lang.Long.compareTo 36 0,01% 99,18% 16762 300475 java.util.HashMap.put 37 0,01% 99,19% 38768 300121 java.lang.StringBuilder.append 38 0,01% 99,20% 41182 303263 java.math.BigInteger.bitLength 39 0,01% 99,21% 3268 302615 sun.security.provider.ByteArrayAccess.b2iBig64 40 0,01% 99,22% 82459 303844 java.lang.Math.abs 41 0,01% 99,23% 78754 300087 java.lang.String.length 42 0,01% 99,24% 53433 300119 java.lang.AbstractStringBuilder.ensureCapacityInternal 43 0,01% 99,24% 10698 301392 freenet.support.SimpleFieldSet.put 44 0,01% 99,25% 42852 303264 java.math.BigInteger.getInt 45 0,01% 99,26% 33907 300089 java.lang.String.indexOf 46 0,01% 99,27% 28767 300195 java.lang.String.substring 47 0,01% 99,27% 65463 300006 java.lang.String.getChars 48 0,01% 99,28% 26771 300130 java.lang.String.<init> 49 0,01% 99,28% 66653 302613 java.lang.Integer.reverseBytes 50 0,01% 99,29% 1 303627 freenet.node.Node$2.run 51 0,01% 99,30% 22473 300128 java.lang.AbstractStringBuilder.expandCapacity 52 0,01% 99,30% 49579 300091 java.lang.String.charAt 53 0,01% 99,31% 20644 303478 freenet.crypt.Yarrow.next 54 0,01% 99,31% 3792 300440 java.util.zip.Inflater.inflate 55 0,01% 99,32% 4556 300378 java.util.zip.ZipCoder.getBytes CPU TIME (ms) END
