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>'.
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
_______________________________________________
Devl mailing list
Devl@freenetproject.org
https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
