PATCH2/2: post processing and reporting

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

PATCH2/2: post processing and reporting

Derek Zhou
This is a couple smalltalk classes to post process the profile and print a report. It is old syntax smalltalk though.

Object subclass: #MethodProfile
    instanceVariableNames: 'selfCost totalCost callTimes callees table'
    classVariableNames: ''
    poolDictionaries: ''
    category: 'Profiling'!

MethodProfile comment:
    'I store some statistic info about a method, including cast and
call graph'!

!MethodProfile class methodsFor: 'instance creation'!

newFrom: p in: t
    ^self new initWith: p in: t!
!

!MethodProfile methodsFor: 'basic'!

initWith: p in: t
    "initial self from raw profile p, which is a MethodDictionary"
    selfCost := p at: true.
    table := t.
    "to be figured out later"
    callTimes := 0.
    callees := IdentityDictionary new.
    p keysAndValuesDo: [ :k :v |
        "ignore blocks for now"
        (k ~~ true) &
            (CallGraph seperateBlocks or: [ k isKindOf: CompiledMethod ])
            ifTrue: [ callees at: k put: v ]]!

mergeWith: p
    "merge with raw profile p, which is a MethodDictionary"
    selfCost := selfCost + (p at: true).
    p keysAndValuesDo: [ :k :v |
        "ignore blocks for now"
        (k ~~ true) &
            (CallGraph seperateBlocks or: [ k isKindOf: CompiledMethod ])
            ifTrue: [
                (callees includesKey: k)
                    ifTrue: [ callees at: k put: v + (callees at: k) ]
                    ifFalse: [ callees at: k put: v ]]]!
!

!MethodProfile methodsFor: 'printing'!

printCallGraphOn: aStream
    aStream nextPutAll: '0 %1' % {selfCost}; nl.
    callees keysAndValuesDo: [ :callee :n |
        aStream
            nextPutAll: 'cfl=%1' % {callee methodClass}; nl;
            nextPutAll: 'cfn=%1' % {callee}; nl;
            nextPutAll: 'calls=%1' % {n}; nl;
            nextPutAll: '* %1' % {self costOf: callee}; nl ]!
!

!MethodProfile methodsFor: 'accessing'!

selfCost
    ^selfCost!

totalCost
    totalCost notNil ifTrue: [ ^totalCost ].
    "TODO: better handle loops"
    totalCost := selfCost.
    callees keysAndValuesDo: [ :callee :n |
        totalCost := (self costOf: callee) + totalCost ].
    ^totalCost!

costOf: callee
    |calleeProfile|
    calleeProfile := table at: callee ifAbsent: [nil].
    calleeProfile isNil
        ifTrue: [
            Transcript show: '%1 has no profile' % {callee}; nl.
            ^0 ]
        ifFalse: [
            ^(calleeProfile totalCost * (callees at: callee) /
                  calleeProfile callTimes) ceiling ]!

callTimes
    ^callTimes!

callTimes: n
    callTimes := n!

callees
    ^callees!
!

Object subclass: #CallGraph
    instanceVariableNames: 'methodProfiles'
    classVariableNames: 'seperateBlocks'
    poolDictionaries: ''
    category: ''!

CallGraph comment:
    'I store a call tree and associated profiling info'!

!CallGraph class methodsFor: 'instance creation'!

seperateBlocks
    "return whether to seperate blocks in the report"
    ^seperateBlocks!

seperateBlocks: bool
    "set whether to seperate blocks in the report, default is false"
    seperateBlocks := bool!

new
    "capture the current raw profile. Infers Smalltalk profilerOff"
    Smalltalk profilerOff.
    ^super new
        initFrom: (Smalltalk rawProfile);
        computeCallTimes;
        computeCost;
        yourself!
!

CallGraph seperateBlocks: false!

!CallGraph methodsFor: 'basic'!

initFrom: p
    methodProfiles := IdentityDictionary new: 256.
    p keysAndValuesDo: [ :k :v |
        |method|
        "merge the costs of block to the mother method. If we treat block calls
         as full blown method calls then a method like
         SequenceableCollection>>do:, with do nothing but invoking blocks,
         will see highly varied execution paths and may cause many false
         recursions, both of which will produce highly skewed cost
         allocation."
        method := (seperateBlocks or: [ k isKindOf: CompiledMethod ])
            ifTrue: [ k ]
            ifFalse: [ k method ].
        (methodProfiles includesKey: method)
            ifTrue: [ (methodProfiles at: method) mergeWith: v ]
            ifFalse: [ methodProfiles at: method put:
                           (MethodProfile newFrom: v in: methodProfiles)]]!

