On Tue, Jun 17, 2014 at 10:29 AM, Eliot Miranda <eliot.mira...@gmail.com> wrote:
> Hi Philippe, > > > On Tue, Jun 17, 2014 at 1:03 AM, Philippe Marschall < > philippe.marsch...@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 > What I meant to say is that it may fail if the morph can't open. It doesn't routinely fail :-) > > 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 > -- best, Eliot
