Cog VM Performance
Locked
12
12
 
|
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 |
|
|
Hi Herbert, Something that is less efficient in 4.x trunk image (but correct) is printing Float.you can send the tally or a code snippet if you can isolate the Pb. 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. (I do not remember the details, where to find it, etc...). 2013/9/27 Herbert König <[hidden email]> Hi Folks, |
|
|
https://github.com/squeak-smalltalk/squeak-ci/blob/master/package-load-scripts/AndreasSystemProfiler.st
:) Installer squeakmap update; addPackage: 'AndreasSystemProfiler (head)'; install. On 27 September 2013 12:06, Nicolas Cellier <[hidden email]> wrote: > 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 <[hidden email]> >> >> 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 >> > > > > |
|
|
In reply to this post by Herbert König
It seems likely that the difference will be something in the image (4.4 versus
3.8) as opposed to something in the VM (Cog versus interpreter). You should be able to confirm this by running the tests with an newer interpreter VM from http://squeakvm.org/win32/. You can use that VM to run both the 3.8 and the 4.4 image. Assuming that the difference is related to the image, and if 4.4 with Cog is five times slower than 3.8 in your tests, then I would expect that 4.4 with the interpreter should be about ten times (!) slower than 3.8 with the interpreter. If that is the case, then it should be easy to find the difference using a profiler. Andreas' high performance profiler is currently available only for Cog, so you are limited to using use the normal profiler when running with interpreter VM. But if you can confirm that the issue is in the image, then you can use Cog with Andreas profiler to do the detailed profiling. Dave On Fri, Sep 27, 2013 at 12:26:32PM +0200, Herbert K?nig wrote: > 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 |
|
|
In reply to this post by Frank Shearar-3
Hi,
thanks that worked like a charm. Actually like a charm over a 60kBit line. Googling is no fun under these conditions. But the landscape is nice in rural Bavaria :-)) AndrasSystemProfiler is running, I'll reply to Nicolas with the results. Cheers, Herbert Am 27.09.2013 13:21, schrieb Frank Shearar: > Installer squeakmap > update; > addPackage: 'AndreasSystemProfiler (head)'; > install. |
|
|
In reply to this post by Nicolas Cellier
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:
|
Spy Results.text (14K) |
|
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, |
|
|
In reply to this post by David T. Lewis
Hi David,
i checked with this VM and it is a VM issue. In the interpreter VM all images take very similar time while the new image with the Cog VM is dramatically slow with integer to float conversions. The snipped I sent in the other post is sufficient to show the effect. Thanks to all who gave me tips. I happily use the Cog VM with Float and get an improvement from above two minutes to 30 seconds without the tally. Cheers, Herbert Am 27.09.2013 14:04, schrieb David T. Lewis: > It seems likely that the difference will be something in the image (4.4 versus > 3.8) as opposed to something in the VM (Cog versus interpreter). You should > be able to confirm this by running the tests with an newer interpreter VM > from http://squeakvm.org/win32/. You can use that VM to run both the 3.8 and > the 4.4 image. > > Assuming that the difference is related to the image, and if 4.4 with Cog > is five times slower than 3.8 in your tests, then I would expect that 4.4 > with the interpreter should be about ten times (!) slower than 3.8 with > the interpreter. > > If that is the case, then it should be easy to find the difference using > a profiler. Andreas' high performance profiler is currently available only > for Cog, so you are limited to using use the normal profiler when running > with interpreter VM. But if you can confirm that the issue is in the image, > then you can use Cog with Andreas profiler to do the detailed profiling. > > Dave > > > On Fri, Sep 27, 2013 at 12:26:32PM +0200, Herbert K?nig wrote: >> 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 |
|
|
I've published a change to accelerate mixed integer/float comparisons in COG (comparisons between float and int) Search for COG issues at https://code.google.com/p/cog/issues/detail?id=41&can=1&q=floatIt might have been integrated in pharo VM, but not yet by Eliot in official cog VM From there might come the bitShift... 2013/9/27 Herbert König <[hidden email]> Hi David, |
|
|
In reply to this post by Herbert König
Following up Herbert's question, I wrote:
compareTiming: a to: b " ---interpreter vm (5.7.4.1) --------- Float compareTiming: 1 to: 1.0 ==> 719 Float compareTiming: 1.0 to: 1.0 ==> 991 Float compareTiming: 1 to: 1 ==> 312 Float compareTiming: 1.0 to: 1 ==> 686 ---cog vm (2749)--------- Float compareTiming: 1 to: 1.0 ==> 28162 Float compareTiming: 1.0 to: 1.0 ==> 148 Float compareTiming: 1 to: 1 ==> 97 Float compareTiming: 1.0 to: 1 ==> 179 " ^[1000000 timesRepeat: [ a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. a < b. ]] timeToRun So, some obvious questions: - in the interpreter vm, why is comparing two floats slower that an integer and a float? - what's up with Cog? Three tests are faster by the expected ratio and one took a real dive. Also, the profiler Herbert used could use some attention to the NewFloat printing: 99.9 (898,069) Multiline1 doOneStep: 77.30000000000001 (694,902) Multiline1 [HkTestLine] doTests: 73.8 (663,438) HkRunin [HkTestStation] canStartNextTest: Cheers, Bob |
|
|
Hi Bob, thanks for the heads up! I'll take a look at this ASAP, but ephemerons in the Spur scavenger come first.
On Fri, Sep 27, 2013 at 11:12 AM, Bob Arning <[hidden email]> wrote:
best, Eliot
|
|
|
Again, this is a resolved problem, see https://code.google.com/p/cog/issues/detail?id=41&can=1&q=float On my home brewed COG, I have Home brewed COG VM -> 156 157 2013/9/27 Eliot Miranda <[hidden email]>
|
|
|
The MC packages are also available at http://smalltalkhub.com/#!/~nice/NiceVMExperiments
2013/9/27 Nicolas Cellier <[hidden email]>
|
|
|
And the exact MC version would be http://smalltalkhub.com/#!/~nice/NiceVMExperiments/versions/VMMaker.oscog-nice.243 2013/9/27 Nicolas Cellier <[hidden email]>
|
|
|
Thanks Nicolas! On Fri, Sep 27, 2013 at 1:13 PM, Nicolas Cellier <[hidden email]> wrote:
best, Eliot
|
|
|
In reply to this post by Bob Arning-2
I thought I'd extend the test to an older
squeak&vm
---interpreter vm (3.8.12) squeak 3.2 --------- Float compareTiming: 1 to: 1.0 ==> 496 Float compareTiming: 1.0 to: 1.0 ==> 761 Float compareTiming: 1 to: 1 ==> 225 Float compareTiming: 1.0 to: 1 ==> 494 ---interpreter vm (5.7.4.1) squeak 4.5 --------- Float compareTiming: 1 to: 1.0 ==> 719 Float compareTiming: 1.0 to: 1.0 ==> 991 Float compareTiming: 1 to: 1 ==> 312 Float compareTiming: 1.0 to: 1 ==> 686 The old one wins. Cheers, Bob On 9/27/13 2:12 PM, Bob Arning wrote:
Following up Herbert's question, I wrote: |
|
|
On Fri, Sep 27, 2013 at 05:51:33PM -0400, Bob Arning wrote:
> I thought I'd extend the test to an older squeak&vm > > ---interpreter vm (3.8.12) squeak 3.2 --------- > Float compareTiming: 1 to: 1.0 ==> 496 > Float compareTiming: 1.0 to: 1.0 ==> 761 > Float compareTiming: 1 to: 1 ==> 225 > Float compareTiming: 1.0 to: 1 ==> 494 > ---interpreter vm (5.7.4.1) squeak 4.5 --------- > Float compareTiming: 1 to: 1.0 ==> 719 > Float compareTiming: 1.0 to: 1.0 ==> 991 > Float compareTiming: 1 to: 1 ==> 312 > Float compareTiming: 1.0 to: 1 ==> 686 > > The old one wins. > > Cheers, > Bob (CC to vm-dev list) I get different results on my Linux PC. - Squeak 3.2 with interpreter VM compiled by Ian, circa 2006: Float compareTiming: 1 to: 1.0 ==> 1041 Float compareTiming: 1.0 to: 1.0 ==> 1432 Float compareTiming: 1 to: 1 ==> 390 Float compareTiming: 1.0 to: 1 ==> 1108 - Squeak 4.4 with Ian's 4.4.7-2357 VM, circa 2012: Float compareTiming: 1 to: 1.0 ==> 840 Float compareTiming: 1.0 to: 1.0 ==> 1176 Float compareTiming: 1 to: 1 ==> 420 Float compareTiming: 1.0 to: 1 ==> 836 - Squeak 4.4 with my locally compiled 4.12.6.2787 VM (because I cannot use Ian's 4.10.2.2614 from squeakvm.org due to a Linux glib compatibility problem for the outdated Linux on my PC): Float compareTiming: 1 to: 1.0 ==> 782 Float compareTiming: 1.0 to: 1.0 ==> 1077 Float compareTiming: 1 to: 1 ==> 461 Float compareTiming: 1.0 to: 1 ==> 789 Perhaps there are other factors on the Mac platform (compiler changes, etc) that are affecting the performance. Could you try Squeak 4.4 with Ian's unix Mac VM from squeakvm.org and see if you get different results? http://squeakvm.org/unix/release/Squeak-4.10.2.2614-darwin10.8.0_i386.tar.gz Dave > On 9/27/13 2:12 PM, Bob Arning wrote: > >Following up Herbert's question, I wrote: > > > >compareTiming: a to: b > >" > >---interpreter vm (5.7.4.1) --------- > >Float compareTiming: 1 to: 1.0 ==> 719 > >Float compareTiming: 1.0 to: 1.0 ==> 991 > >Float compareTiming: 1 to: 1 ==> 312 > >Float compareTiming: 1.0 to: 1 ==> 686 > >---cog vm (2749)--------- > >*Float compareTiming: 1 to: 1.0 ==> 28162* > >Float compareTiming: 1.0 to: 1.0 ==> 148 > >Float compareTiming: 1 to: 1 ==> 97 > >Float compareTiming: 1.0 to: 1 ==> 179 > >" > > > >^[1000000 timesRepeat: [ > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > > a < b. > >]] timeToRun > > > >So, some obvious questions: > >- in the interpreter vm, why is comparing two floats slower that an > >integer and a float? > >- what's up with Cog? Three tests are faster by the expected ratio and > >one took a real dive. > > > >Also, the profiler Herbert used could use some attention to the > >NewFloat printing: > > > >99.9 (898,069) Multiline1 doOneStep: > >*77.30000000000001* (694,902) Multiline1 [HkTestLine] doTests: > > 73.8 (663,438) HkRunin [HkTestStation] canStartNextTest: > > > >Cheers, > >Bob > > > > |
|
|
I'm not familiar enough with unix to know what
to do with that. It decompresses to a folder hierarchy; not clear
what the magic button is.
Cheers, Bob On 9/27/13 9:08 PM, David T. Lewis
wrote:
Could you try Squeak 4.4 with Ian's unix Mac VM from squeakvm.org and see if you get different results? http://squeakvm.org/unix/release/Squeak-4.10.2.2614-darwin10.8.0_i386.tar.gz |
|
|
In reply to this post by David T. Lewis
FWIW, I reran my 3 tests and the gap in the 2
interpreter versions narrowed, but old is still faster. And I
still can't guess why a pure float compare is slower than a
float-int compare.
Cheers, Bob Squeak3.2gamma(interp 3.8.12) 1 < 1.0 = #(507 506 500) 1.0 < 1.0 = #(764 776 768) 1 < 1 = #(230 234 238) 1.0 < 1 = #(501 503 496) Squeak4.5 (cog) 1 < 1.0 = #(23562 28802 28797) 1.0 < 1.0 = #(122 122 125) 1 < 1 = #(87 91 90) 1.0 < 1 = #(151 149 149) Squeak4.5(interp 5.7.4.1) 1 < 1.0 = #(618 612 605) 1.0 < 1.0 = #(845 845 856) 1 < 1 = #(269 272 269) 1.0 < 1 = #(586 581 591) On 9/27/13 9:08 PM, David T. Lewis
wrote:
On Fri, Sep 27, 2013 at 05:51:33PM -0400, Bob Arning wrote:I thought I'd extend the test to an older squeak&vm ---interpreter vm (3.8.12) squeak 3.2 --------- Float compareTiming: 1 to: 1.0 ==> 496 Float compareTiming: 1.0 to: 1.0 ==> 761 Float compareTiming: 1 to: 1 ==> 225 Float compareTiming: 1.0 to: 1 ==> 494 ---interpreter vm (5.7.4.1) squeak 4.5 --------- Float compareTiming: 1 to: 1.0 ==> 719 Float compareTiming: 1.0 to: 1.0 ==> 991 Float compareTiming: 1 to: 1 ==> 312 Float compareTiming: 1.0 to: 1 ==> 686 The old one wins. Cheers, Bob(CC to vm-dev list) I get different results on my Linux PC. - Squeak 3.2 with interpreter VM compiled by Ian, circa 2006: Float compareTiming: 1 to: 1.0 ==> 1041 Float compareTiming: 1.0 to: 1.0 ==> 1432 Float compareTiming: 1 to: 1 ==> 390 Float compareTiming: 1.0 to: 1 ==> 1108 - Squeak 4.4 with Ian's 4.4.7-2357 VM, circa 2012: Float compareTiming: 1 to: 1.0 ==> 840 Float compareTiming: 1.0 to: 1.0 ==> 1176 Float compareTiming: 1 to: 1 ==> 420 Float compareTiming: 1.0 to: 1 ==> 836 - Squeak 4.4 with my locally compiled 4.12.6.2787 VM (because I cannot use Ian's 4.10.2.2614 from squeakvm.org due to a Linux glib compatibility problem for the outdated Linux on my PC): Float compareTiming: 1 to: 1.0 ==> 782 Float compareTiming: 1.0 to: 1.0 ==> 1077 Float compareTiming: 1 to: 1 ==> 461 Float compareTiming: 1.0 to: 1 ==> 789 Perhaps there are other factors on the Mac platform (compiler changes, etc) that are affecting the performance. Could you try Squeak 4.4 with Ian's unix Mac VM from squeakvm.org and see if you get different results? http://squeakvm.org/unix/release/Squeak-4.10.2.2614-darwin10.8.0_i386.tar.gz DaveOn 9/27/13 2:12 PM, Bob Arning wrote: |
|
|
endianness... in old vm float were stored in big endian, so converting one int->float is faster than reversing float endianness (as it is programmed in the vm at least) 2013/9/28 Bob Arning <[hidden email]>
|
«
Return to Squeak - Dev
|
1 view|%1 views
| Free forum by Nabble | Edit this page |