computeCallTimes
    methodProfiles do: [ :profile |
        profile callees keysAndValuesDo: [ :callee :n |
            |calleeProfile|
            calleeProfile := methodProfiles at: callee ifAbsent: [nil].
            calleeProfile isNil
                ifTrue: [
                    Transcript show: '%1 has no profile' % {callee}; nl ]
                ifFalse: [
                    calleeProfile callTimes:
                              (calleeProfile callTimes + n) ]]]!

computeCost
    methodProfiles do: [ :profile |
        profile totalCost ]!

totalCost
    ^methodProfiles inject: 0 into: [ :sum :profile |
        sum + profile selfCost ]!

methodCount
    ^methodProfiles size!
!

!CallGraph methodsFor: 'printing'!

printCallGraphOn: aStream
"print a callgrind compatible profile report on aStream"
    self printHeaderOn: aStream.
    methodProfiles keysAndValuesDo: [ :method :profile |
    aStream
        nextPutAll: 'fl=%1' % {method methodClass}; nl;
        nextPutAll: 'fn=%1' % {method}; nl.
        profile printCallGraphOn: aStream.
        aStream nl ]!

printCallGraphToFile: fn
"print a callgrind compatible profile report to a file named fn"
    |fs|
    fs := (File name: fn) writeStream.
    [ self printCallGraphOn: fs ] ensure: [ fs close ]!

printHeaderOn: aStream
    aStream
        nextPutAll: 'version: 1'; nl;
        nextPutAll: 'creator: gst profile'; nl;
        nextPutAll: 'positions: instr'; nl;
        nextPutAll: 'events: Ir'; nl;
        nextPutAll: 'summary: %1' % {self totalCost}; nl; nl!
!



_______________________________________________
help-smalltalk mailing list
[hidden email]
http://lists.gnu.org/mailman/listinfo/help-smalltalk
Reply | Threaded
Open this post in threaded view
|

Re: PATCH2/2: post processing and reporting

Paolo Bonzini-2
Just a note that I have not forgotten about this.  I created a profile
branch in my repository with code mostly based on yours.

Can you explain this formula?

            ^(calleeProfile totalCost * (callees at: callee) /
                  calleeProfile callTimes) ceiling

Is it just because you don't have fully context-sensitive profiling?

Paolo


_______________________________________________
help-smalltalk mailing list
[hidden email]
http://lists.gnu.org/mailman/listinfo/help-smalltalk
Reply | Threaded
Open this post in threaded view
|

Re: PATCH2/2: post processing and reporting

Paolo Bonzini-2
Paolo Bonzini wrote:
> Just a note that I have not forgotten about this.  I created a profile
> branch in my repository with code mostly based on yours.
>
> Can you explain this formula?
>
>             ^(calleeProfile totalCost * (callees at: callee) /
>                   calleeProfile callTimes) ceiling
>
> Is it just because you don't have fully context-sensitive profiling?

Here it is in the meanwhile.  The first patch is for the VM, the second
adds the tool as in Derek's series.

I settled for a single primitive, and I removed the global too.
push/pop functionality is placed in a Profiler abstract class from which
I derived CallGraphProfiler and MethodCallGraphProfiler.  The two
classes should have the same purpose as the separateBlocks flag.

TODO (patches/testing are welcome):
- comment and categorize methods

- check that the format is really the same as callgrind's, especially I
don't know if cumulative counts should be added to the caller as well?

- make a driver and connect gst-tool to it (i.e. install it)

- find a way to remove the conditional from SET_THIS_METHOD???

Paolo

commit 609c3876ea34a200af8b45c913054c63e8e019d9
Author: Paolo Bonzini <[hidden email]>
Date:   Fri Feb 20 10:36:48 2009 +0100

    add profiling primitives
   
    2009-02-19  Derek Zhou  <[hidden email]>
                Paolo Bonzini  <[hidden email]>
   
    * kernel/SysDict.st: Add profiling primitive.
   
    libgst:
    2009-02-19  Derek Zhou  <[hidden email]>
                Paolo Bonzini  <[hidden email]>
   
    * libgst/dict.c: Add profiling callback.
    * libgst/dict.h: Add profiling callback.
    * libgst/interp-bc.inl: Call it.
    * libgst/interp.c: Declare variables.
    * libgst/interp.h: Declare variables.
    * libgst/prims.def: Add profiling primitive.

