[Vm-dev] Re: [Pharo-dev] Spur Squeak Trunk Image Available

Eliot Miranda eliot.miranda at gmail.com
Tue Jun 17 17:29:13 UTC 2014


Hi Philippe,


On Tue, Jun 17, 2014 at 1:03 AM, Philippe Marschall <
philippe.marschall at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.squeakfoundation.org/pipermail/vm-dev/attachments/20140617/bbdab638/attachment-0001.htm


More information about the Vm-dev mailing list