[PATCH] gst-profile

This patch adds a gst-profile tool to use the profiler more easily.  Bug
reports (Derek, can you reproduce the filein thing?) are welcome.

Paolo

commit 876ba99d2504cf3ab38958e775a0b7a93c059b53
Author: Paolo Bonzini <[hidden email]>
Date:   Mon Feb 23 09:55:26 2009 +0100

    add gst-profile.
   
    2009-02-22  Paolo Bonzini  <[hidden email]>
   
    * scripts/Profile.st: New.
    * gst-tool.c: Add its options.

diff --git a/ChangeLog b/ChangeLog
index 86914c8..e053802 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,8 @@
+2009-02-22  Paolo Bonzini  <[hidden email]>
+
+ * scripts/Profile.st: New.
+ * gst-tool.c: Add its options.
+
 2009-02-19  Paolo Bonzini  <[hidden email]>
 
  * kernel/CompildCode.st: Add #method.
diff --git a/Makefile.am b/Makefile.am
index 95f29eb..374d31c 100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -119,7 +119,7 @@ gst_tool_DEPENDENCIES = libgst/libgst.la lib-src/library.la
 gst_tool_LDFLAGS = -export-dynamic $(RELOC_LDFLAGS)
 
 GST_EXTRA_TOOLS = gst-reload gst-sunit gst-blox gst-package gst-convert \
- gst-doc gst-remote
+ gst-doc gst-remote gst-profile
 
 uninstall-local::
  @for i in gst-load $(GST_EXTRA_TOOLS); do \
diff --git a/gst-tool.c b/gst-tool.c
index 1d6a464..8599eb6 100644
--- a/gst-tool.c
+++ b/gst-tool.c
@@ -135,6 +135,13 @@ struct tool tools[] = {
  -I|--image-file: --kernel-directory:",
     NULL
   },
+  {
+    "gst-profile", "scripts/Profile.st",
+    "-f|--file: -e|--eval: -o|--output: -h|--help --version \
+ --no-separate-blocks",
+    NULL
+  },
+
   { NULL, NULL, NULL, NULL }
 };
 
