Never ending BlockClosure>>benchFor:
Hello, I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut. benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue? I will continue trying to isolate the problem, but maybe you have some idea. * the conditions to reproduce are: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*' Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior... Regards, Martin
I also tried with a modified #benchFor: that doesn't use a forked block, and that fixed the issue. benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count started endTime | count := 0. started := Time millisecondClockValue. endTime := started + duration asMilliSeconds. [ Time millisecondClockValue > endTime ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself Do you think comparing each time, instead of using #fork is a bad idea? That's how it was working #bench in Pharo 3. Martin On Thu, Nov 12, 2015 at 2:42 AM, Martin Dias <tinchodias@gmail.com> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
Hi Martin, Here is the relevant issue for the last change in that method: https://pharo.fogbugz.com/f/cases/14989/Improve-and-simplify-BlockClosure-be... IIRC the timing change was done in Squeak too, not the BenchmarkResult object. Maybe the old code is more reliable, thing is, the CI machines being VM's sometimes act very weird with respect to timing and clocks. Sven
On 12 Nov 2015, at 02:45, Martin Dias <tinchodias@gmail.com> wrote:
I also tried with a modified #benchFor: that doesn't use a forked block, and that fixed the issue.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count started endTime | count := 0. started := Time millisecondClockValue. endTime := started + duration asMilliSeconds. [ Time millisecondClockValue > endTime ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Do you think comparing each time, instead of using #fork is a bad idea? That's how it was working #bench in Pharo 3.
Martin
On Thu, Nov 12, 2015 at 2:42 AM, Martin Dias <tinchodias@gmail.com> wrote: Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
Hi Sven, El 12/11/2015 9:32, "Sven Van Caekenberghe" <sven@stfx.eu> escribió:
Hi Martin,
Here is the relevant issue for the last change in that method:
https://pharo.fogbugz.com/f/cases/14989/Improve-and-simplify-BlockClosure-be...
IIRC the timing change was done in Squeak too, not the BenchmarkResult object.
Maybe the old code is more reliable, thing is, the CI machines being VM's sometimes act very weird with respect to timing and clocks.
Thanks for the pointer, I like the improvements of that slice: using the fork instead of comparing on each run, the new API, the new object to model the benchmark. Any suggestion of what to do with my problem? If I skip #testBenchFor, then no problem. So, it's the only test in the whole image that presents this problem. Ah, and this happens locally in my Mac OS too, not only in the CI. Martin
But how could Epicea have an impact on that part ? That is the question. Unless someone objects, I would not say that this should hold integration. There will be much more work to do after integration when people start using it ;-)
On 12 Nov 2015, at 10:40, Martin Dias <tinchodias@gmail.com> wrote:
Hi Sven,
El 12/11/2015 9:32, "Sven Van Caekenberghe" <sven@stfx.eu> escribió: Hi Martin,
Here is the relevant issue for the last change in that method:
https://pharo.fogbugz.com/f/cases/14989/Improve-and-simplify-BlockClosure-be...
IIRC the timing change was done in Squeak too, not the BenchmarkResult object.
Maybe the old code is more reliable, thing is, the CI machines being VM's sometimes act very weird with respect to timing and clocks.
Thanks for the pointer, I like the improvements of that slice: using the fork instead of comparing on each run, the new API, the new object to model the benchmark.
Any suggestion of what to do with my problem? If I skip #testBenchFor, then no problem. So, it's the only test in the whole image that presents this problem.
Ah, and this happens locally in my Mac OS too, not only in the CI.
Martin
On 12 Nov 2015, at 10:49, Sven Van Caekenberghe <sven@stfx.eu> wrote:
But how could Epicea have an impact on that part ?
That is the question.
Unless someone objects, I would not say that this should hold integration. There will be much more work to do after integration when people start using it ;-)
Unless #benchFor: is broken for everyone, everywhere, of course
On 12 Nov 2015, at 10:40, Martin Dias <tinchodias@gmail.com> wrote:
Hi Sven,
El 12/11/2015 9:32, "Sven Van Caekenberghe" <sven@stfx.eu> escribió: Hi Martin,
Here is the relevant issue for the last change in that method:
https://pharo.fogbugz.com/f/cases/14989/Improve-and-simplify-BlockClosure-be...
IIRC the timing change was done in Squeak too, not the BenchmarkResult object.
Maybe the old code is more reliable, thing is, the CI machines being VM's sometimes act very weird with respect to timing and clocks.
Thanks for the pointer, I like the improvements of that slice: using the fork instead of comparing on each run, the new API, the new object to model the benchmark.
Any suggestion of what to do with my problem? If I skip #testBenchFor, then no problem. So, it's the only test in the whole image that presents this problem.
Ah, and this happens locally in my Mac OS too, not only in the CI.
Martin
The fun thing is that I now get the same problem when integrating the GT Tools update. After doing the update for issue 16957, the test run hangs with starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')" Martin On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority -
started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started)
milliSeconds;
yourself
Strangely, I verified with several #logCr that the forked block starts,
but the #wait never ends.
---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification. I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add 2 seconds asDelay wait. Smalltalk garbageCollect. or Smalltalk garbageCollect. 2 seconds asDelay wait. after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point. I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start. For testing I used the following command line: ./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)" Install Epicea with ./pharo Pharo.image get Epicea 6.5 To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning). HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu <mailto:sven@stfx.eu>> wrote: Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr <mailto:marcus.denker@inria.fr>> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
thanks max this is great to have your support. Le 12/11/15 21:21, Max Leske a écrit :
I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification.
I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add
2 seconds asDelay wait. Smalltalk garbageCollect.
or
Smalltalk garbageCollect. 2 seconds asDelay wait.
after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point.
I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start.
For testing I used the following command line:
./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)"
Install Epicea with
./pharo Pharo.image get Epicea 6.5
To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning).
HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu <mailto:sven@stfx.eu>> wrote:
Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
> On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr <mailto:marcus.denker@inria.fr>> wrote: > > The fun thing is that I now get the same problem when integrating the GT Tools update. > > After doing the update for issue 16957, the test run hangs with > > starting testcase: BlockClosureTest>>testBenchFor ... > > >> On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote: >> >> Hello, >> >> I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut. >> >> benchFor: duration >> "Run me for duration and return a BenchmarkResult" >> >> "[ 100 factorial ] benchFor: 2 seconds" >> >> | count run started | >> count := 0. >> run := true. >> [ duration wait. run := false ] forkAt: Processor timingPriority - 1. >> started := Time millisecondClockValue. >> [ run ] whileTrue: [ self value. count := count + 1 ]. >> ^ BenchmarkResult new >> iterations: count; >> elapsedTime: (Time millisecondsSince: started) milliSeconds; >> yourself >> >> Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. >> ---> Maybe you see something I don't in the code. Any clue? >> >> I will continue trying to isolate the problem, but maybe you have some idea. >> >> * the conditions to reproduce are: >> 1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash >> 2) ./pharo Pharo.image get Epicea 6.5 >> 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*' >> >> Notes: >> - It doesn't hang when running from UI >> - it doesn't hang when running less tests, like: >> pharo Pharo.image test '^(?!Metacello)[E-L].*' >> - it *does* hang even when removing all Epicea tests >> - Epicea doesn't extend or override "kernel" behavior... >> >> Regards, >> Martin >
+1 Doru
On Nov 12, 2015, at 10:21 PM, stepharo <stepharo@free.fr> wrote:
thanks max this is great to have your support.
Le 12/11/15 21:21, Max Leske a écrit :
I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification.
I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add
2 seconds asDelay wait. Smalltalk garbageCollect.
or
Smalltalk garbageCollect. 2 seconds asDelay wait.
after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point.
I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start.
For testing I used the following command line:
./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)"
Install Epicea with
./pharo Pharo.image get Epicea 6.5
To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning).
HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote: Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
-- www.tudorgirba.com "To utilize feedback, you first have to acquire it."
Hi,
Any news on this?
Might be totally unrelated but I went back and searched for the the first
version where [1] blocks.
In my case the first version where it blocks is Pharo-40520. In Pharo-40519
it works ok.
40520 integrated https://pharo.fogbugz.com/f/cases/14993 which does a lot
of changes, but one changed that this issue did is introduced an async
tasks for updating the scrolling in inspector.
Next if in the latest version I change in
GLMScrollPaneBandBrick>>onChildrenLayouted the priority of asyncTask from
'Processor lowestPriority' to 'Processor userBackgroundPriority + 1'
then #testBenchFor does not block. If I change the priority to the initial
one it blocks again. At least on my machine this is consistent.
Not sure if this fixes the bug on the CI but I updated issue 16957
<https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> to
include this change.
Can you try to integrate the issue and see if it still blocks.
Cheers,
Andrei
[1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses:
{GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'.
CommandLineTestRunner runPackages: #('Kernel-Tests')"
On Thu, Nov 12, 2015 at 9:21 PM, Max Leske <maxleske@gmail.com> wrote:
> I found a single test method I could use to narrow down the problem (be
> aware that this might not work for you. I have other (fresh) images where
> the issue never occurs). The method I used
> is EpRedoAndUndoVisitorTest>>testClassModification.
>
> I was able to mitigate the hang by making a small modification to the
> method EpUndoVisitor>>visitClassModification: Simply add
>
> 2 seconds asDelay wait. Smalltalk garbageCollect.
>
> or
>
> Smalltalk garbageCollect. 2 seconds asDelay wait.
>
> after the compilation phase. My guess is, that announcements build up (a
> simple printout showed 1 announcement instance before and 74 instances
> after the #evaluate:) and do stuff in the system that influence the process
> scheduling. For instance, a lot of those announcements will probably be
> weak and need to be finalized at some point.
>
> I donât have enough experience with the ClassBuilder to go on hunting but
> this should hopefully give you a good head start.
>
>
>
> For testing I used the following command line:
>
> ./pharo found_case.image eval "CommandLineTestRunner runPackages:
> #('Epicea' 'Kernel-Testsâ)"
>
> Install Epicea with
>
> ./pharo Pharo.image get Epicea 6.5
>
>
> To isolate the test case I simply moved test classes from Epicea to a
> differently named package and once I had found the class I started
> excluding methods (e.g. with âself fail.â at the beginning).
>
>
> HTH,
> Max
>
>
>
>
> On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com> wrote:
>
> Yes! with Max Leske we have been isolating the problem and we realized
> that a fresh image was enough:
>
> 1)
> curl get.pharo.org/50+vm | bash
>
> 2)
> ./pharo Pharo.image eval "CommandLineTestRunner runClasses:
> {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'.
> CommandLineTestRunner runPackages: #('Kernel-Tests')"
>
> Martin
>
> On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu>
> wrote:
>
>> Then it must be that waiting on the delay never ends, which is probably a
>> problem all by itself.
>>
>> > On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr> wrote:
>> >
>> > The fun thing is that I now get the same problem when integrating the
>> GT Tools update.
>> >
>> > After doing the update for issue 16957, the test run hangs with
>> >
>> > starting testcase: BlockClosureTest>>testBenchFor ...
>> >
>> >
>> >> On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com> wrote:
>> >>
>> >> Hello,
>> >>
>> >> I'm trying to understand why this method hangs in certain conditions*.
>> What happens is that the #whileTrue: in the following method is never cut.
>> >>
>> >> benchFor: duration
>> >> "Run me for duration and return a BenchmarkResult"
>> >>
>> >> "[ 100 factorial ] benchFor: 2 seconds"
>> >>
>> >> | count run started |
>> >> count := 0.
>> >> run := true.
>> >> [ duration wait. run := false ] forkAt: Processor timingPriority
>> - 1.
>> >> started := Time millisecondClockValue.
>> >> [ run ] whileTrue: [ self value. count := count + 1 ].
>> >> ^ BenchmarkResult new
>> >> iterations: count;
>> >> elapsedTime: (Time millisecondsSince: started)
>> milliSeconds;
>> >> yourself
>> >>
>> >> Strangely, I verified with several #logCr that the forked block
>> starts, but the #wait never ends.
>> >> ---> Maybe you see something I don't in the code. Any clue?
>> >>
>> >> I will continue trying to isolate the problem, but maybe you have some
>> idea.
>> >>
>> >> * the conditions to reproduce are:
>> >> 1) curl get.pharo.org/50+vm | bash
>> >> 2) ./pharo Pharo.image get Epicea 6.5
>> >> 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
>> >>
>> >> Notes:
>> >> - It doesn't hang when running from UI
>> >> - it doesn't hang when running less tests, like:
>> >> pharo Pharo.image test '^(?!Metacello)[E-L].*'
>> >> - it *does* hang even when removing all Epicea tests
>> >> - Epicea doesn't extend or override "kernel" behavior...
>> >>
>> >> Regards,
>> >> Martin
>> >
>>
>>
>>
>
>
Very nice! I can confirm that this change does indeed help. Now the question becomes: why?
On 16 Nov 2015, at 14:12, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Hi,
Any news on this?
Might be totally unrelated but I went back and searched for the the first version where [1] blocks. In my case the first version where it blocks is Pharo-40520. In Pharo-40519 it works ok. 40520 integrated https://pharo.fogbugz.com/f/cases/14993 <https://pharo.fogbugz.com/f/cases/14993> which does a lot of changes, but one changed that this issue did is introduced an async tasks for updating the scrolling in inspector.
Next if in the latest version I change in GLMScrollPaneBandBrick>>onChildrenLayouted the priority of asyncTask from 'Processor lowestPriority' to 'Processor userBackgroundPriority + 1' then #testBenchFor does not block. If I change the priority to the initial one it blocks again. At least on my machine this is consistent.
Not sure if this fixes the bug on the CI but I updated issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> to include this change. Can you try to integrate the issue and see if it still blocks.
Cheers, Andrei
[1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
On Thu, Nov 12, 2015 at 9:21 PM, Max Leske <maxleske@gmail.com <mailto:maxleske@gmail.com>> wrote: I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification.
I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add
2 seconds asDelay wait. Smalltalk garbageCollect.
or
Smalltalk garbageCollect. 2 seconds asDelay wait.
after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point.
I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start.
For testing I used the following command line:
./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)"
Install Epicea with
./pharo Pharo.image get Epicea 6.5
To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning).
HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu <mailto:sven@stfx.eu>> wrote: Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr <mailto:marcus.denker@inria.fr>> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
Interestingly, if I change the delay in that method from 400 to 0 I get the same effect (namely, it doesnât hang). So maybe itâs a problem with delay scheduling from low priority processes?
On 16 Nov 2015, at 14:12, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Hi,
Any news on this?
Might be totally unrelated but I went back and searched for the the first version where [1] blocks. In my case the first version where it blocks is Pharo-40520. In Pharo-40519 it works ok. 40520 integrated https://pharo.fogbugz.com/f/cases/14993 <https://pharo.fogbugz.com/f/cases/14993> which does a lot of changes, but one changed that this issue did is introduced an async tasks for updating the scrolling in inspector.
Next if in the latest version I change in GLMScrollPaneBandBrick>>onChildrenLayouted the priority of asyncTask from 'Processor lowestPriority' to 'Processor userBackgroundPriority + 1' then #testBenchFor does not block. If I change the priority to the initial one it blocks again. At least on my machine this is consistent.
Not sure if this fixes the bug on the CI but I updated issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> to include this change. Can you try to integrate the issue and see if it still blocks.
Cheers, Andrei
[1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
On Thu, Nov 12, 2015 at 9:21 PM, Max Leske <maxleske@gmail.com <mailto:maxleske@gmail.com>> wrote: I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification.
I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add
2 seconds asDelay wait. Smalltalk garbageCollect.
or
Smalltalk garbageCollect. 2 seconds asDelay wait.
after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point.
I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start.
For testing I used the following command line:
./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)"
Install Epicea with
./pharo Pharo.image get Epicea 6.5
To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning).
HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu <mailto:sven@stfx.eu>> wrote: Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr <mailto:marcus.denker@inria.fr>> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
Also you do not have to run it from the command line to reproduce the error.
You can just execute in a playground:
CommandLineTestRunner runClasses: {GLMPagerMorphTest . GLMTreeMorphicTest.
GLMWatcherMorphicTest} named: 'x'. CommandLineTestRunner runPackages:
#('Kernel-Tests').
But if you run the same tests using a script then there is no block:
suite := TestSuite named: 'x'.
classes := {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest}
asSortedCollection: [ :a :b | a name <= b name ].
classes
do: [ :each | each addToSuiteFromSelectors: suite ].
runner := TestRunner new .
Author uniqueInstance
ifUnknownAuthorUse: 'hudson'
during: [ runner
runSuite: suite ].
On Mon, Nov 16, 2015 at 2:25 PM, Max Leske <maxleske@gmail.com> wrote:
> Interestingly, if I change the delay in that method from 400 to 0 I get
> the same effect (namely, it doesnât hang). So maybe itâs a problem with
> delay scheduling from low priority processes?
>
>
> On 16 Nov 2015, at 14:12, Andrei Chis <chisvasileandrei@gmail.com> wrote:
>
> Hi,
>
> Any news on this?
>
> Might be totally unrelated but I went back and searched for the the first
> version where [1] blocks.
> In my case the first version where it blocks is Pharo-40520.
> In Pharo-40519 it works ok.
> 40520 integrated https://pharo.fogbugz.com/f/cases/14993 which does a lot
> of changes, but one changed that this issue did is introduced an async
> tasks for updating the scrolling in inspector.
>
> Next if in the latest version I change in
> GLMScrollPaneBandBrick>>onChildrenLayouted the priority of asyncTask from
> 'Processor lowestPriority' to 'Processor userBackgroundPriority + 1'
> then #testBenchFor does not block. If I change the priority to the initial
> one it blocks again. At least on my machine this is consistent.
>
> Not sure if this fixes the bug on the CI but I updated issue 16957
> <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> to
> include this change.
> Can you try to integrate the issue and see if it still blocks.
>
> Cheers,
> Andrei
>
>
>
> [1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses:
> {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'.
> CommandLineTestRunner runPackages: #('Kernel-Tests')"
>
>
>
> On Thu, Nov 12, 2015 at 9:21 PM, Max Leske <maxleske@gmail.com> wrote:
>
>> I found a single test method I could use to narrow down the problem (be
>> aware that this might not work for you. I have other (fresh) images where
>> the issue never occurs). The method I used
>> is EpRedoAndUndoVisitorTest>>testClassModification.
>>
>> I was able to mitigate the hang by making a small modification to the
>> method EpUndoVisitor>>visitClassModification: Simply add
>>
>> 2 seconds asDelay wait. Smalltalk garbageCollect.
>>
>> or
>>
>> Smalltalk garbageCollect. 2 seconds asDelay wait.
>>
>> after the compilation phase. My guess is, that announcements build up (a
>> simple printout showed 1 announcement instance before and 74 instances
>> after the #evaluate:) and do stuff in the system that influence the process
>> scheduling. For instance, a lot of those announcements will probably be
>> weak and need to be finalized at some point.
>>
>> I donât have enough experience with the ClassBuilder to go on hunting but
>> this should hopefully give you a good head start.
>>
>
>
>>
>>
>> For testing I used the following command line:
>>
>> ./pharo found_case.image eval "CommandLineTestRunner runPackages:
>> #('Epicea' 'Kernel-Testsâ)"
>>
>> Install Epicea with
>>
>> ./pharo Pharo.image get Epicea 6.5
>>
>>
>> To isolate the test case I simply moved test classes from Epicea to a
>> differently named package and once I had found the class I started
>> excluding methods (e.g. with âself fail.â at the beginning).
>>
>>
>> HTH,
>> Max
>>
>>
>>
>>
>> On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com> wrote:
>>
>> Yes! with Max Leske we have been isolating the problem and we realized
>> that a fresh image was enough:
>>
>> 1)
>> curl get.pharo.org/50+vm | bash
>>
>> 2)
>> ./pharo Pharo.image eval "CommandLineTestRunner runClasses:
>> {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'.
>> CommandLineTestRunner runPackages: #('Kernel-Tests')"
>>
>> Martin
>>
>> On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu>
>> wrote:
>>
>>> Then it must be that waiting on the delay never ends, which is probably
>>> a problem all by itself.
>>>
>>> > On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr>
>>> wrote:
>>> >
>>> > The fun thing is that I now get the same problem when integrating the
>>> GT Tools update.
>>> >
>>> > After doing the update for issue 16957, the test run hangs with
>>> >
>>> > starting testcase: BlockClosureTest>>testBenchFor ...
>>> >
>>> >
>>> >> On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com> wrote:
>>> >>
>>> >> Hello,
>>> >>
>>> >> I'm trying to understand why this method hangs in certain
>>> conditions*. What happens is that the #whileTrue: in the following method
>>> is never cut.
>>> >>
>>> >> benchFor: duration
>>> >> "Run me for duration and return a BenchmarkResult"
>>> >>
>>> >> "[ 100 factorial ] benchFor: 2 seconds"
>>> >>
>>> >> | count run started |
>>> >> count := 0.
>>> >> run := true.
>>> >> [ duration wait. run := false ] forkAt: Processor timingPriority
>>> - 1.
>>> >> started := Time millisecondClockValue.
>>> >> [ run ] whileTrue: [ self value. count := count + 1 ].
>>> >> ^ BenchmarkResult new
>>> >> iterations: count;
>>> >> elapsedTime: (Time millisecondsSince: started)
>>> milliSeconds;
>>> >> yourself
>>> >>
>>> >> Strangely, I verified with several #logCr that the forked block
>>> starts, but the #wait never ends.
>>> >> ---> Maybe you see something I don't in the code. Any clue?
>>> >>
>>> >> I will continue trying to isolate the problem, but maybe you have
>>> some idea.
>>> >>
>>> >> * the conditions to reproduce are:
>>> >> 1) curl get.pharo.org/50+vm | bash
>>> >> 2) ./pharo Pharo.image get Epicea 6.5
>>> >> 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
>>> >>
>>> >> Notes:
>>> >> - It doesn't hang when running from UI
>>> >> - it doesn't hang when running less tests, like:
>>> >> pharo Pharo.image test '^(?!Metacello)[E-L].*'
>>> >> - it *does* hang even when removing all Epicea tests
>>> >> - Epicea doesn't extend or override "kernel" behavior...
>>> >>
>>> >> Regards,
>>> >> Martin
>>> >
>>>
>>>
>>>
>>
>>
>
>
We investigated more with Max and Aliaksey, and managed to reduce the bug to executing just two tests. Just it would great if somebody else could reproduce it. You need to run commands only from console and save and quit the image after a change. The tests that need to be executed are GTInspectorExamplesTest>>#testAllExamples and BlockClosureTest>>#testBenchFor. Download the latest pharo image and remove GTInspectorExamplesTest>>#testGlobals, so that GTInspectorExamplesTest has one single test. In GTInspectorExamplesTest>>#testAllExamples replace 'Object withAllSubclasses' with 'Dictionary asOrderedCollection' (it's not the actual examples that cause problems). If you execute now the tests, BlockClosureTest>>#testBenchFor will block for around 20 seconds. ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GTInspectorExamplesTest} named: 'x'. CommandLineTestRunner runClasses: {BlockClosureTest} named: 'y'" Now go to SHTextStyler>>styleInBackgroundProcess: and in the only onTimeout: block from the method add --> 'timeoute done' logCr. <--. Run again the tests and now the string 'timeoute done' is printed 4 times after 20 seconds. Replace in RubShoutStylerDecorator>>style: the call to #styleInBackgroundProcess: with #style: Running again the tests has no delay on BlockClosureTest>>#testBenchFor. Reverting the changes to GTInspectorExamplesTest>>#testAllExamples and running all examples again leads to no delay on BlockClosureTest>>#testBenchFor (testing all examples can take a few minutes). Running all the tests as on the CI also does not block in BlockClosureTest>>#testBenchFor. ./pharo Pharo.image test --junit-xml-output '^(?!Metacello)[A-L].*' (ignore the output about GTDummyExamplesInvalid which will disappear when the new version is integrated) (running the tests takes a bit of time) I get the same behaviour if I first load issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> If anybody else can reproduce this behaviour then the zombie processes that appear while styling in rubric are somehow interfering with the delay scheduling mechanism. Cheers, Andrei On Mon, Nov 16, 2015 at 2:45 PM, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Also you do not have to run it from the command line to reproduce the error. You can just execute in a playground:
CommandLineTestRunner runClasses: {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests').
But if you run the same tests using a script then there is no block:
suite := TestSuite named: 'x'. classes := {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest} asSortedCollection: [ :a :b | a name <= b name ]. classes do: [ :each | each addToSuiteFromSelectors: suite ]. runner := TestRunner new . Author uniqueInstance ifUnknownAuthorUse: 'hudson' during: [ runner runSuite: suite ].
On Mon, Nov 16, 2015 at 2:25 PM, Max Leske <maxleske@gmail.com> wrote:
Interestingly, if I change the delay in that method from 400 to 0 I get the same effect (namely, it doesnât hang). So maybe itâs a problem with delay scheduling from low priority processes?
On 16 Nov 2015, at 14:12, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Hi,
Any news on this?
Might be totally unrelated but I went back and searched for the the first version where [1] blocks. In my case the first version where it blocks is Pharo-40520. In Pharo-40519 it works ok. 40520 integrated https://pharo.fogbugz.com/f/cases/14993 which does a lot of changes, but one changed that this issue did is introduced an async tasks for updating the scrolling in inspector.
Next if in the latest version I change in GLMScrollPaneBandBrick>>onChildrenLayouted the priority of asyncTask from 'Processor lowestPriority' to 'Processor userBackgroundPriority + 1' then #testBenchFor does not block. If I change the priority to the initial one it blocks again. At least on my machine this is consistent.
Not sure if this fixes the bug on the CI but I updated issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> to include this change. Can you try to integrate the issue and see if it still blocks.
Cheers, Andrei
[1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
On Thu, Nov 12, 2015 at 9:21 PM, Max Leske <maxleske@gmail.com> wrote:
I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification.
I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add
2 seconds asDelay wait. Smalltalk garbageCollect.
or
Smalltalk garbageCollect. 2 seconds asDelay wait.
after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point.
I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start.
For testing I used the following command line:
./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)"
Install Epicea with
./pharo Pharo.image get Epicea 6.5
To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning).
HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
I can confirm that changing #styleInBackgroundProcess: to #style: fixes the problem on my machine. I had tracked down a version of GTInspector-Core (StefanReichhart.310) that exhibited the problem while the immediate ancestor didnât. Unfortunately the number of changes are huge in that version. Still, making the above change makes that version also work. My guess is, that this version leads to more of these styling requests. I logged the number of processes after running the examples: without the fix: 937 with the fix: 17 Sounds pretty compelling to me that this will mess with process scheduling⦠Cheers, Max
On 17 Nov 2015, at 22:56, Andrei Chis <chisvasileandrei@gmail.com> wrote:
We investigated more with Max and Aliaksey, and managed to reduce the bug to executing just two tests. Just it would great if somebody else could reproduce it. You need to run commands only from console and save and quit the image after a change.
The tests that need to be executed are GTInspectorExamplesTest>>#testAllExamples and BlockClosureTest>>#testBenchFor.
Download the latest pharo image and remove GTInspectorExamplesTest>>#testGlobals, so that GTInspectorExamplesTest has one single test. In GTInspectorExamplesTest>>#testAllExamples replace 'Object withAllSubclasses' with 'Dictionary asOrderedCollection' (it's not the actual examples that cause problems).
If you execute now the tests, BlockClosureTest>>#testBenchFor will block for around 20 seconds.
./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GTInspectorExamplesTest} named: 'x'. CommandLineTestRunner runClasses: {BlockClosureTest} named: 'y'"
Now go to SHTextStyler>>styleInBackgroundProcess: and in the only onTimeout: block from the method add --> 'timeoute done' logCr. <--.
Run again the tests and now the string 'timeoute done' is printed 4 times after 20 seconds.
Replace in RubShoutStylerDecorator>>style: the call to #styleInBackgroundProcess: with #style:
Running again the tests has no delay on BlockClosureTest>>#testBenchFor. Reverting the changes to GTInspectorExamplesTest>>#testAllExamples and running all examples again leads to no delay on BlockClosureTest>>#testBenchFor (testing all examples can take a few minutes).
Running all the tests as on the CI also does not block in BlockClosureTest>>#testBenchFor.
./pharo Pharo.image test --junit-xml-output '^(?!Metacello)[A-L].*' (ignore the output about GTDummyExamplesInvalid which will disappear when the new version is integrated) (running the tests takes a bit of time)
I get the same behaviour if I first load issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1>
If anybody else can reproduce this behaviour then the zombie processes that appear while styling in rubric are somehow interfering with the delay scheduling mechanism.
Cheers, Andrei
On Mon, Nov 16, 2015 at 2:45 PM, Andrei Chis <chisvasileandrei@gmail.com <mailto:chisvasileandrei@gmail.com>> wrote: Also you do not have to run it from the command line to reproduce the error. You can just execute in a playground:
CommandLineTestRunner runClasses: {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests').
But if you run the same tests using a script then there is no block:
suite := TestSuite named: 'x'. classes := {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest} asSortedCollection: [ :a :b | a name <= b name ]. classes do: [ :each | each addToSuiteFromSelectors: suite ]. runner := TestRunner new . Author uniqueInstance ifUnknownAuthorUse: 'hudson' during: [ runner runSuite: suite ].
On Mon, Nov 16, 2015 at 2:25 PM, Max Leske <maxleske@gmail.com <mailto:maxleske@gmail.com>> wrote: Interestingly, if I change the delay in that method from 400 to 0 I get the same effect (namely, it doesnât hang). So maybe itâs a problem with delay scheduling from low priority processes?
On 16 Nov 2015, at 14:12, Andrei Chis <chisvasileandrei@gmail.com <mailto:chisvasileandrei@gmail.com>> wrote:
Hi,
Any news on this?
Might be totally unrelated but I went back and searched for the the first version where [1] blocks. In my case the first version where it blocks is Pharo-40520. In Pharo-40519 it works ok. 40520 integrated https://pharo.fogbugz.com/f/cases/14993 <https://pharo.fogbugz.com/f/cases/14993> which does a lot of changes, but one changed that this issue did is introduced an async tasks for updating the scrolling in inspector.
Next if in the latest version I change in GLMScrollPaneBandBrick>>onChildrenLayouted the priority of asyncTask from 'Processor lowestPriority' to 'Processor userBackgroundPriority + 1' then #testBenchFor does not block. If I change the priority to the initial one it blocks again. At least on my machine this is consistent.
Not sure if this fixes the bug on the CI but I updated issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> to include this change. Can you try to integrate the issue and see if it still blocks.
Cheers, Andrei
[1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
On Thu, Nov 12, 2015 at 9:21 PM, Max Leske <maxleske@gmail.com <mailto:maxleske@gmail.com>> wrote: I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification.
I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add
2 seconds asDelay wait. Smalltalk garbageCollect.
or
Smalltalk garbageCollect. 2 seconds asDelay wait.
after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point.
I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start.
For testing I used the following command line:
./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)"
Install Epicea with
./pharo Pharo.image get Epicea 6.5
To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning).
HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu <mailto:sven@stfx.eu>> wrote: Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr <mailto:marcus.denker@inria.fr>> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
On Tue, Nov 17, 2015 at 11:44 PM, Max Leske <maxleske@gmail.com> wrote:
I can confirm that changing #styleInBackgroundProcess: to #style: fixes the problem on my machine.
I had tracked down a version of GTInspector-Core (StefanReichhart.310) that exhibited the problem while the immediate ancestor didnât. Unfortunately the number of changes are huge in that version. Still, making the above change makes that version also work. My guess is, that this version leads to more of these styling requests.
I logged the number of processes after running the examples: without the fix: 937 with the fix: 17
Is this the number of processes for running all examples? If yes can you also measure it when running just a single example, as testBenchFor also blocks in that case. Cheers, Andrei
Sounds pretty compelling to me that this will mess with process schedulingâ¦
Cheers, Max
On 17 Nov 2015, at 22:56, Andrei Chis <chisvasileandrei@gmail.com> wrote:
We investigated more with Max and Aliaksey, and managed to reduce the bug to executing just two tests. Just it would great if somebody else could reproduce it. You need to run commands only from console and save and quit the image after a change.
The tests that need to be executed are GTInspectorExamplesTest>>#testAllExamples and BlockClosureTest>>#testBenchFor.
Download the latest pharo image and remove GTInspectorExamplesTest>>#testGlobals, so that GTInspectorExamplesTest has one single test. In GTInspectorExamplesTest>>#testAllExamples replace 'Object withAllSubclasses' with 'Dictionary asOrderedCollection' (it's not the actual examples that cause problems).
If you execute now the tests, BlockClosureTest>>#testBenchFor will block for around 20 seconds.
./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GTInspectorExamplesTest} named: 'x'. CommandLineTestRunner runClasses: {BlockClosureTest} named: 'y'"
Now go to SHTextStyler>>styleInBackgroundProcess: and in the only onTimeout: block from the method add --> 'timeoute done' logCr. <--.
Run again the tests and now the string 'timeoute done' is printed 4 times after 20 seconds.
Replace in RubShoutStylerDecorator>>style: the call to #styleInBackgroundProcess: with #style:
Running again the tests has no delay on BlockClosureTest>>#testBenchFor. Reverting the changes to GTInspectorExamplesTest>>#testAllExamples and running all examples again leads to no delay on BlockClosureTest>>#testBenchFor (testing all examples can take a few minutes).
Running all the tests as on the CI also does not block in BlockClosureTest>>#testBenchFor.
./pharo Pharo.image test --junit-xml-output '^(?!Metacello)[A-L].*' (ignore the output about GTDummyExamplesInvalid which will disappear when the new version is integrated) (running the tests takes a bit of time)
I get the same behaviour if I first load issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1>
If anybody else can reproduce this behaviour then the zombie processes that appear while styling in rubric are somehow interfering with the delay scheduling mechanism.
Cheers, Andrei
On Mon, Nov 16, 2015 at 2:45 PM, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Also you do not have to run it from the command line to reproduce the error. You can just execute in a playground:
CommandLineTestRunner runClasses: {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests').
But if you run the same tests using a script then there is no block:
suite := TestSuite named: 'x'. classes := {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest} asSortedCollection: [ :a :b | a name <= b name ]. classes do: [ :each | each addToSuiteFromSelectors: suite ]. runner := TestRunner new . Author uniqueInstance ifUnknownAuthorUse: 'hudson' during: [ runner runSuite: suite ].
On Mon, Nov 16, 2015 at 2:25 PM, Max Leske <maxleske@gmail.com> wrote:
Interestingly, if I change the delay in that method from 400 to 0 I get the same effect (namely, it doesnât hang). So maybe itâs a problem with delay scheduling from low priority processes?
On 16 Nov 2015, at 14:12, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Hi,
Any news on this?
Might be totally unrelated but I went back and searched for the the first version where [1] blocks. In my case the first version where it blocks is Pharo-40520. In Pharo-40519 it works ok. 40520 integrated https://pharo.fogbugz.com/f/cases/14993 which does a lot of changes, but one changed that this issue did is introduced an async tasks for updating the scrolling in inspector.
Next if in the latest version I change in GLMScrollPaneBandBrick>>onChildrenLayouted the priority of asyncTask from 'Processor lowestPriority' to 'Processor userBackgroundPriority + 1' then #testBenchFor does not block. If I change the priority to the initial one it blocks again. At least on my machine this is consistent.
Not sure if this fixes the bug on the CI but I updated issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> to include this change. Can you try to integrate the issue and see if it still blocks.
Cheers, Andrei
[1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
On Thu, Nov 12, 2015 at 9:21 PM, Max Leske <maxleske@gmail.com> wrote:
I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification.
I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add
2 seconds asDelay wait. Smalltalk garbageCollect.
or
Smalltalk garbageCollect. 2 seconds asDelay wait.
after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point.
I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start.
For testing I used the following command line:
./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)"
Install Epicea with
./pharo Pharo.image get Epicea 6.5
To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning).
HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
On 17 Nov 2015, at 23:50, Andrei Chis <chisvasileandrei@gmail.com> wrote:
On Tue, Nov 17, 2015 at 11:44 PM, Max Leske <maxleske@gmail.com <mailto:maxleske@gmail.com>> wrote: I can confirm that changing #styleInBackgroundProcess: to #style: fixes the problem on my machine.
I had tracked down a version of GTInspector-Core (StefanReichhart.310) that exhibited the problem while the immediate ancestor didnât. Unfortunately the number of changes are huge in that version. Still, making the above change makes that version also work. My guess is, that this version leads to more of these styling requests.
I logged the number of processes after running the examples: without the fix: 937 with the fix: 17
Is this the number of processes for running all examples?
Yes.
If yes can you also measure it when running just a single example, as testBenchFor also blocks in that case.
Thereâs no facility for running a single example, so I just created this method: GTInspectorExamplesTest>>testSingleExample self checkAllPresentationsOf: Collection gtExamples first Then, when I run this command line: ./pharo Pharo.image eval "| suite | suite := TestSuite named: 'x'. suite addTest: (GTInspectorExamplesTest new setTestSelector: #testSingleExample; yourself). CommandLineTestRunner runSuite: suite. suite := TestSuite named: 'y'. suite addTest: (BlockClosureTest new setTestSelector: #testBenchFor; yourself). CommandLineTestRunner runSuite: suite.â I get 17 with the fix and 19 without. Which example did you run to have #testBenchFor block? Because it didnât block for me...
Cheers, Andrei
Sounds pretty compelling to me that this will mess with process schedulingâ¦
Cheers, Max
On 17 Nov 2015, at 22:56, Andrei Chis <chisvasileandrei@gmail.com <mailto:chisvasileandrei@gmail.com>> wrote:
We investigated more with Max and Aliaksey, and managed to reduce the bug to executing just two tests. Just it would great if somebody else could reproduce it. You need to run commands only from console and save and quit the image after a change.
The tests that need to be executed are GTInspectorExamplesTest>>#testAllExamples and BlockClosureTest>>#testBenchFor.
Download the latest pharo image and remove GTInspectorExamplesTest>>#testGlobals, so that GTInspectorExamplesTest has one single test. In GTInspectorExamplesTest>>#testAllExamples replace 'Object withAllSubclasses' with 'Dictionary asOrderedCollection' (it's not the actual examples that cause problems).
If you execute now the tests, BlockClosureTest>>#testBenchFor will block for around 20 seconds.
./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GTInspectorExamplesTest} named: 'x'. CommandLineTestRunner runClasses: {BlockClosureTest} named: 'y'"
Now go to SHTextStyler>>styleInBackgroundProcess: and in the only onTimeout: block from the method add --> 'timeoute done' logCr. <--.
Run again the tests and now the string 'timeoute done' is printed 4 times after 20 seconds.
Replace in RubShoutStylerDecorator>>style: the call to #styleInBackgroundProcess: with #style:
Running again the tests has no delay on BlockClosureTest>>#testBenchFor. Reverting the changes to GTInspectorExamplesTest>>#testAllExamples and running all examples again leads to no delay on BlockClosureTest>>#testBenchFor (testing all examples can take a few minutes).
Running all the tests as on the CI also does not block in BlockClosureTest>>#testBenchFor.
./pharo Pharo.image test --junit-xml-output '^(?!Metacello)[A-L].*' (ignore the output about GTDummyExamplesInvalid which will disappear when the new version is integrated) (running the tests takes a bit of time)
I get the same behaviour if I first load issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1>
If anybody else can reproduce this behaviour then the zombie processes that appear while styling in rubric are somehow interfering with the delay scheduling mechanism.
Cheers, Andrei
On Mon, Nov 16, 2015 at 2:45 PM, Andrei Chis <chisvasileandrei@gmail.com <mailto:chisvasileandrei@gmail.com>> wrote: Also you do not have to run it from the command line to reproduce the error. You can just execute in a playground:
CommandLineTestRunner runClasses: {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests').
But if you run the same tests using a script then there is no block:
suite := TestSuite named: 'x'. classes := {GLMPagerMorphTest . GLMTreeMorphicTest. GLMWatcherMorphicTest} asSortedCollection: [ :a :b | a name <= b name ]. classes do: [ :each | each addToSuiteFromSelectors: suite ]. runner := TestRunner new . Author uniqueInstance ifUnknownAuthorUse: 'hudson' during: [ runner runSuite: suite ].
On Mon, Nov 16, 2015 at 2:25 PM, Max Leske <maxleske@gmail.com <mailto:maxleske@gmail.com>> wrote: Interestingly, if I change the delay in that method from 400 to 0 I get the same effect (namely, it doesnât hang). So maybe itâs a problem with delay scheduling from low priority processes?
On 16 Nov 2015, at 14:12, Andrei Chis <chisvasileandrei@gmail.com <mailto:chisvasileandrei@gmail.com>> wrote:
Hi,
Any news on this?
Might be totally unrelated but I went back and searched for the the first version where [1] blocks. In my case the first version where it blocks is Pharo-40520. In Pharo-40519 it works ok. 40520 integrated https://pharo.fogbugz.com/f/cases/14993 <https://pharo.fogbugz.com/f/cases/14993> which does a lot of changes, but one changed that this issue did is introduced an async tasks for updating the scrolling in inspector.
Next if in the latest version I change in GLMScrollPaneBandBrick>>onChildrenLayouted the priority of asyncTask from 'Processor lowestPriority' to 'Processor userBackgroundPriority + 1' then #testBenchFor does not block. If I change the priority to the initial one it blocks again. At least on my machine this is consistent.
Not sure if this fixes the bug on the CI but I updated issue 16957 <https://pharo.fogbugz.com/f/cases/16957/Update-GTools-version-3-1> to include this change. Can you try to integrate the issue and see if it still blocks.
Cheers, Andrei
[1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
On Thu, Nov 12, 2015 at 9:21 PM, Max Leske <maxleske@gmail.com <mailto:maxleske@gmail.com>> wrote: I found a single test method I could use to narrow down the problem (be aware that this might not work for you. I have other (fresh) images where the issue never occurs). The method I used is EpRedoAndUndoVisitorTest>>testClassModification.
I was able to mitigate the hang by making a small modification to the method EpUndoVisitor>>visitClassModification: Simply add
2 seconds asDelay wait. Smalltalk garbageCollect.
or
Smalltalk garbageCollect. 2 seconds asDelay wait.
after the compilation phase. My guess is, that announcements build up (a simple printout showed 1 announcement instance before and 74 instances after the #evaluate:) and do stuff in the system that influence the process scheduling. For instance, a lot of those announcements will probably be weak and need to be finalized at some point.
I donât have enough experience with the ClassBuilder to go on hunting but this should hopefully give you a good head start.
For testing I used the following command line:
./pharo found_case.image eval "CommandLineTestRunner runPackages: #('Epicea' 'Kernel-Testsâ)"
Install Epicea with
./pharo Pharo.image get Epicea 6.5
To isolate the test case I simply moved test classes from Epicea to a differently named package and once I had found the class I started excluding methods (e.g. with âself fail.â at the beginning).
HTH, Max
On 12 Nov 2015, at 18:57, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Yes! with Max Leske we have been isolating the problem and we realized that a fresh image was enough:
1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash
2) ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests')"
Martin
On Thu, Nov 12, 2015 at 6:42 PM, Sven Van Caekenberghe <sven@stfx.eu <mailto:sven@stfx.eu>> wrote: Then it must be that waiting on the delay never ends, which is probably a problem all by itself.
On 12 Nov 2015, at 18:39, Marcus Denker <marcus.denker@inria.fr <mailto:marcus.denker@inria.fr>> wrote:
The fun thing is that I now get the same problem when integrating the GT Tools update.
After doing the update for issue 16957, the test run hangs with
starting testcase: BlockClosureTest>>testBenchFor ...
On 11 Nov 2015, at 22:42, Martin Dias <tinchodias@gmail.com <mailto:tinchodias@gmail.com>> wrote:
Hello,
I'm trying to understand why this method hangs in certain conditions*. What happens is that the #whileTrue: in the following method is never cut.
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 1. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
Strangely, I verified with several #logCr that the forked block starts, but the #wait never ends. ---> Maybe you see something I don't in the code. Any clue?
I will continue trying to isolate the problem, but maybe you have some idea.
* the conditions to reproduce are: 1) curl get.pharo.org/50+vm <http://get.pharo.org/50+vm> | bash 2) ./pharo Pharo.image get Epicea 6.5 3) ./pharo Pharo.image test '^(?!Metacello)[A-L].*'
Notes: - It doesn't hang when running from UI - it doesn't hang when running less tests, like: pharo Pharo.image test '^(?!Metacello)[E-L].*' - it *does* hang even when removing all Epicea tests - Epicea doesn't extend or override "kernel" behavior...
Regards, Martin
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine: |duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] . duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration. In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark. At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)" So the benchmark is executed for over one minute before the delay expires.
a BenchmarkResult(5,057,441 iterations in 3 minutes 26 seconds 74 milliseconds. 24,542 per second) ./pharo Pharo.image eval 205,98s user 2,07s system 100% cpu 3:27,44 total
On 18 Nov 2015, at 11:48, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
From Playground... a BenchmarkResult(1,942,473 iterations in 1 minute 47 seconds 237 milliseconds. 18,114 per second)
Now I haven't thought hard enough about the following to know if its the right solution, but just an early share... changing... ] forkAt: Processor activePriority. to... ] forkAt: Processor activePriority - 1. in #styleInBackgroundProcess: has a positive impact. cheers -ben On Wed, Nov 18, 2015 at 7:09 PM, Max Leske <maxleske@gmail.com> wrote:
a BenchmarkResult(5,057,441 iterations in 3 minutes 26 seconds 74 milliseconds. 24,542 per second)
./pharo Pharo.image eval 205,98s user 2,07s system 100% cpu 3:27,44 total
On 18 Nov 2015, at 11:48, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
On 18 Nov 2015, at 15:10, Ben Coman <btc@openInWorld.com> wrote:
From Playground... a BenchmarkResult(1,942,473 iterations in 1 minute 47 seconds 237 milliseconds. 18,114 per second)
Now I haven't thought hard enough about the following to know if its the right solution, but just an early share... changing... ] forkAt: Processor activePriority. to... ] forkAt: Processor activePriority - 1. in #styleInBackgroundProcess: has a positive impact.
That would definitely help. Another thing I think should be different is the 5 second delay in that process. The 5 seconds might make some sense for a regular user but they pose a problem for automated tests (as we have seen here).
cheers -ben
On Wed, Nov 18, 2015 at 7:09 PM, Max Leske <maxleske@gmail.com> wrote:
a BenchmarkResult(5,057,441 iterations in 3 minutes 26 seconds 74 milliseconds. 24,542 per second)
./pharo Pharo.image eval 205,98s user 2,07s system 100% cpu 3:27,44 total
On 18 Nov 2015, at 11:48, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
On Wed, Nov 18, 2015 at 3:10 PM, Ben Coman <btc@openinworld.com> wrote:
From Playground... a BenchmarkResult(1,942,473 iterations in 1 minute 47 seconds 237 milliseconds. 18,114 per second)
Now I haven't thought hard enough about the following to know if its the right solution, but just an early share... changing... ] forkAt: Processor activePriority. to... ] forkAt: Processor activePriority - 1. in #styleInBackgroundProcess: has a positive impact.
Interesting. Just somehow this seems more like a workaround. I'd really like to find out why rubric creates zombie processes when styling and how do these processes affect the delay scheduling. Replacing, in the code I previously send, the creation of a Rubric editor with just the code for styling leads to no delay. (RubSHTextStylerST80 new styleInBackgroundProcess: '1+1' asText) Ideally I'd like to find some code, independent of rubric that exhibits the bug. Something in the line of this script http://ws.stfx.eu/1P51Y1WBN9RJ , which for now does not produce any delay. For the moment I'll disable #testAllExamples so see if this actually fixes the blocking issue from the CI. Cheers, Andrei
cheers -ben
On Wed, Nov 18, 2015 at 7:09 PM, Max Leske <maxleske@gmail.com> wrote:
a BenchmarkResult(5,057,441 iterations in 3 minutes 26 seconds 74 milliseconds. 24,542 per second)
./pharo Pharo.image eval 205,98s user 2,07s system 100% cpu 3:27,44 total
On 18 Nov 2015, at 11:48, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana). Regards Andreas
I went ahead and implemented a simple fix for the styler. Not sure how well it performs but in my simple experiments it seems to work fine. Please test it and let me know what you think. https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces... Cheers, Max
On 18 Nov 2015, at 19:02, Andreas Wacknitz <A.Wacknitz@gmx.de> wrote:
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana).
Regards Andreas
Hi! With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended. More in detail, the following method makes the assumption that once the delay process finishes the handling of the delay to schedule, it will return to same process. But that is not true if there is another process with more priority. schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [^self error: 'This Delay has already been scheduled.']. accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := (scheduledDelay == nil). ]. ^scheduled. Our solution is to run the critical section in a higher priority to ensure that always comes back to the same process to release the delay lock. schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [ ^ self error: 'This Delay has already been scheduled.' ]. [ accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := scheduledDelay == nil ]. ^ scheduled ] valueAt: Processor timingPriority - 1 Also, to not have interference with the benchmarking process we reduce the priority of the process used in benchFor: benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority *- 2*. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself We will create an entry in fogbugz and submit the change. Regards, Martin, Guille and Pablo On Wed, Nov 18, 2015 at 8:33 PM, Max Leske <maxleske@gmail.com> wrote:
I went ahead and implemented a simple fix for the styler. Not sure how well it performs but in my simple experiments it seems to work fine. Please test it and let me know what you think.
https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...
Cheers, Max
On 18 Nov 2015, at 19:02, Andreas Wacknitz <A.Wacknitz@gmx.de> wrote:
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana).
Regards Andreas
2015-11-20 12:46 GMT+01:00 Martin Dias <tinchodias@gmail.com>:
Hi!
With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended.
I believe this is a text book example of priority inversion. Kudo's for finding it! Thierry
More in detail, the following method makes the assumption that once the delay process finishes the handling of the delay to schedule, it will return to same process. But that is not true if there is another process with more priority.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [^self error: 'This Delay has already been scheduled.']. accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := (scheduledDelay == nil). ]. ^scheduled.
Our solution is to run the critical section in a higher priority to ensure that always comes back to the same process to release the delay lock.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [ ^ self error: 'This Delay has already been scheduled.' ]. [ accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := scheduledDelay == nil ]. ^ scheduled ] valueAt: Processor timingPriority - 1
Also, to not have interference with the benchmarking process we reduce the priority of the process used in benchFor:
benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority *- 2*. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
We will create an entry in fogbugz and submit the change.
Regards, Martin, Guille and Pablo
On Wed, Nov 18, 2015 at 8:33 PM, Max Leske <maxleske@gmail.com> wrote:
I went ahead and implemented a simple fix for the styler. Not sure how well it performs but in my simple experiments it seems to work fine. Please test it and let me know what you think.
https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...
Cheers, Max
On 18 Nov 2015, at 19:02, Andreas Wacknitz <A.Wacknitz@gmx.de> wrote:
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana).
Regards Andreas
On 20 Nov 2015, at 13:03, Thierry Goubier <thierry.goubier@gmail.com> wrote:
2015-11-20 12:46 GMT+01:00 Martin Dias <tinchodias@gmail.com>: Hi!
With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended.
I believe this is a text book example of priority inversion.
Kudo's for finding it!
Great work, great team ! Also a bit scary.
Thierry
More in detail, the following method makes the assumption that once the delay process finishes the handling of the delay to schedule, it will return to same process. But that is not true if there is another process with more priority.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [^self error: 'This Delay has already been scheduled.']. accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := (scheduledDelay == nil). ]. ^scheduled.
Our solution is to run the critical section in a higher priority to ensure that always comes back to the same process to release the delay lock.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [ ^ self error: 'This Delay has already been scheduled.' ]. [ accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := scheduledDelay == nil ]. ^ scheduled ] valueAt: Processor timingPriority - 1
Also, to not have interference with the benchmarking process we reduce the priority of the process used in benchFor:
benchFor: duration "Run me for duration and return a BenchmarkResult"
"[ 100 factorial ] benchFor: 2 seconds"
| count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 2. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
We will create an entry in fogbugz and submit the change.
Regards, Martin, Guille and Pablo
On Wed, Nov 18, 2015 at 8:33 PM, Max Leske <maxleske@gmail.com> wrote: I went ahead and implemented a simple fix for the styler. Not sure how well it performs but in my simple experiments it seems to work fine. Please test it and let me know what you think.
https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...
Cheers, Max
On 18 Nov 2015, at 19:02, Andreas Wacknitz <A.Wacknitz@gmx.de> wrote:
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana).
Regards Andreas
2015-11-20 13:44 GMT+01:00 Sven Van Caekenberghe <sven@stfx.eu>:
On 20 Nov 2015, at 13:03, Thierry Goubier <thierry.goubier@gmail.com> wrote:
2015-11-20 12:46 GMT+01:00 Martin Dias <tinchodias@gmail.com>: Hi!
With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended.
I believe this is a text book example of priority inversion.
Kudo's for finding it!
Great work, great team !
Also a bit scary.
No. And yes. No, because its inherent to the Pharo scheduler. Yes, because anywhere you acquire a non-local lock in Pharo in a process with less that max priority, it may happen. And that the cooperative nature of the Pharo scheduler increase the risks. Thierry
On Fri, Nov 20, 2015 at 2:00 PM, Thierry Goubier <thierry.goubier@gmail.com> wrote:
2015-11-20 13:44 GMT+01:00 Sven Van Caekenberghe <sven@stfx.eu>:
On 20 Nov 2015, at 13:03, Thierry Goubier <thierry.goubier@gmail.com> wrote:
2015-11-20 12:46 GMT+01:00 Martin Dias <tinchodias@gmail.com>: Hi!
With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended.
I believe this is a text book example of priority inversion.
Kudo's for finding it!
Great work, great team !
Also a bit scary.
No. And yes.
No, because its inherent to the Pharo scheduler.
Yes, because anywhere you acquire a non-local lock in Pharo in a process with less that max priority, it may happen. And that the cooperative nature of the Pharo scheduler increase the risks.
Ah! DelayMillisecondScheduler should be fixed too.
Could you try the various DelayExperimentalXXXSchedulers? Under System > Settings > System > Delay Scheduler. I believe there's a good chance one of them may fix also the problem. I had planned to push one of these as the default in Pharo 5 but hadn't decided which, got distracted and stretched a bit thin IRL. I believe these experimental schedulers are better than the current mutex based scheduler, since passing Delays from your normal-priority process to the timing-priority delay scheduling process is a signalling paradigm more than a shared memory paradigm. I came to this conclusion reading [2] which says... "The correct use of a semaphore is for signalling from one task to another. A mutex is meant to be taken and released, always in that order, by [the same task using] the shared resource it protects. By contrast, tasks that use semaphores either signal or waitânot both. ... Another important distinction between a mutex and a semaphore is that the proper use of a mutex to protect a shared resource can have a dangerous unintended side effect ... any two tasks that operate at different priorities and coordinate via a mutex, create the opportunity for priority inversion ... Fortunately ... semaphores ... do not cause priority inversion when used for signalling." A mutex makes DelayXXXScheduler>>#schedule: susceptible to priority inversion since it is used by many processes at different priority levels. Using a signalling-semaphore might avoid the problem. The experimental delay schedulers were developed to address the problem reported in the "super fast delay" [2], but there may also have been a fix for that through another means. [1] http://www.barrgroup.com/Embedded-Systems/How-To/RTOS-Mutex-Semaphore [2] http://forum.world.st/Super-fast-delay-td4787257.html cheers -ben On Fri, Nov 20, 2015 at 8:03 PM, Thierry Goubier <thierry.goubier@gmail.com> wrote:
2015-11-20 12:46 GMT+01:00 Martin Dias <tinchodias@gmail.com>:
Hi!
With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended.
I believe this is a text book example of priority inversion.
Kudo's for finding it!
Thierry
More in detail, the following method makes the assumption that once the delay process finishes the handling of the delay to schedule, it will return to same process. But that is not true if there is another process with more priority.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [^self error: 'This Delay has already been scheduled.']. accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := (scheduledDelay == nil). ]. ^scheduled.
Our solution is to run the critical section in a higher priority to ensure that always comes back to the same process to release the delay lock.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [ ^ self error: 'This Delay has already been scheduled.' ]. [ accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := scheduledDelay == nil ]. ^ scheduled ] valueAt: Processor timingPriority - 1
Also, to not have interference with the benchmarking process we reduce the priority of the process used in benchFor:
benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 2. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
We will create an entry in fogbugz and submit the change.
Regards, Martin, Guille and Pablo
On Wed, Nov 18, 2015 at 8:33 PM, Max Leske <maxleske@gmail.com> wrote:
I went ahead and implemented a simple fix for the styler. Not sure how well it performs but in my simple experiments it seems to work fine. Please test it and let me know what you think.
https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...
Cheers, Max
On 18 Nov 2015, at 19:02, Andreas Wacknitz <A.Wacknitz@gmx.de> wrote:
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana).
Regards Andreas
So you can try the following... $ curl get.pharo.org/50+vm | bash $ ./pharo Pharo.image eval "Delay delaySchedulerClass: DelayExperimentalSemaphoreScheduler. CommandLineTestRunner runClasses: {GLMTreeMorphicTest. GLMWatcherMorphicTest. GLMPagerMorphTest} named: 'x'. CommandLineTestRunner runPackages: #('Kernel-Tests') btw, these are named "experimental" only because they were integrated a week before the Pharo 4 release (delayed due to some conflict with the CI system). For me they had been stable for months before that (only some CI conflicts delayed integration.) I believe these are ready for wider community testing by promoting an "experimental" delay scheduler to be default. Probably leave its name unchanged for now. There is some refactoring I want to do to clean up its hierarchy that will be simplified by leaving the name as it is for now. cheers -ben On Fri, Nov 20, 2015 at 11:43 PM, Ben Coman <btc@openinworld.com> wrote:
Could you try the various DelayExperimentalXXXSchedulers? Under System > Settings > System > Delay Scheduler.
I believe there's a good chance one of them may fix also the problem. I had planned to push one of these as the default in Pharo 5 but hadn't decided which, got distracted and stretched a bit thin IRL. I believe these experimental schedulers are better than the current mutex based scheduler, since passing Delays from your normal-priority process to the timing-priority delay scheduling process is a signalling paradigm more than a shared memory paradigm. I came to this conclusion reading [2] which says...
"The correct use of a semaphore is for signalling from one task to another. A mutex is meant to be taken and released, always in that order, by [the same task using] the shared resource it protects. By contrast, tasks that use semaphores either signal or waitânot both. ... Another important distinction between a mutex and a semaphore is that the proper use of a mutex to protect a shared resource can have a dangerous unintended side effect ... any two tasks that operate at different priorities and coordinate via a mutex, create the opportunity for priority inversion ... Fortunately ... semaphores ... do not cause priority inversion when used for signalling."
A mutex makes DelayXXXScheduler>>#schedule: susceptible to priority inversion since it is used by many processes at different priority levels. Using a signalling-semaphore might avoid the problem.
The experimental delay schedulers were developed to address the problem reported in the "super fast delay" [2], but there may also have been a fix for that through another means.
[1] http://www.barrgroup.com/Embedded-Systems/How-To/RTOS-Mutex-Semaphore [2] http://forum.world.st/Super-fast-delay-td4787257.html
cheers -ben
On Fri, Nov 20, 2015 at 8:03 PM, Thierry Goubier <thierry.goubier@gmail.com> wrote:
2015-11-20 12:46 GMT+01:00 Martin Dias <tinchodias@gmail.com>:
Hi!
With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended.
I believe this is a text book example of priority inversion.
Kudo's for finding it!
Thierry
More in detail, the following method makes the assumption that once the delay process finishes the handling of the delay to schedule, it will return to same process. But that is not true if there is another process with more priority.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [^self error: 'This Delay has already been scheduled.']. accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := (scheduledDelay == nil). ]. ^scheduled.
Our solution is to run the critical section in a higher priority to ensure that always comes back to the same process to release the delay lock.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [ ^ self error: 'This Delay has already been scheduled.' ]. [ accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := scheduledDelay == nil ]. ^ scheduled ] valueAt: Processor timingPriority - 1
Also, to not have interference with the benchmarking process we reduce the priority of the process used in benchFor:
benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority - 2. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
We will create an entry in fogbugz and submit the change.
Regards, Martin, Guille and Pablo
On Wed, Nov 18, 2015 at 8:33 PM, Max Leske <maxleske@gmail.com> wrote:
I went ahead and implemented a simple fix for the styler. Not sure how well it performs but in my simple experiments it seems to work fine. Please test it and let me know what you think.
https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...
Cheers, Max
On 18 Nov 2015, at 19:02, Andreas Wacknitz <A.Wacknitz@gmx.de> wrote:
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana).
Regards Andreas
https://pharo.fogbugz.com/f/cases/17066/Problem-scheduling-delay-from-a-low-... On Fri, Nov 20, 2015 at 12:46 PM, Martin Dias <tinchodias@gmail.com> wrote:
Hi!
With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended.
More in detail, the following method makes the assumption that once the delay process finishes the handling of the delay to schedule, it will return to same process. But that is not true if there is another process with more priority.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [^self error: 'This Delay has already been scheduled.']. accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := (scheduledDelay == nil). ]. ^scheduled.
Our solution is to run the critical section in a higher priority to ensure that always comes back to the same process to release the delay lock.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [ ^ self error: 'This Delay has already been scheduled.' ]. [ accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := scheduledDelay == nil ]. ^ scheduled ] valueAt: Processor timingPriority - 1
Also, to not have interference with the benchmarking process we reduce the priority of the process used in benchFor:
benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority *- 2*. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
We will create an entry in fogbugz and submit the change.
Regards, Martin, Guille and Pablo
On Wed, Nov 18, 2015 at 8:33 PM, Max Leske <maxleske@gmail.com> wrote:
I went ahead and implemented a simple fix for the styler. Not sure how well it performs but in my simple experiments it seems to work fine. Please test it and let me know what you think.
https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...
Cheers, Max
On 18 Nov 2015, at 19:02, Andreas Wacknitz <A.Wacknitz@gmx.de> wrote:
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana).
Regards Andreas
Great catch! Can something similar be also the reason SHTextStyler>>styleInBackgroundProcess: spawns zombie processes? Even with this fix script [1] blocks in testBenchFor. If I apply the fix proposed by ben in this thread or the slice for issue 17050 <https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...> then [1] does not block in testBenchFor. [1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GTInspectorExamplesTest} named: 'x'. CommandLineTestRunner runClasses: {BlockClosureTest} named: 'y'" On Fri, Nov 20, 2015 at 12:46 PM, Martin Dias <tinchodias@gmail.com> wrote:
Hi!
With Guille and Pablo this morning we found what is the problem and apparently fixed it. The problem is that there is a process in priority 10 that takes the delay lock (accessProtect semaphore) and go to sleep. Then the #benchFor: launches another process in priority 79 that tries to take the delay lock but, since it's taken by the other process, it goes to sleep. But the UI process is in priority 40 so it will always have priority over the one that has the lock. Consequence: the process in priority 10 has the delay lock and will never be awaken until the UI process gets suspended.
More in detail, the following method makes the assumption that once the delay process finishes the handling of the delay to schedule, it will return to same process. But that is not true if there is another process with more priority.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [^self error: 'This Delay has already been scheduled.']. accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := (scheduledDelay == nil). ]. ^scheduled.
Our solution is to run the critical section in a higher priority to ensure that always comes back to the same process to release the delay lock.
schedule: aDelay | scheduled | scheduled := false. aDelay schedulerBeingWaitedOn ifTrue: [ ^ self error: 'This Delay has already been scheduled.' ]. [ accessProtect critical: [ scheduledDelay := aDelay. timingSemaphore signal. "#handleTimerEvent: sets scheduledDelay:=nil" scheduled := scheduledDelay == nil ]. ^ scheduled ] valueAt: Processor timingPriority - 1
Also, to not have interference with the benchmarking process we reduce the priority of the process used in benchFor:
benchFor: duration "Run me for duration and return a BenchmarkResult" "[ 100 factorial ] benchFor: 2 seconds" | count run started | count := 0. run := true. [ duration wait. run := false ] forkAt: Processor timingPriority *- 2*. started := Time millisecondClockValue. [ run ] whileTrue: [ self value. count := count + 1 ]. ^ BenchmarkResult new iterations: count; elapsedTime: (Time millisecondsSince: started) milliSeconds; yourself
We will create an entry in fogbugz and submit the change.
Regards, Martin, Guille and Pablo
On Wed, Nov 18, 2015 at 8:33 PM, Max Leske <maxleske@gmail.com> wrote:
I went ahead and implemented a simple fix for the styler. Not sure how well it performs but in my simple experiments it seems to work fine. Please test it and let me know what you think.
https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...
Cheers, Max
On 18 Nov 2015, at 19:02, Andreas Wacknitz <A.Wacknitz@gmx.de> wrote:
Am 18.11.15 um 11:48 schrieb Andrei Chis:
Can you try the script below in the latest Pharo image and let me know how much does it take to execute on your machine:
|duration benchmarkResult| 100 timesRepeat: [ RubScrolledTextMorph new model: (RubScrolledTextModel new setInitialText: '1+1'; yourself); beForSmalltalkScripting; yourself ] .
duration := 100 milliSeconds. benchmarkResult := [ 100 factorial ] benchFor: duration.
In my case it takes around 1 minute. The inner loop finishes immediately and then most time is spend executing the benchmark.
At the end I get the following result: "a BenchmarkResult(2,060,386 iterations in 1 minute 7 seconds 498 milliseconds. 30,525 per second)"
So the benchmark is executed for over one minute before the delay expires.
"a BenchmarkResult(1,263,573 iterations in 37 seconds 689 milliseconds. 33,526 per second)" (HP Z420 with Xeon E5-1620 under OpenIndiana).
Regards Andreas
On Fri, Nov 20, 2015 at 2:27 PM, Andrei Chis <chisvasileandrei@gmail.com> wrote:
Great catch!
Can something similar be also the reason SHTextStyler>>styleInBackgroundProcess: spawns zombie processes? Even with this fix script [1] blocks in testBenchFor. If I apply the fix proposed by ben in this thread or the slice for issue 17050 <https://pharo.fogbugz.com/f/cases/17050/SHTextStyler-styleInBackgroundProces...> then [1] does not block in testBenchFor.
[1] ./pharo Pharo.image eval "CommandLineTestRunner runClasses: {GTInspectorExamplesTest} named: 'x'. CommandLineTestRunner runClasses: {BlockClosureTest} named: 'y'"
I confirm! Andrei's script hangs when loading 17066's slice without 17050's slice (and post-load do it). So I set 17050 as a subcase of 17066. Martin
participants (10)
-
Andreas Wacknitz -
Andrei Chis -
Ben Coman -
Marcus Denker -
Martin Dias -
Max Leske -
stepharo -
Sven Van Caekenberghe -
Thierry Goubier -
Tudor Girba