2014/1/13 Frank Shearar <frank.shearar at gmail.com>

> On 11 January 2014 22:55, Frank Shearar <frank.shearar at gmail.com> wrote:
> > On 11 January 2014 19:19, tim Rowledge <tim at rowledge.org> wrote:
> >>
> >> On 11-01-2014, at 6:29 AM, Frank Shearar <frank.shearar at gmail.com>
> wrote:
> >>
> >>> A bunch of the Trait tests fail, despite no one having worked on the
> >>> Traits code in quite a while. The symptom is that the tests time out
> >>> [1]. I've tried to debug some, only to find that they pass. For
> >>> instance, <timeout: 60> sometimes "fixes" the tests.
> >>>
> >>> But the tests shouldn't be failing. Any takers?
> >>
> >> I noticed similar issues when running test on a Pi; being a relatively
> slow machine it takes longer to do some things and needed a larger timeout
> value.
> >>
> >> If tests that used to run within the time are now taking longer but
> still pass if given enough time, that implies to me that either
> >> a) the tests are being run on a slower machine due to some system
> configuration change (are other jobs also running and taking time?)
> >> b) something has changed in the execution path to slow down the tested
> code. Which obviously, ought not be the case.
> >
> > They time out on my beefy work laptop: a 2.7 GHz machine. That's
> > probably a higher spec machine than the build server.
> >
> > If I was a betting man I'd be inclined to put my money on (b).
>
> Attached is the output of MessageTally spyOn: [[TraitCompositionTest
> debug: #testAliasCompositions] on: TestFailure do: [#fail]], after
> adding <timeout: 60> to the test.
>
> The leaves are very interesting:
>
> **Leaves**
> 43.1% {28650ms} CompiledMethod>>originalTraitMethod:
> 36.9% {24505ms} Text>>size
> 9.7% {6425ms} Delay>>wait
> 3.4% {2239ms} SecurityManager class>>default
> 1.1% {749ms} CompiledMethod>>checkOKToAdd:at:
>
> _24 seconds_ in Text >> #size ?! Also,
> CompiledMethod>>originalTraitMethod: hasn't changed in 4 years. In
> fact the only things that have changed, that I can see, in the code
> path are Chris Muller's fixing of TestCase >> #debug and Nicolas
> Cellier's cleanup of the Compiler API. Nothing looks even remotely
> capable of slowing stuff down this dramatically.
>
> frank
>
> I don't get same figures here:

1st run:
**Leaves**
50.5% {3145ms} CompiledMethod>>originalTraitMethod:
18.1% {1125ms} Delay>>wait
11.8% {731ms} MultiByteFileStream>>nextPut:
5.1% {316ms} Trait(ClassDescription)>>organization
3.3% {206ms} MultiByteFileStream(StandardFileStream)>>open:forWrite:
1.7% {108ms} CompiledMethodWithNode>>selector
1.1% {67ms} ByteSymbol(Symbol)>>=

2nd run:

**Leaves**
50.5% {1991ms} CompiledMethod>>originalTraitMethod:
15.7% {617ms} MultiByteFileStream>>nextPut:
8.8% {346ms} Delay>>wait
4.6% {180ms} MultiByteFileStream(StandardFileStream)>>open:forWrite:
3.9% {153ms} Trait(ClassDescription)>>organization
2.3% {92ms} ByteSymbol(Symbol)>>=
1.5% {59ms} WeakArray class>>finalizationProcess
1.4% {54ms} CompiledMethodWithNode>>selector
1.1% {42ms} Array(SequenceableCollection)>>indexOf:startingAt:ifAbsent:

Hmm, great variations between 2 runs?
I also note presence of AnObsoleteC1/2 as large consumers... Not that
healthy.

With an AndreasSystemProfiler, here are the leaves:

1st run:
**Leaves**
57.1 (2,518)  Array  elementsForwardIdentityTo:
16.4 (722)  StandardFileStream  primWrite:from:startingAt:count:
6.5 (288)  Symbol  flushCache
5.7 (252)  StandardFileStream  primOpen:writable:

2nd run:
**Leaves**
64.8 (4,436)  Array  elementsForwardIdentityTo:
17.3 (1,183)  StandardFileStream  primWrite:from:startingAt:count:
4.6 (318)  Symbol  flushCache
4.1 (282)  StandardFileStream  primOpen:writable:

Though I failed to find the direct call to elementsForwardIdentityTo: in
the send chain (probably thru becomeForward:)...
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.squeakfoundation.org/pipermail/squeak-dev/attachments/20140113/2af57f8c/attachment.htm