diff --git a/scripts/Profile.st b/scripts/Profile.st
new file mode 100644
index 0000000..0d92036
--- /dev/null
+++ b/scripts/Profile.st
@@ -0,0 +1,122 @@
+"======================================================================
+|
+|   GNU Smalltalk profiling tool
+|
+|
+ ======================================================================"
+
+
+"======================================================================
+|
+| Copyright 2009 Free Software Foundation, Inc.
+| Written by 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.  
+|
+ ======================================================================"
+
+PackageLoader fileInPackage: 'ProfileTools'.
+DLD addLibrary: 'libc'.
+
+SystemDictionary extend [
+    SmalltalkArgv := OrderedCollection new.
+]
+
+| helpString output profiler profilerClass last |
+commands := OrderedCollection new.
+output := nil.
+profilerClass := CallGraphProfiler.
+
+helpString :=
+'Usage:
+    gst-profile [ flag ... ] [FILE ARGS]
+
+Options:
+    -f --file=FILE            file in FILE
+    -e --eval=CODE            evaluate CODE
+    -o --output=FILE          output file for callgrind_annotate
+    -h --help                 show this message
+       --no-separate-blocks   do not track blocks separately
+       --version              print version information and exit
+
+FILE is always parsed, even if --file or --eval are used.  It is also
+always parsed last.  Use /dev/null to pass arguments directly to --file
+or --eval options.
+'.
+
+"Parse the command-line arguments."
+[Smalltalk
+    arguments: '-f|--file: -e|--eval: -o|--output: -h|--help --version
+ --no-separate-blocks'
+    do: [ :opt :arg |
+
+    opt = 'help' ifTrue: [
+ helpString displayOn: stdout.
+ ObjectMemory quit: 0 ].
+
+    opt = 'no-separate-blocks' ifTrue: [
+ profilerClass := MethodCallGraphProfiler ].
+
+    opt = 'version' ifTrue: [
+ ('gst-profile - %1' % {Smalltalk version}) displayNl.
+ ObjectMemory quit: 0 ].
+
+    opt = 'output' ifTrue: [
+ output isNil ifFalse: [ self error: 'multiple output files' ].
+ output := arg ].
+
+    opt = 'file' ifTrue: [
+ commands add: (File name: arg) ].
+
+    opt = 'eval' ifTrue: [
+ commands add: arg ].
+
+    opt isNil ifTrue: [
+ last isNil
+    ifTrue: [ last := arg ]
+    ifFalse: [ SystemDictionary.SmalltalkArgv addLast: arg ] ].
+    ]
+
+    ifError: [
+        helpString displayOn: stderr.
+        ObjectMemory quit: 1 ].
+
+    last isNil ifFalse: [
+ commands add: (File name: last) ].
+
+    commands isEmpty ifTrue: [ self error: 'no commands given' ]
+ ] on: Error do: [ :ex |
+    ('gst-profile: ', ex messageText, '
+') displayOn: stderr.
+    stderr flush.
+    helpString displayOn: stderr.
+    ObjectMemory quit: 1 ].
+
+SystemDictionary compile:
+    'getpid [ <cCall: ''getpid'' returning: #int args: #()> ]'.
+SystemDictionary compile:
+    'arguments [ ^SmalltalkArgv asArray ]'.
+
+profiler := profilerClass new.
+output isNil ifTrue: [
+    output := Directory working / ('gst-profile.%1' % { Smalltalk getpid }) ].
+
+commands do: [ :each |
+    "Using #readStream makes it work both for Strings and Files.
+     TODO: use hooks instead, maybe directly in Profiler?."
+    profiler withProfilerDo: [ each readStream fileIn ] ].
+
+profiler printCallGraphToFile: output.

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

I will do that tomorrow.
Derek

On Wednesday 25 February 2009 01:16:45 am Paolo Bonzini wrote:
> This patch adds a gst-profile tool to use the profiler more easily.  Bug
> reports (Derek, can you reproduce the filein thing?) are welcome.
>
> Paolo
>




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

On Wednesday 25 February 2009 01:16:45 am Paolo Bonzini wrote:
> This patch adds a gst-profile tool to use the profiler more easily.  Bug
> reports (Derek, can you reproduce the filein thing?) are welcome.
>
> Paolo
>

A few things:
1, scripts/Profile.st is not installed by default, gst-profile can not find it.

2, I highly recommending making no-separate-blocks the default. Consider the very common case like:
anArray do: [ :each | each doSomethingEasy ].
...
anotherArray do: [ :each | each doSomethingHard ].
The inclusive cost calculation assume each invocation cost roughly the same; but a do: method basically does nothing but evaluates blocks, and there can be huge variation and even false recursion, so if blocks are separated out the resulting inclusive cost calculation can be very skewed. On the other hand, if we lump the cost of block into the parent method it would appear that all blocks are inlined just like ifTrue:, etc, which is actually quite intuitive. Also the inclusive cost calculation would reflect the reality more. Yes, non-literal blocks will cause strange cost allocation but in most programs literal blocks outnumber non-literal block by a wide margin.    

3, this need to be done to avoid potential endless recursion:
derek@xiaomai:~/src$ diff -u smalltalk/packages/profile/Profiler.st ~smalltalk/packages/profile/Profiler.st
--- smalltalk/packages/profile/Profiler.st~ 2009-02-26 22:10:43.000000000 -0800
+++ smalltalk/packages/profile/Profiler.st 2009-02-26 22:32:51.000000000 -0800
@@ -149,8 +149,9 @@
 
     totalCost [
         totalCost notNil ifTrue: [ ^totalCost ].
- "TODO: handle loops better."
-        totalCost := calleeCounts keys inject: selfCost into: [ :old :callee |
+ "TODO: handle loops better. The assignment prevent endless recursion"
+        totalCost := selfCost.
+        totalCost := calleeCounts keys inject: totalCost into: [ :old :callee |
     old + (self costOf: callee) ].
  ^totalCost
     ]
Assignment to totalCost before diving in the call tree will make a potential recursive call terminate. Not the best way in the world but at least it won't bomb.  

4, yes, if there is fileIn inside the profiling block (which is guarantied with gst-profile) the 2 things I observed before still happen:
* Some methods get negative cost. I believe this is caused by somewhere inside fileIn the byteCounter is reset to 0. One way to work around it is do something like:
  MAX(_gst_bytecode_counter - _gst_saved_bytecode_counter, 0)
But it looks ugly.
* I still observed some crashes; and they disappeared if I manually invoke the profiler to avoid fileIns. The crashes are non-intuitive yet deterministic; same program will always crash the same way; and some superficial change to the program can make the crash to disappear or appear or move to another place. One workaround is to  change fileIn to always push/pop profiler around it but that feels ugly too.

Derek
 


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

> 1, scripts/Profile.st is not installed by default, gst-profile can not find it.

Thanks

> 2, I highly recommending making no-separate-blocks the default.

Ok.

> 3, this need to be done to avoid potential endless recursion:

Ops, I forgot to push a patch.

> 4, yes, if there is fileIn inside the profiling block (which is guarantied with gst-profile) the 2 things I observed before still happen:
> * Some methods get negative cost. I believe this is caused by somewhere inside fileIn the byteCounter is reset to 0.

It's in _gst_execute_statements, I fixed it in the same patch I've not pushed.

> * I still observed some crashes; and they disappeared if I manually invoke the profiler to avoid fileIns. The crashes are non-intuitive yet deterministic; same program will always crash the same way; and some superficial change to the program can make the crash to disappear or appear or move to another place. One workaround is to  change fileIn to always push/pop profiler around it but that feels ugly too.

Do you have a simple example (I can use delta to minimize it, send it
offlist if there are privacy problems of any kind).

Paolo


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

On Thursday 26 February 2009 11:35:58 pm Paolo Bonzini wrote:
> Do you have a simple example (I can use delta to minimize it, send it
> offlist if there are privacy problems of any kind).
>
> Paolo
>
This patch seems to fix my problem. What it does is to move the
prepare_context call to before the SET_THIS_METHOD. Logically it should not
matter one way or the other but now that SET_THIS_METHOD may call the
profiler which can allocate memory which in turn can trigger GC. If the
context is not prepared correctly, GC may corrupt the memory and cause
mystical crash.

The above is just a theory and I have no solid proof that this is the problem
but my crashes do go away. I also do not have a good reason why fileIn seems
to have strong correlation with my crashes. I do believe this change is
harmless at the very least.

Derek  

diff --git a/libgst/interp-bc.inl b/libgst/interp-bc.inl
index 34e68e4..970dd61 100644
--- a/libgst/interp-bc.inl
+++ b/libgst/interp-bc.inl
@@ -301,11 +304,11 @@ _gst_send_message_internal (OOP sendSelector,
 
   newContext = activate_new_context (header.stack_depth, sendArgs);
   newContext->flags = MCF_IS_METHOD_CONTEXT;
+  /* push args and temps, set sp and _gst_temporaries */
+  prepare_context ((gst_context_part) newContext, sendArgs, header.numTemps);
   SET_THIS_METHOD (methodOOP, 0);
   _gst_self = receiver;
 
-  /* push args and temps, set sp and _gst_temporaries */
-  prepare_context ((gst_context_part) newContext, sendArgs, header.numTemps);
 }
 
 void
@@ -388,11 +391,11 @@ _gst_send_method (OOP methodOOP)
   /* prepare new state */
   newContext = activate_new_context (header.stack_depth, sendArgs);
   newContext->flags = MCF_IS_METHOD_CONTEXT;
+  /* push args and temps, set sp and _gst_temporaries */
+  prepare_context ((gst_context_part) newContext, sendArgs, header.numTemps);
   SET_THIS_METHOD (methodOOP, 0);
   _gst_self = receiver;
 
-  /* push args and temps, set sp and _gst_temporaries */
-  prepare_context ((gst_context_part) newContext, sendArgs, header.numTemps);
 }
 
 
@@ -424,11 +427,11 @@ send_block_value (int numArgs, int cull_up_to)
     (gst_block_context) activate_new_context (header.depth, numArgs);
   closure = (gst_block_closure) OOP_TO_OBJ (closureOOP);
   blockContext->outerContext = closure->outerContext;
-  _gst_self = closure->receiver;
-  SET_THIS_METHOD (closure->block, 0);
-
   /* push args and temps */
   prepare_context ((gst_context_part) blockContext, numArgs, header.numTemps);
+  SET_THIS_METHOD (closure->block, 0);
+  _gst_self = closure->receiver;
+
   return (false);
 }
 




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

