John: Forget my previous mail. I found the .txt. Very, very thanks for this work. Still wish know if I could start/stop the profiling for I choose what profile.

Edgar

___________________________________________________________ 1GB gratis, Antivirus y Antispam Correo Yahoo!, el mejor correo web del mundo http://correo.yahoo.com.ar

On 29-Oct-05, at 8:50 AM, John M McIntosh wrote:

Let me add a primitive to turn that on or off

There are already primitives for controlling profiling. Just use those! clearProfile, dumpProfile, startProfiling, stopProfiling

tim

If you're attempting a serious attack on profiling you ought to include some time looking at how to make profiling work in the face of long running primitives. The profiles we get when using TimeProfiler et al can be quite innaccurate if the code being profiled uses prims that take a long time; the process that interrupts to sample the subject code cannot actually interrupt inside such a long prim.

I forget how it was tackled but VW has some code to try to improve the value of the results, or used to. It is possible that later changes have obviated the problem or changed it beyond obvious similarity.

tim

Hello Alexandre,

happy to hear you will work on this! AB> Here are some thoughts: AB> - 2 kinds of profiling: time and speed. How long methods of my AB> application takes ? How much memory my application requires ?

one thing I always miss: the time spent in my code vs. the total time spent in the method. I always have to write something to find out never knowing if my simplifications are valid.

Example: my code is iterating over an ordered collection and I want to know if OrderedCollection>>do: already takes a significant time of it all, so it's not worth speeding up my method.

Also I'd like a non indented display in the ProfileBrowser, just methods ordered by the time spent inside them and the number of sends.

ClassName>>messageName, timeSpentHere, numberOfSends, ordered by time.

The number of sends is important, it is a difference to reduce the number of sends or to speed up the code.

AB> - Currently, in Squeak, I can only listen to everything (i.e., AB> every method call is measured). It might be interesting to limit the AB> measurement to a small part of the system (e.g., objets).

A good idea! Please extend it to isKindOf as a way to select objects included into the measurement.

There is another area which I call "activity spikes" lacking a better description. Think of responsiveness of an UI. Think of real time processing, like not missing an audio sample.

I'd like to have a trigger when the time spent in a block of code exceeds a certain time. Then I'd like to get a trace of sends to find out what lead to this situation.

This needs a finer grained timer, as it's not an option to divide the obtained time by the number of executions.

Also a trigger on number of sends. The objects you mention also belong to the triggers.

A trace and triggers are important in profiling.

And please keep me (or the list) posted in this matter!

Cheers,

Herbert mailto:herbertkoenig@gmx.net

Hi Alex,

perhaps comprehensive system accounting (CSA) is a starter to see what ideas are already around for everyday's system accounting (for such long runners as Seaside). - http://www.google.com/search?q=comprehensive+system+accounting+csa

In any case I think that accounting for memory and cpu should be per process (and so I would see my favorite memory integral again :) but that would require changes to ObjectMemory (object instantiation + GC) ...

Into quite another direction goes the polymorphism metrics, which addresses the actual receiver and/or target method per call site, and can serve as a measurement of an application's object-orientedness, etc. This should also be per process (or, better perhaps per ClassBox). - http://www.google.com/search?q=call+site+polymorphic

Hope that's not too much ;)

/Klaus

On Sat, 29 Oct 2005 19:04:34 +0200, Alexandre Bergel bergel@iam.unibe.ch wrote:

In the very near future, I plan to work on profiling technics. The question I want to ask you is: What are the information we want to obtain from a program execution?

Here are some thoughts: - 2 kinds of profiling: time and speed. How long methods of my application takes ? How much memory my application requires ? - minimize the amount of information by restricting the output of the profiler to the information I am really interested in. Basically, If I define a seaside application, I am only concerned by my application, and not by the seaside framework. - Currently, in Squeak, I can only listen to everything (i.e., every method call is measured). It might be interesting to limit the measurement to a small part of the system (e.g., objets).

I would be really interested in hearing your opinion...

Regards, Alexandre

On Oct 29, 2005, at 6:36 PM, tim Rowledge wrote:

...

On 29-Oct-05, at 8:50 AM, John M McIntosh wrote:

...

Let me add a primitive to turn that on or off

