Hi Philippe,

On Tue, Jun 17, 2014 at 1:03 AM, Philippe Marschall <philippe.marschall@netcetera.ch> wrote:

On 13.06.14 01:41, Eliot Miranda wrote:

Hi All,

�� �� ��it gives me great pleasure to let you know that a spur-format trunk
Squeak image is finally available at
http://www.mirandabanda.org/files/Cog/SpurImages/. ��Spur VMs are
available at http://www.mirandabanda.org/files/Cog/VM/VM.r2987/.

���

I'm seeing a Seaside request handling benchmark going from 10k req/s to 11k req/s.
Don't be too quick to dismiss this as being IO-bound (being IO-bound is actually quite hard on Squeak/Pharo). During the benchmark Squeak fully saturates one core. It is hard to tell what the limiting factor for this benchmark actually is. But removing one or two String allocations from the request handling loop usually yields about 100 to 200 additional req/s.

That's good news at least. ��One thing you can try is the VMProfiler. ��It's an interactive Morphic application so it will try and open and may crash Load the VMProfiler and use it via

�� �� VMProfiler openInstance

�� �� �� �� spyOn: [...];

�� �� �� �� report: aStream.

e.g.��

VMProfiler openInstance

spyOn: [1 tinyBenchmarks];

report: (Transcript cr; yourself).

Transcript flush.

produces:

/Users/eliot/Cog/oscogvm/build.macos32x86/squeak.cog.spur/Fast.app/Contents/MacOS/Squeak ��6/17/2014��

eden size: 2,603,344 ��stack pages: 160 ��code size: 1,048,576

1 tinyBenchmarks

gc prior. ��clear prior. ��

6.298 seconds; sampling frequency 1473 hz

9231 samples in the VM (9275 samples in the entire program) ��99.53% of total

8798 samples in generated vm code 95.31% of entire vm (94.86% of total)

433 samples in vanilla vm code �� 4.69% of entire vm ( ��4.67% of total)

% of generated vm code (% of total) (samples) (cumulative)

61.29% �� ��(58.13%) Integer>>benchFib (5392) (61.29%)

13.47% �� ��(12.78%) Integer>>benchmark (1185) (74.76%)

11.48% �� ��(10.89%) Object>>at:put: (1010) (86.24%)

�� 9.60% �� ��( ��9.11%) SmallInteger>>+ (845) (95.84%)

�� 3.99% �� ��( ��3.78%) Object>>at: (351) (99.83%)

�� 0.07% �� ��( ��0.06%) ceBaseFram...Trampoline(6) (99.90%)

�� 0.03% �� ��( ��0.03%) ceMethodAbort0Args (3) (99.93%)

�� 0.03% �� ��( ��0.03%) Sequenceabl...om:to:put: (3) (99.97%)

�� 0.02% �� ��( ��0.02%) Magnitude>>min: (2) (99.99%)

�� 0.01% �� ��( ��0.01%) ceEnterCog...ceiverReg (1) (100.0%)

% of vanilla vm code (% of total) (samples) (cumulative)

32.33% �� ��( ��1.51%) primitiveStringReplace (140) (32.33%)

24.25% �� ��( ��1.13%) copyAndForward (105) (56.58%)

13.63% �� ��( ��0.64%) marryFrameSP (59) (70.21%)

10.85% �� ��( ��0.51%) instantiateClassindexableSize (47) (81.06%)

�� 3.46% �� ��( ��0.16%) ceBaseFrameReturn (15) (84.53%)

�� 2.08% �� ��( ��0.10%) scavengeLoop (9) (86.61%)

�� 1.62% �� ��( ��0.08%) checkForEvent...ontextSwitch (7) (88.22%)

�� 1.39% �� ��( ��0.06%) externalEnsureIsBaseFrame (6) (89.61%)

�� 1.39% �� ��( ��0.06%) voidVMStateForSn...nalPrimitivesIf(6) (90.99%)

�� 1.15% �� ��( ��0.05%) mapInterpreterOops (5) (92.15%)

�� 1.15% �� ��( ��0.05%) returnToExecuti...tContextSwitch(5) (93.30%)

�� 1.15% �� ��( ��0.05%) scavengeReferentsOf (5) (94.46%)

�� 0.92% �� ��( ��0.04%) handleStackOverflow (4) (95.38%)

�� 0.92% �� ��( ��0.04%) signed64BitIntegerFor (4) (96.30%)

�� 0.46% �� ��( ��0.02%) primitiveShortAt (2) (96.77%)

�� 0.46% �� ��( ��0.02%) ceNonLocalReturn (2) (97.23%)

�� 0.23% �� ��( ��0.01%) gMoveCwR (1) (97.46%)

�� 0.23% �� ��( ��0.01%) genInnerPrimit...CharacterinReg (1) (97.69%)

�� 0.23% �� ��( ��0.01%) genPrimitiveMultiply (1) (97.92%)

�� 0.23% �� ��( ��0.01%) primitiveInflateDecompressBlock(1) (98.15%)

�� 0.23% �� ��( ��0.01%) primitiveNewWithArg (1) (98.38%)

�� 0.23% �� ��( ��0.01%) primitiveTestAnd...fCriticalSection(1) (98.61%)

�� 0.23% �� ��( ��0.01%) processWeaklings (1) (98.85%)

�� 0.23% �� ��( ��0.01%) scavengingGCTenuringIf (1) (99.08%)

�� 0.23% �� ��( ��0.01%) updateMaybeObjRefAt (1) (99.31%)

�� 0.23% �� ��( ��0.01%) wakeHighestPriority (1) (99.54%)

�� 0.23% �� ��( ��0.01%) ceCannotResume (1) (99.77%)

�� 0.23% �� ��( ��0.01%) ioPositionOfWindowSetxy (1) (100.0%)

**Memory**

old +574,744 bytes

**GCs**

full 0 totalling 0ms (0% elapsed time)

scavenges 330 totalling 93ms (1.477% elapsed time), avg 0.282ms

tenures 0

root table 0 overflows

**Compiled Code Compactions**

0 totalling 0ms (0% elapsed time)

**Events**

Process switches 66 (10 per second)

ioProcessEvents calls 314 (50 per second)

Interrupt checks 3462 (550 per second)

Event checks 3585 (569 per second)

Stack overflows 421897 (66989 per second)

Stack page divorces 0 (0 per second)

�� �� �� ����

While this profile is flat, it does show where the VM is spending its time, and since the VM is not something with deep call chains, this view is the most useful I have.

The VMProfiler is part of the CogTools package at��http://source.squeak.org/VMMaker.

P.S. Extending the size of the DefaultTabsArray will result in a less cramped report.

HTH

Eliot