On Thursday 26 February 2009 11:35:58 pm Paolo Bonzini wrote:
> Do you have a simple example (I can use delta to minimize it, send it
> offlist if there are privacy problems of any kind).
>
> Paolo
>
Update the patch try to cover more bases. The idea is to make sure when
_gst_record_profile is called the VM is in a self-consistant state so if GC
is triggered it won't mess up the memory.

Derek

--- orig/libgst/interp-bc.inl
+++ mod/libgst/interp-bc.inl
@@ -160,15 +160,15 @@
 #define GET_CONTEXT_IP(ctx) TO_INT((ctx)->ipOffset)
 
 #define SET_THIS_METHOD(method, ipOffset) do { \
-  gst_compiled_method _method;                                          \
-  if UNCOMMON (_gst_raw_profile)                                        \
-    _gst_record_profile (method, ipOffset);                             \
-  _method = (gst_compiled_method)                 \
+  OOP old_method_oop = _gst_this_method;                                \
+  gst_compiled_method _method = (gst_compiled_method)                   \
     OOP_TO_OBJ (_gst_this_method = (method)); \
  \
   method_base = _method->bytecodes; \
-  _gst_literals = OOP_TO_OBJ (_method->literals)->data; \
+  _gst_literals = OOP_TO_OBJ (_method->literals)->data;                 \
   ip = method_base + (ipOffset); \