There are already primitives for controlling profiling. Just use those! clearProfile, dumpProfile, startProfiling, stopProfiling

tim --tim Rowledge; tim@rowledge.org; http://www.rowledge.org/tim

Herbert, Stéf, Klaus, John,

thanks very much for your feedback. I am really excited by this idea of profiling. you count on me to ask you to be testers :-)

Cheers, Alexandre

On Oct 29, 2005, at 11:36 PM, John M McIntosh wrote:

Well Process>>resume: in the vm is where process switch. A few years back I wrote a change set and altered Process to track millisecond clock time, start dispatch, end of dispatch, and total time dispatched. That let you understand the clock time that a process had to run with (not the same as cpu time). One could also track the allocation count for a process by tracking that by the active processor structure when new is invoked.

On 29-Oct-05, at 1:00 PM, Klaus D. Witzel wrote:

...

Hi Alex,

perhaps comprehensive system accounting (CSA) is a starter to see what ideas are already around for everyday's system accounting (for such long runners as Seaside).

• http://www.google.com/search?q=comprehensive+system+accounting+csa

In any case I think that accounting for memory and cpu should be per process (and so I would see my favorite memory integral again :) but that would require changes to ObjectMemory (object instantiation + GC) ...

Into quite another direction goes the polymorphism metrics, which addresses the actual receiver and/or target method per call site, and can serve as a measurement of an application's object- orientedness, etc. This should also be per process (or, better perhaps per ClassBox).

• http://www.google.com/search?q=call+site+polymorphic

Hope that's not too much ;)

/Klaus

On Sat, 29 Oct 2005 19:04:34 +0200, Alexandre Bergel bergel@iam.unibe.ch wrote:

...

In the very near future, I plan to work on profiling technics. The question I want to ask you is: What are the information we want to obtain from a program execution?

Here are some thoughts: - 2 kinds of profiling: time and speed. How long methods of my application takes ? How much memory my application requires ? - minimize the amount of information by restricting the output of the profiler to the information I am really interested in. Basically, If I define a seaside application, I am only concerned by my application, and not by the seaside framework. - Currently, in Squeak, I can only listen to everything (i.e., every method call is measured). It might be interesting to limit the measurement to a small part of the system (e.g., objets).

I would be really interested in hearing your opinion...

Regards, Alexandre

On Oct 29, 2005, at 6:36 PM, tim Rowledge wrote:

...

On 29-Oct-05, at 8:50 AM, John M McIntosh wrote:

...

Let me add a primitive to turn that on or off

There are already primitives for controlling profiling. Just use those! clearProfile, dumpProfile, startProfiling, stopProfiling

tim --tim Rowledge; tim@rowledge.org; http://www.rowledge.org/tim

--

===== John M. McIntosh johnmci@smalltalkconsulting.com 1-800-477-2659 Corporate Smalltalk Consulting Ltd. http:// www.smalltalkconsulting.com ====================================================================== =====

tim Rowledge puso en su mail :

There are already primitives for controlling profiling. Just use those! clearProfile, dumpProfile, startProfiling, stopProfiling

Tim: Very thanks to you too.

Edgar

___________________________________________________________ 1GB gratis, Antivirus y Antispam Correo Yahoo!, el mejor correo web del mundo http://correo.yahoo.com.ar

Hi tim

I was exactly wondering is they were used.

Actually, I half take back that suggestion to use clear/dump/start/ stop profiling; those are relic stub prims in the primitive table and ought to be excised sometime soon.

Should we deprecated them?

Using the similar names as named prims in the null-module (ie they can be included in the vm like the powermanagement prim) should be fine. That would make them optional and they can be left out to save space when people want to make minimalist VMs.

tim

tim Rowledge; tim@rowledge.org; http://www.rowledge.org/tim

John:

Thanks a lot again. As I write in my acknowledges , you not only are a master, you are "indispensable squeaker".

Gracias desde Rosario, Argentina.

Edgar

___________________________________________________________ 1GB gratis, Antivirus y Antispam Correo Yahoo!, el mejor correo web del mundo http://correo.yahoo.com.ar

David the change set is on ftp://ftp.smalltalkconsulting.com/experimental/JMMRecordMsgSends. 1.cs.zip