diff --git a/ChangeLog b/ChangeLog
index ec8cff9..c1e2ffc 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,8 @@
+2009-02-19  Derek Zhou  <[hidden email]>
+            Paolo Bonzini  <[hidden email]>
+
+ * kernel/SysDict.st: Add profiling primitive.
+
 2009-02-02  Paolo Bonzini  <[hidden email]>
 
  * kernel/HashedColl.st: Inline and eliminate #findIndex:ifAbsent:.
diff --git a/kernel/SysDict.st b/kernel/SysDict.st
index 03b451c..5a1a71d 100644
--- a/kernel/SysDict.st
+++ b/kernel/SysDict.st
@@ -242,5 +242,13 @@ My instance also helps keep track of dependencies between objects.'>
  <category: 'testing'>
  ^true
     ]
+
+    rawProfile: anIdentityDictionary [
+ "Set the raw profile to be anIdentityDictionary and return the
+         old one."
+
+ <category: 'profiling'>
+ <primitive: VMpr_SystemDictionary_rawProfile>
+    ]
 ]
 
diff --git a/libgst/ChangeLog b/libgst/ChangeLog
index 05dfa72..61484bf 100644
--- a/libgst/ChangeLog
+++ b/libgst/ChangeLog
@@ -1,3 +1,13 @@
+2009-02-19  Derek Zhou  <[hidden email]>
+            Paolo Bonzini  <[hidden email]>
+
+ * libgst/dict.c: Add profiling callback.
+ * libgst/dict.h: Add profiling callback.
+ * libgst/interp-bc.inl: Call it.
+ * libgst/interp.c: Declare variables.
+ * libgst/interp.h: Declare variables.
+ * libgst/prims.def: Add profiling primitive.
+
 2009-02-19  Paolo Bonzini  <[hidden email]>
 
  * libgst/dict.c: Fix off-by-one in _gst_identity_dictionary_at_put.