+  if UNCOMMON (_gst_raw_profile)                                        \
+    _gst_record_profile (old_method_oop, method, ipOffset);             \
 } while(0)
 
 
@@ -304,11 +304,11 @@
 
   newContext = activate_new_context (header.stack_depth, sendArgs);
   newContext->flags = MCF_IS_METHOD_CONTEXT;
-  SET_THIS_METHOD (methodOOP, 0);
-  _gst_self = receiver;
-
   /* push args and temps, set sp and _gst_temporaries */
   prepare_context ((gst_context_part) newContext, sendArgs, header.numTemps);
+  _gst_self = receiver;
+  SET_THIS_METHOD (methodOOP, 0);
+
 }
 
 void
@@ -391,11 +391,11 @@
   /* prepare new state */
   newContext = activate_new_context (header.stack_depth, sendArgs);
   newContext->flags = MCF_IS_METHOD_CONTEXT;
-  SET_THIS_METHOD (methodOOP, 0);
-  _gst_self = receiver;
-
   /* push args and temps, set sp and _gst_temporaries */
   prepare_context ((gst_context_part) newContext, sendArgs, header.numTemps);
+  _gst_self = receiver;
+  SET_THIS_METHOD (methodOOP, 0);
+
 }
 
 
@@ -427,11 +427,11 @@
     (gst_block_context) activate_new_context (header.depth, numArgs);
   closure = (gst_block_closure) OOP_TO_OBJ (closureOOP);
   blockContext->outerContext = closure->outerContext;