If you want to change the logic to invoke what you suggest please do and send me the change set. Having a working example for the Unix VM would be a good thing. The method of interest would be:

Change? Interpreter >>initVmStatsTraceMessageSendLevels vmStatsTraceMessageSendLevels := 0. vmStatsTraceMessageSendStorageFile := 0.

Then consider two sig handlers of your choice. One that tracks the level increment number and increments it by one for each signal and then invokes. Smalltalk setVMStatsTraceMessageSendLevels: theIncrementNumber

The other handler would just reset theIncrementNumber to zero and invoke the setVMStatsTraceMessageSendLevels:

----------

ORIGINAL: *Apologies to people horrified by this piece of code abuses of how self cCode: works and how it interacts with SLANG, however as experimental code things can be a bit hacked*

Interpreter >>initVmStatsTraceMessageSendLevels vmStatsTraceMessageSendLevels := 0. vmStatsTraceMessageSendStorageFile := 0. self cCode: ' { void handleUSR1(int signal); void handleUSR2(int signal);

signal(SIGUSR1, handleUSR1); signal(SIGUSR2, handleUSR2); } } #include <libc.h> #include <signal.h>

void handleUSR1(int signal) { foo->vmStatsTraceMessageSendLevels++; }

void handleUSR2(int signal) { foo->vmStatsTraceMessageSendLevels = 0; if (foo->vmStatsTraceMessageSendStorageFile) fclose(foo->vmStatsTraceMessageSendStorageFile); foo->vmStatsTraceMessageSendStorageFile = 0;

'

On 30-Oct-05, at 10:21 AM, David T. Lewis wrote:

On Sat, Oct 29, 2005 at 09:46:39PM -0700, John M McIntosh wrote:

...

b) As an extra feature based on conversation with Michael at breakfast this morning you can also do under os-x (unix/darwin) a kill signal to turn recording on.

kill -USR1 19278 {Pick a squeak VM process id}

kill -USR1 19278 {increment the level by one, go to 2} kill -USR1 19278 {increment the level by one, go to 3}

kill -USR2 19278 {turn recording off, and close the file}

Hi John,

Here's one additional suggestion. Rather than dedicating SIGUSR1 and SIGUSR2 to this specific function, you can select what signals to use from the image, and also handle the signals in the image. The OSPP plugin provides the required signal forwarding primitives, so the idea would be to forward SIGUSR1 and SIGUSR2 (or whatever) to semaphores in the image, with processes waiting on the semaphores to do the #setVMStatsTraceMessageSendLevels: calls that control the trace logging.

The reason this is important is that someone else may want to use SIGUSR1 and SIGUSR2 for some other purpose. For example, some pthread libraries on Linux make use of these signals, which would mean that a Linux VM that used pthreads might not work if you steal the signal handlers away from the pthreads library. I think that the svalib on Linux also uses these signals, which would affect somebody who wanted a VM on Linux that ran directly on the VGA display rather than on X window. And who knows about all the sound libraries and so forth. Also, somebody running a Seaside server might want to use SIGUSR1 to signal the server to do an image save (just making this up as a possible example).

Note: I'm afraid that I did not put convenience methods into OSPP for the SIGUSR1 and SIGUSR2 signals (but that's an easy fix), so you would need to specify the actual integer values 10 and 12, as in

startTracingSemaphore := OSProcess accessor forwardSignal: 10. [[startTracingSemaphore wait. (traceLevel < 5) ifTrue: [traceLevel := traceLevel + 1. Smalltalk setVMStatsTraceMessageSendLevels: traceLevel]] repeat] fork

The above is not tested, but you get the idea.

And I should fix up OSP so you can say "OSProcess accessor forwardSigUsr1" instead of "OSProcess accessor forwardSignal: 10".

Dave

-- ======================================================================== === John M. McIntosh johnmci@smalltalkconsulting.com 1-800-477-2659 Corporate Smalltalk Consulting Ltd. http://www.smalltalkconsulting.com ======================================================================== ===

On Sun, Oct 30, 2005 at 10:44:24AM -0800, John M McIntosh wrote:

On 30-Oct-05, at 10:21 AM, David T. Lewis wrote:

...

Here's one additional suggestion. Rather than dedicating SIGUSR1 and SIGUSR2 to this specific function, you can select what signals to use from the image, and also handle the signals in the image.