diff --git a/libgst/dict.c b/libgst/dict.c
index 6f33560..d2b04a0 100644
--- a/libgst/dict.c
+++ b/libgst/dict.c
@@ -201,6 +201,12 @@ static ssize_t identity_dictionary_find_key (OOP identityDictionaryOOP,
 static size_t identity_dictionary_find_key_or_nil (OOP identityDictionaryOOP,
    OOP keyOOP);
 
+/* assume the value is an integer already or key does not exist, increase the
+   value by inc or set the value to inc */
+static int _gst_identity_dictionary_at_inc (OOP identityDictionaryOOP,
+                                            OOP keyOOP,
+                                            int inc);
+
 /* Create a new instance of CLASSOOP (an IdentityDictionary subclass)
    and answer it.  */
 static OOP identity_dictionary_new (OOP classOOP,
@@ -568,7 +574,7 @@ static const class_definition class_info[] = {
    "WeakValueIdentityDictionary", NULL, NULL, NULL },
 
   {&_gst_identity_dictionary_class, &_gst_lookup_table_class,
-   GST_ISP_POINTER, false, 0,
+   GST_ISP_POINTER, true, 0,
    "IdentityDictionary", NULL, NULL, NULL },
 
   {&_gst_method_dictionary_class, &_gst_lookup_table_class,
@@ -2181,3 +2187,74 @@ _gst_set_file_stream_file (OOP fileStreamOOP,
     isPipe == -1 ? _gst_nil_oop :
     isPipe ? _gst_true_oop : _gst_false_oop;
 }
+
+/* Profiling callback.  The profiler use a simple data structure
+   to store the cost and the call graph, which is a 2 level
+   IdentityDictionary. First level keys are the CompiledMethod or
+   CompiledBlock, and the second level key is the CompiledMethod or
+   CompiledBlock that it calls. Values are the number of calls made. There
+   is a special key "true" in the second level whose corresponding value
+   is the accumulative cost for this method.  */
+
+void
+_gst_record_profile (OOP newMethod, int ipOffset)
+{
+  OOP profile = _gst_identity_dictionary_at (_gst_raw_profile,
+                                             _gst_this_method);
+  if UNCOMMON (IS_NIL (profile))
+    {
+      profile = identity_dictionary_new (_gst_identity_dictionary_class, 6);
+      _gst_identity_dictionary_at_put (_gst_raw_profile, _gst_this_method,
+                                       profile);
+    }
+
+  _gst_identity_dictionary_at_inc (profile, _gst_true_oop,
+                                   _gst_bytecode_counter
+   - _gst_saved_bytecode_counter);
+  _gst_saved_bytecode_counter = _gst_bytecode_counter;
+
+  /* if ipOffset is 0 then it is a callin and not a return, so we also record
+     the call.  */
+  if (ipOffset == 0)
+    _gst_identity_dictionary_at_inc (profile, newMethod, 1);
+}
+
+/* Assume the value for KEYOOP is an integer already or the key does not exist;
+   increase the value by INC or set it to INC if it does not exist.  */
+int
+_gst_identity_dictionary_at_inc (OOP identityDictionaryOOP,
+ OOP keyOOP,
+ int inc)
+{
+  gst_identity_dictionary identityDictionary;
+  intptr_t index;
+  int oldValue;
+
+  identityDictionary =
+    (gst_identity_dictionary) OOP_TO_OBJ (identityDictionaryOOP);
+
+  /* Never make dictionaries too full! For simplicity, we do this even
+     if the key is present in the dictionary (because it will most
+     likely resolve some collisions and make things faster).  */
+
+  if UNCOMMON (TO_INT (identityDictionary->tally) >=
+             TO_INT (identityDictionary->objSize) * 3 / 8)
+    identityDictionary =
+      _gst_grow_identity_dictionary (identityDictionaryOOP);
+
+  index =
+    identity_dictionary_find_key_or_nil (identityDictionaryOOP, keyOOP);
+
+  if UNCOMMON (IS_NIL (identityDictionary->keys[index - 1]))
+    {
+      identityDictionary->tally = INCR_INT (identityDictionary->tally);
+      oldValue = 0;
+    }
+  else
+    oldValue = TO_INT(identityDictionary->keys[index]);
+  
+  identityDictionary->keys[index - 1] = keyOOP;
+  identityDictionary->keys[index] = FROM_INT(inc+oldValue);
+
+  return (oldValue);
+}
diff --git a/libgst/dict.h b/libgst/dict.h
index 439d976..6a4c150 100644
--- a/libgst/dict.h
+++ b/libgst/dict.h
@@ -664,4 +664,8 @@ extern mst_Boolean _gst_init_dictionary_on_image_load (mst_Boolean prim_table_ma
 extern int _gst_resolve_primitive_name (char *name)
   ATTRIBUTE_HIDDEN;
 
+/* Entry point for the profiler.  */
+extern void _gst_record_profile (OOP newMethod, int ipOffset)
+  ATTRIBUTE_HIDDEN;
+
 #endif /* GST_DICT_H */
diff --git a/libgst/interp-bc.inl b/libgst/interp-bc.inl
index 34e68e4..25d5131 100644
--- a/libgst/interp-bc.inl
+++ b/libgst/interp-bc.inl
@@ -160,7 +160,10 @@
 #define GET_CONTEXT_IP(ctx) TO_INT((ctx)->ipOffset)
 
 #define SET_THIS_METHOD(method, ipOffset) do { \
-  gst_compiled_method _method = (gst_compiled_method) \
+  gst_compiled_method _method;                                          \
+  if UNCOMMON (_gst_raw_profile)                                        \
+    _gst_record_profile (method, ipOffset);                             \
+  _method = (gst_compiled_method)                 \
     OOP_TO_OBJ (_gst_this_method = (method)); \
  \
   method_base = _method->bytecodes; \
diff --git a/libgst/interp.c b/libgst/interp.c
index e859806..f095a05 100644
--- a/libgst/interp.c
+++ b/libgst/interp.c
@@ -171,6 +171,12 @@ unsigned long _gst_cache_misses = 0;
 /* The number of cache lookups - either hits or misses */
 unsigned long _gst_sample_counter = 0;
 
+/* The OOP for an IdentityDictionary that stores the raw profile.  */
+OOP _gst_raw_profile = NULL;
+
+/* A bytecode counter value used while profiling. */
+unsigned long _gst_saved_bytecode_counter = 0;
+
 #ifdef ENABLE_JIT_TRANSLATION
 #define method_base 0
 char *native_ip = NULL;
diff --git a/libgst/interp.h b/libgst/interp.h
index 770c238..b9e9187 100644
--- a/libgst/interp.h
+++ b/libgst/interp.h
@@ -301,6 +301,14 @@ extern OOP _gst_self
 extern OOP _gst_this_context_oop
   ATTRIBUTE_HIDDEN;
 
+/* The OOP for an IdentityDictionary that stores the raw profile. */
+extern OOP _gst_raw_profile
+  ATTRIBUTE_HIDDEN;
+
+/* A bytecode counter value used while profiling. */
+extern unsigned long _gst_saved_bytecode_counter
+  ATTRIBUTE_HIDDEN;
+
 /* The type used to hold the instruction pointer.  For the JIT, this
    is an offset from a location which is deemed the `base' of
    native-compiled methods (because this way it will fit in a
diff --git a/libgst/prims.def b/libgst/prims.def
index c05aa0f..12fdb0a 100644
--- a/libgst/prims.def
+++ b/libgst/prims.def
@@ -5935,6 +5935,30 @@ primitive VMpr_ObjectMemory_gcPrimitives :
   PRIM_SUCCEEDED;
 }
 
+/* SystemDictionary profilerOn */
+
+primitive VMpr_SystemDictionary_rawProfile [succeed]
+{
+  OOP oop1 = POP_OOP ();
+  if (_gst_raw_profile)
+    {
+      _gst_record_profile (NULL, -1);
+      SET_STACKTOP (_gst_raw_profile);
+      _gst_unregister_oop (_gst_raw_profile);
+    }
+  else
+    SET_STACKTOP (_gst_nil_oop);
+  if (IS_NIL (oop1))
+    _gst_raw_profile = NULL;
+  else
+    {
+      _gst_raw_profile = oop1;
+      _gst_register_oop (_gst_raw_profile);
+      _gst_saved_bytecode_counter = _gst_bytecode_counter;
+    }
+  PRIM_SUCCEEDED;
+}
+
 
 #undef INT_BIN_OP
 #undef BOOL_BIN_OP

commit 85d5532d730ec0ff88ecc51497e644b2f67b1c87
Author: Paolo Bonzini <[hidden email]>
Date:   Fri Feb 20 11:27:26 2009 +0100

    add basic callgraph profiler
   
    2009-02-19  Paolo Bonzini  <[hidden email]>
   
    * kernel/CompildCode.st: Add #method.
   
    packages/profile:
    2009-02-19  Derek Zhou  <[hidden email]>
                Paolo Bonzini  <[hidden email]>
   
    * Profiler.st: New.

diff --git a/ChangeLog b/ChangeLog
index c1e2ffc..86914c8 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,7 @@
+2009-02-19  Paolo Bonzini  <[hidden email]>
+
+ * kernel/CompildCode.st: Add #method.
+
 2009-02-19  Derek Zhou  <[hidden email]>
             Paolo Bonzini  <[hidden email]>
 
diff --git a/configure.ac b/configure.ac
index d3d2979..e14dabc 100644
--- a/configure.ac
+++ b/configure.ac
@@ -449,6 +449,7 @@ GST_PACKAGE_ENABLE([LibSDL_ttf], [sdl/libsdl_ttf],
 GST_PACKAGE_ENABLE([Compiler], [stinst/compiler])
 GST_PACKAGE_ENABLE([Parser], [stinst/parser])
 GST_PACKAGE_ENABLE([ClassPublisher], [stinst/doc])
+GST_PACKAGE_ENABLE([ProfileTools], [profile])
 GST_PACKAGE_ENABLE([ROE], [roe])
 GST_PACKAGE_ENABLE([Seaside-Core], [seaside/core])
 GST_PACKAGE_ENABLE([Seaside-Development], [seaside/dev])
diff --git a/kernel/CompildCode.st b/kernel/CompildCode.st
index e9debc2..5410b73 100644
--- a/kernel/CompildCode.st
+++ b/kernel/CompildCode.st
@@ -339,6 +339,13 @@ superclass for blocks and methods'>
  self subclassResponsibility
     ]
 
+    method [
+ "Answer the parent method for the receiver, or self if it is a method."
+
+ <category: 'accessing'>
+ ^self
+    ]
+
     numLiterals [
  "Answer the number of literals for the receiver"
 
diff --git a/packages/profile/ChangeLog b/packages/profile/ChangeLog
new file mode 100644
index 0000000..718eb1e
--- /dev/null
+++ b/packages/profile/ChangeLog
@@ -0,0 +1,4 @@
+2009-02-19  Derek Zhou  <[hidden email]>
+            Paolo Bonzini  <[hidden email]>
+
+ * Profiler.st: New.
diff --git a/packages/profile/Profiler.st b/packages/profile/Profiler.st
new file mode 100644
index 0000000..4272255
--- /dev/null
+++ b/packages/profile/Profiler.st
@@ -0,0 +1,284 @@
+"======================================================================
+|
+|   Basic Profiler tools
+|
+|
+ ======================================================================"
+
+"======================================================================
+|
+| Copyright 2009 2006, 2007 Free Software Foundation, Inc.
+| Written by Derek Zhou and Paolo Bonzini.
+|
+| This file is part of GNU Smalltalk.
+|
+| GNU Smalltalk is free software; you can redistribute it and/or modify it
+| under the terms of the GNU General Public License as published by the Free
+| Software Foundation; either version 2, or (at your option) any later version.
+|
+| GNU Smalltalk is distributed in the hope that it will be useful, but WITHOUT
+| ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
+| FOR A PARTICULAR PURPOSE.  See the GNU General Public License for more
+| details.
+|
+| You should have received a copy of the GNU General Public License along with
+| GNU Smalltalk; see the file COPYING.  If not, write to the Free Software
+| Foundation, 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.  
+|
+ ======================================================================"
+
+
+Object subclass: Profiler [
+    Stack := nil.
+
+    | rawProfile name |
+
+    Profiler class >> profile: aBlock [
+ ^self new
+    withProfilerDo: aBlock;
+    yourself
+    ]
+
+    name [
+ ^name ifNil: [ 'gst ', (Smalltalk arguments join: ' ') ]
+    ]
+
+    name: aString [
+ name := aString
+    ]
+
+    push [
+ Stack isNil ifTrue: [ Stack := OrderedCollection new ].
+ Stack addLast: (Smalltalk rawProfile: self rawProfile)
+    ]
+
+    pop [
+ Smalltalk rawProfile: Stack removeLast
+    ]
+
+    rawProfile [
+ rawProfile isNil ifTrue: [ rawProfile := IdentityDictionary new ].
+ ^rawProfile
+    ]
+
+    withProfilerDo: aBlock [
+ ^[ self push. aBlock value ] ensure: [ self pop ]
+    ]
+]
+
+
+Warning subclass: NoProfile [
+    | method |
+
+    NoProfile class >> for: aMethod [
+ ^self new method: aMethod; yourself
+    ]
+
+    method: aMethod [
+ method := aMethod
+    ]
+
+    description [
+ ^'No profile found'
+    ]
+
+    messageText [
+ ^'%1 for %2' % {self description. method}
+    ]
+]
+
+Object subclass: MethodProfile [
+    | selfCost totalCost totalCalls calleeCounts profiler |
+
+    <category: 'Profiling'>
+    <comment: 'I store some statistics about a method, including cost and
+call graph'>
+
+    MethodProfile class >> newIn: profiler [
+        ^self new initWith: profiler
+    ]
+
+    initWith: p [
+ <category: 'instance creation'>
+        selfCost := 0.
+        profiler := p.
+ calleeCounts := IdentityDictionary new.
+ totalCalls := 0.
+    ]
+
+    merge: p select: aBlock [
+        "merge with raw profile p, which is an IdentityDictionary"
+        p keysAndValuesDo: [ :k :v || profileKey |
+    k == true
+ ifTrue: [ selfCost := selfCost + v ]
+ ifFalse: [
+    (aBlock value: k) ifTrue: [ self add: v callsTo: k]]].
+ totalCost := nil.
+    ]
+
+    printOn: aStream [
+        aStream nextPutAll: '0 %1' % {selfCost}; nl.
+        calleeCounts keysAndValuesDo: [ :callee :n |
+            aStream
+                nextPutAll: 'cfl=%1' % {callee methodSourceFile}; nl;
+                nextPutAll: 'cfn=%1' % {callee uniquePrintString}; nl;
+                nextPutAll: 'calls=%1' % {n}; nl;
+                nextPutAll: '* %1' % {self costOf: callee}; nl ].
+    ]
+
+    add: n callsTo: callee [
+ | calleeProfile |
+ calleeProfile := profiler profileAt: callee.
+ calleeProfile totalCalls: calleeProfile totalCalls + n.
+ calleeCounts
+    at: callee
+    put: n + (calleeCounts at: callee ifAbsent: [0]).
+    ]
+
+    selfCost [
+        ^selfCost
+    ]
+
+    totalCalls [
+ ^totalCalls
+    ]
+
+    totalCalls: n [
+ totalCalls := n
+    ]
+
+    totalCost [
+        totalCost notNil ifTrue: [ ^totalCost ].
+ "TODO: handle loops better."
+        totalCost := calleeCounts keys inject: selfCost into: [ :old :callee |
+    old + (self costOf: callee) ].
+ ^totalCost
+    ]
+
+    costOf: callee [
+        | calleeProfile |
+ calleeProfile := profiler profileAt: callee.
+        calleeProfile totalCalls = 0
+    ifTrue: [(NoProfile for: callee) signal. ^0].
+
+        ^(calleeProfile totalCost * (calleeCounts at: callee)
+    + calleeProfile totalCalls - 1)
+ // calleeProfile totalCalls
+    ]
+]
+
+
+CompiledMethod extend [
+    uniquePrintString [
+ ^self printString
+    ]
+]
+
+CompiledBlock extend [
+    uniquePrintString [
+ ^'%1 at line %2' % { self. self sourceCodeMap first }
+    ]
+]
+
+Profiler subclass: CallGraphProfiler [
+    | methodProfiles |
+
+    <category: 'Profiler'>
+    <comment: 'I store a call tree and associated profiling info'>
+
+    mergeRawProfile [
+        self rawProfile keysAndValuesDo: [ :k :v |
+    | method |
+    method := self accountingMethodFor: k.
+    (self profileAt: method)
+ merge: v
+ select: [ :callee | self isMethodAccounted: callee ]
+ ].
+ rawProfile := nil
+    ]
+
+    accountingMethodFor: aMethod [
+ ^aMethod
+    ]
+
+    isMethodAccounted: aMethod [
+ ^true
+    ]
+
+    profileAt: aMethod [
+ ^methodProfiles
+    at: aMethod
+    ifAbsentPut: [MethodProfile newIn: self]
+    ]
+
+    push [
+        methodProfiles isNil ifTrue: [
+    methodProfiles := IdentityDictionary new: 256 ].
+ super push
+    ]
+
+    pop [
+ super pop.
+ self mergeRawProfile.
+    ]
+
+    totalCost [
+        ^methodProfiles inject: 0 into: [ :sum :each | sum + each selfCost ]
+    ]
+
+    methodCount [
+        ^methodProfiles size
+    ]
+
+    printOn: aStream [
+ "print a callgrind compatible profile report on aStream"
+ self printSummaryOn: aStream.
+ self printCallGraphOn: aStream.
+    ]
+
+    printCallGraphOn: aStream [
+ methodProfiles keysAndValuesDo: [ :method :profile |
+    aStream
+        nextPutAll: 'fl=%1' % {method methodSourceFile}; nl;
+        nextPutAll: 'fn=%1' % {method uniquePrintString}; nl.
+    profile printOn: aStream.
+    aStream nl ]
+    ]
+
+    printCallGraphToFile: aFile [
+ "print a callgrind compatible profile report to a file named aFile"
+ | fs |
+ fs := aFile asFile writeStream.
+ [
+    self
+ printHeaderOn: fs;
+ printSummaryOn: fs.
+    fs nl.
+    self printCallGraphOn: fs
+ ] ensure: [ fs close ]
+    ]
+
+    printSummaryOn: aStream [
+        aStream nextPutAll: 'summary: %1' % {self totalCost}; nl.
+    ]
+
+    printHeaderOn: aStream [
+ aStream
+    nextPutAll: 'version: 1'; nl;
+    nextPutAll: 'creator: gst-profile'; nl;
+    nextPutAll: 'positions: instr'; nl;
+    nextPutAll: 'cmd: %1' % {self name}; nl;
+    nextPutAll: 'events: Ir'; nl
+    ]
+]
+
+CallGraphProfiler subclass: MethodCallGraphProfiler [
+    accountingMethodFor: aMethod [
+ ^aMethod method
+    ]
+
+    isMethodAccounted: aMethod [
+ "Discard blocks, they are accounted for in the parent."
+ ^aMethod method == aMethod
+    ]
+]
diff --git a/packages/profile/package.xml b/packages/profile/package.xml
new file mode 100644
index 0000000..e51404a
--- /dev/null
+++ b/packages/profile/package.xml
@@ -0,0 +1,8 @@
+<package>
+  <name>ProfileTools</name>
+
+  <filein>Profiler.st</filein>
+
+  <file>Profiler.st</file>
+  <file>ChangeLog</file>
+</package>

_______________________________________________
help-smalltalk mailing list
[hidden email]
http://lists.gnu.org/mailman/listinfo/help-smalltalk
Reply | Threaded
Open this post in threaded view
|

Re: PATCH2/2: post processing and reporting

Derek Zhou
On Friday 20 February 2009 05:55:09 am you wrote:
> I settled for a single primitive, and I removed the global too.
And the mystery of MethodDictionaty vs IdentityDictionary is solved too. Very impressive.  
> push/pop functionality is placed in a Profiler abstract class from which
> I derived CallGraphProfiler and MethodCallGraphProfiler.  The two
> classes should have the same purpose as the separateBlocks flag.
Good.
>
> TODO (patches/testing are welcome):
The 2 biggest caveats are:
1, inclusive cost calculation is not accurate. I think a "context sensitive" accounting is doable if we are willing to give up speed and space
2, the cost counter is SmallInteger so it overflows quickly. To run the profiler for more than a couple of minutes we can make it 64 bit and somehow create a LargeInteger when passed back to the smalltalk world.
Both of these are hard to fix, that's why I didn't do. :)
> - comment and categorize methods
>
> - check that the format is really the same as callgrind's, especially I
There is a document at:
http://valgrind.org/docs/manual/cl-format.html
However it does not seems to match 100% what callgrind actually produce. I do know the profile produced by this is usable by kcachegrind, which seems to be the only possible consumer for the output file anyhow.
> don't know if cumulative counts should be added to the caller as well?
From the document:
...
Note that regular cost lines always give self (also called exclusive) cost of code at a given position.
...
The 2nd line looks like a regular cost line with the difference that inclusive cost spent inside of the function call has to be specified.
...
So "regular" cost line (the ones defined by the original cachegrind) should be exclusive and the "association" cost line (the additional ones defined by callgrind) should be inclusive.  
>
> - find a way to remove the conditional from SET_THIS_METHOD???
one single conditional (and staticly predicted not taken) should be almost free. I timed a couple programs with and without it and cannot see any difference. There must be some thing to call the profiler hook and it does not get any faster than that.
>
> Paolo
>
Also I noticed you changed the "fl=" directive to source file name (like what callgrind does) instead of class name. This is nice; I did not know gst actually records file name and line number. Now that we do know the fine name and line number we can change:
positions: instr
to:
positions: line
and change the "0" or "*" at the beginning or each cost line to the line number of the method/block.

Derek


_______________________________________________
help-smalltalk mailing list
[hidden email]
http://lists.gnu.org/mailman/listinfo/help-smalltalk
Reply | Threaded
Open this post in threaded view
|

Re: PATCH2/2: post processing and reporting

Paolo Bonzini-2
Derek Zhou wrote:
> On Friday 20 February 2009 05:55:09 am you wrote:
>> I settled for a single primitive, and I removed the global too.
> And the mystery of MethodDictionaty vs IdentityDictionary is solved too. Very impressive.  
>> push/pop functionality is placed in a Profiler abstract class from which
>> I derived CallGraphProfiler and MethodCallGraphProfiler.  The two
>> classes should have the same purpose as the separateBlocks flag.
> Good.

Yeah, I plan to have more subclasses, for example Profiler->VMProfiler
(making push/pop abstract in the former).  I'd like to have simple
hierarchical timers for example, and they'd inherit from Profiler.

The CallGraphProfiler output could also be moved to a separate
ProfileTable class, so that a sampling profiler can reuse the callgrind
output code.  There's plenty of opportunities for refactoring but I did
only what was immediately useful.

> 1, inclusive cost calculation is not accurate. I think a "context sensitive"
> accounting is doable if we are willing to give up speed and space

Yes, that would probably work better with a sampling profiler.

> 2, the cost counter is SmallInteger so it overflows quickly.

There are facilities for 64-bit counters in the VM, but you have to be
careful not to allocate too many LargeIntegers

>> - check that the format is really the same as callgrind's, especially I
> There is a document at:
> http://valgrind.org/docs/manual/cl-format.html
> However it does not seems to match 100% what callgrind actually produce.
> I do know the profile produced by this is usable by kcachegrind

Yeah, it works well with callgrind_annotate too.

> Also I noticed you changed the "fl=" directive to source file name (like what callgrind does) instead of class name. This is nice; I did not know gst actually records file name and line number. Now that we do know the fine name and line number we can change:
> positions: instr
> to:
> positions: line
> and change the "0" or "*" at the beginning or each cost line to the line number of the method/block.

Good idea, yes (though not strictly urgent).

More short-term I'd like to make a gst-profile driver to make the
ProfilerTools package easy to use.  I guess that will expose the #fileIn
bug you mentioned, whatever it is...

Paolo


_______________________________________________
help-smalltalk mailing list
[hidden email]
http://lists.gnu.org/mailman/listinfo/help-smalltalk