+  /* push args and temps */
+  prepare_context ((gst_context_part) blockContext, numArgs, header.numTemps);
   _gst_self = closure->receiver;
   SET_THIS_METHOD (closure->block, 0);
 
-  /* push args and temps */
-  prepare_context ((gst_context_part) blockContext, numArgs, header.numTemps);
   return (false);
 }
 
--- orig/libgst/dict.h
+++ mod/libgst/dict.h
@@ -665,7 +665,7 @@
   ATTRIBUTE_HIDDEN;
 
 /* Entry point for the profiler.  */
-extern void _gst_record_profile (OOP newMethod, int ipOffset)
+extern void _gst_record_profile (OOP oldMethod, OOP newMethod, int ipOffset)
   ATTRIBUTE_HIDDEN;
 
 #endif /* GST_DICT_H */
--- orig/libgst/dict.c
+++ mod/libgst/dict.c
@@ -2197,14 +2197,14 @@
    is the accumulative cost for this method.  */
 
 void
-_gst_record_profile (OOP newMethod, int ipOffset)
+_gst_record_profile (OOP oldMethod, OOP newMethod, int ipOffset)
 {
   OOP profile = _gst_identity_dictionary_at (_gst_raw_profile,
-                                             _gst_this_method);
+                                             oldMethod);
   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,
+      _gst_identity_dictionary_at_put (_gst_raw_profile, oldMethod,
                                        profile);
     }
 
--- orig/libgst/interp.c
+++ mod/libgst/interp.c
@@ -1342,8 +1342,8 @@
 
   _gst_this_context_oop = oop;
   thisContext = (gst_method_context) OOP_TO_OBJ (oop);
-  SET_THIS_METHOD (thisContext->method, GET_CONTEXT_IP (thisContext));
   sp = thisContext->contextStack + TO_INT (thisContext->spOffset);
+  SET_THIS_METHOD (thisContext->method, GET_CONTEXT_IP (thisContext));
 
 #if ENABLE_JIT_TRANSLATION
   ip = TO_INT (thisContext->ipOffset);
--- orig/libgst/prims.def
+++ mod/libgst/prims.def
@@ -5942,7 +5942,7 @@
   OOP oop1 = POP_OOP ();
   if (_gst_raw_profile)
     {
-      _gst_record_profile (NULL, -1);
+      _gst_record_profile (_gst_this_method, NULL, -1);
       SET_STACKTOP (_gst_raw_profile);
       _gst_unregister_oop (_gst_raw_profile);
     }
 


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

Derek Zhou wrote:
> On Thursday 26 February 2009 11:35:58 pm Paolo Bonzini wrote:
>> Do you have a simple example (I can use delta to minimize it, send it
>> offlist if there are privacy problems of any kind).
>>
>> Paolo
>>
> Update the patch try to cover more bases. The idea is to make sure when
> _gst_record_profile is called the VM is in a self-consistant state so if GC
> is triggered it won't mess up the memory.

Yes, this should be okay because ip is recalculated upon GC.  So you
make it consistent before GC.  I'll look at the code a bit more and then
apply the patch, thanks!

Paolo


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

Derek Zhou wrote:
> On Thursday 26 February 2009 11:35:58 pm Paolo Bonzini wrote:
>> Do you have a simple example (I can use delta to minimize it, send it
>> offlist if there are privacy problems of any kind).
>>
>> Paolo
>>
> Update the patch try to cover more bases. The idea is to make sure when
> _gst_record_profile is called the VM is in a self-consistant state so if GC
> is triggered it won't mess up the memory.

I committed the patch with an additional tiny change to incubate the
oldMethod in _gst_record_profile.  I'll merge the branch to master soon.

Paolo


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