David the change set is on ftp://ftp.smalltalkconsulting.com/experimental/JMMRecordMsgSends. 1.cs.zip

If you want to change the logic to invoke what you suggest please do and send me the change set. Having a working example for the Unix VM would be a good thing.

Hi John,

Here are the changes to move the SIGUSR1 and SIGUSR2 signal handlers out of the VM and into the image. Class VMStatsTraceControl implements the signal handlers, which are activated at image startup and deactivated at image shutdown.

Along the way I fixed a bug in #primitiveSetVMStatsTraceMessageSendLevels that was causing my VM to crash when the stats log file was closed then reopened.

I have to mention that I have seen a nasty problem that I don't understand. On two different occasions while I was writing and debugging this, I ended up the stats trace log data being written to my changes file (with horrible results, needless to say). I do not know what the cause was, I don't know how to reproduce it, and I don't know if it's related to the signal handling or something else in the interpreter changes. In any case, be on the lookout for this bug, and save your image rather more often than you might otherwise do.

Other than that, it's rock solid ;)

Dave

From the change set preambles:

VMStatsTraceControl-dtl

Add VMStatsTraceControl to provide the signal handlers for SIGUSR1 and SIGUSR1 controlling VM stats log. Sending a SIGUSR1 signal to the Squeak process increments the logging level, and SIGUSR2 disables logging and closes the file.

Requires OSProcess for the signal handling (but relevant methods can be copied into VMStatsTraceControl if you don't want to require OSP). The signal handling primitive is in OSPP, currently distributed with the Unix VM, or load OSProcessPlugin from SqueakMap.

VMStatsInterpreterChanges-dtl

Interpreter changes to accompany VMStatsTraceControl-dtl. This removes the SIGUSR1 and SIGUSR2 signal handlers from the interpreter so they can be handled in the image.

Load this after JMMRecordMsgSends and JMMRecordMsgSendInterface. Also load VMStatsTraceControl-dtl.

Interpreter changes: - Removed #cCode: (interrupt handlers) from Interpreter>>initVmStatsTraceMessageSendLevels. - Added Add Interpreter>>primitiveGetVMStatsTraceMessageSendLevels. - Added SystemDictionary>>getVMStatsTraceMessageSendLevels - Fixed assignment bug in Interpreter>>primitiveSetVMStatsTraceMessageSendLevels (change '=' to ':=').

On Wed, Nov 02, 2005 at 05:38:55PM -0800, John M McIntosh wrote:

(got to love = versus == issues as always in C, 27 years of practice and I still can get it right).

Worse than that, I didn't spot it until I looked at the generated C code. So I was staring at the "=" versus ":=" and not seeing it, but when I saw the "==" instead of "=" in C, I noticed it. So maybe that funky left-arrow assignment character isn't such a dumb idea after all ;)

...

<intermittent irreproducible bug description snipped>

I think the issue here (and might suggest you could make the change) is to set a flag on the signal change to avoid a race condition between the interpreter and the signal handler for access to the file handle. I wonder if the file gets closed by the signal as we are doing fprintfs....

It sure seems like it must be that sort of problem. Only thing is, nothing is being done in the context of the Unix signal handler. By forwarding the Unix signal to a Squeak Semaphore, we are ensuring that the signal handling work is done in the interpreter itself, hence no such race condition should be possible.

Unfortunately, noone has informed the bug of the impossibility of its existence, so it still seems to be happening.

I'll try harder to reproduce this, and see if your suggestion helps.

Dave

John,

This is an updated version of VMStatsTraceControl-dtl for controlling your VM stats logging. It is updated to take advantage of OSP 4.0.1 and OSPP 4.0.1, which provide primitives to identify the (platform-dependent) SIGUSR1 and SIGUSR2 signal numbers. It is backward compatible, using the default values 10 and 12 respectively if the primitives are not available.

It also provides convenience methods VMStatsTraceControl class>>incrSigNum: and VMStatsTraceControl class>>clearSigNum: to control the signals to be monitored.

VMStatsTraceControl-dtl.9.cs.gz is the updated change set. I am also attaching the original (unchanged) VMStatsInterpreterChanges-dtl.cs.gz for completeness.

Dave