Hi,

that did the trick. An over 20 times improvement.

So the culprit is mixed Integer and Float arithmetic.

My code is:

ml := Multiline1 new.
ml station: #futm40 testRepeat: 1.
ml station: #final testRepeat: 1.
time := 0.
1 to: 864000 do: [:i|
     ml doOneStep: time.
     i \\ 50 = 0 ifTrue: [ml canEnterNewRack ifTrue:
             [ml addRack: (B8DutRack fullOfB8MostCto) time: time].
         (ml canRemoveTestedRack: time) ifTrue:
             [ml removeRack: time]].
     time := time + 1].

I changed time into a Float. In the Tally you will find 
...canStartNextTest: time which does ^time > (testStart + testDuration)

testDuration is Float, time was Integer resulting in two conversions.

So you can print this snippet ant then change time to anInteger:
Time millisecondsToRun: [
|time testStart testDuration|
time := 0.0.
testDuration := 0.2.
1 to: 100000 do: [:i|
     testStart := time - 1.
     time > (testStart + testDuration).
     time := time + 1.0]]

In 3.8 the same operation brought down the timr from 158 to 139 seconds.


Am 27.09.2013 14:20, schrieb Herbert König:
> Hi Nicolas,
>
> I don't print Floats consciously. Basically I do message sends, 
> iterate over collections and some mixed Integer and Float arithmetic.
>
> This may be where the bitShift originates from. I'll make it all Float 
> to confirm the issue.
>
> For the interested, I simulate a production line in one second steps 
> (hence integer) but internally the times are Floats.
>
> Then I'll follow David's advice and report back.
>
> Attached are the spy results.
>
>
> Am 27.09.2013 13:06, schrieb Nicolas Cellier:
>> Hi Herbert,
>> you can send the tally or a code snippet if you can isolate the Pb.
>> Something that is less efficient in 4.x trunk image (but correct) is 
>> printing Float.
>> This is because we now print the minimal decimal representation that 
>> can be re-interpreted unchanged, while we formerly printed an 
>> approximate decimal representation that would not - several different 
>> Float did have the same printString.
>> Otherwise, there can be some other change...
>> Also you'd better use the advanced tally from Andreas Raab if you are 
>> using COG, because it's more accurate
>> (I do not remember the details, where to find it, etc...).
>>
>>
>> 2013/9/27 Herbert König <herbertkoenig at gmx.net 
>> <mailto:herbertkoenig at gmx.net>>
>>
>>     Hi Folks,
>>
>>     I'm doing some simulation in Squeak 3.8 and as some tests ran
>>     over two minutes I decided to try a more recent image with cog vm.
>>
>>     To my surprise 4.4 took around 5 times as long as 3.8. I believe
>>     I do nothing out of the ordinary here. Time is spent in:
>>     24% SmallInteger>>negative; 22% SmallInteger>>bitShift: (I don't
>>     use bitShift: explicitly) and 20% Array>> collect:
>>
>>     Which image and VM should I use to verify this before sending the
>>     complete message tallies?
>>
>>     Cheers
>>
>>     Herbert
>>
>>     I used the following recent image / vm:
>>     Image
>>     -----
>>     C:\daten\Squeak\4_4Dev\Squeak4.4-DCSE.image
>>     Squeak4.4
>>     latest update: #12333
>>     Current Change Set: Knacken mit APX
>>     Image format 6505 (32 bit)
>>
>>     Virtual Machine
>>     ---------------
>>     C:\daten\Squeak\4_4Dev\Squeak.exe
>>     Croquet Closure Cog VM [CoInterpreter VMMaker.oscog-eem.302]
>>     Win32 built on Jul 15 2013 15:35:13 Compiler: 3.4.4 (cygming
>>     special, gdc 0.12, using dmd 0.125)
>>     platform sources revision VM: r2749
>>     http://www.squeakvm.org/svn/squeak/branches/Cog Plugins: r2545
>>     http://squeakvm.org/svn/squeak/trunk/platforms/Cross/plugins
>>     CoInterpreter VMMaker.oscog-eem.302 uuid:
>>     2ac39432-ac54-4584-964e-b129c90792f4 Jul 15 2013
>>     StackToRegisterMappingCogit VMMaker.oscog-eem.302 uuid:
>>     2ac39432-ac54-4584-964e-b129c90792f4 Jul 15 2013
>>
>>
>>
>>
>
>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.squeakfoundation.org/pipermail/squeak-dev/attachments/20130927/63835e01/attachment.htm