Just for the fun, I did a system tracing...
strace ../../../products/sqcogspurlinux/lib/squeak/5.0-201711262336/squeak TravisCI.image test.st > tmp.log 2>tmp.trace Then interrupted and quit the image
It's amazing how many time we stat/open the changes file... grep changes tmp.trace | grep open | wc 3027 15226 511279
sometimes, we open many .changes in a row and the file index keep increasing, like:
lstat64("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", {st_mode=S_IFREG|0644, st_size=10701044, ...}) = 0 open("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", O_RDONLY|O_LARGEFILE) = 206 lstat64("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", {st_mode=S_IFREG|0644, st_size=10701077, ...}) = 0 open("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", O_RDONLY|O_LARGEFILE) = 208 lstat64("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", {st_mode=S_IFREG|0644, st_size=10701103, ...}) = 0 open("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", O_RDONLY|O_LARGEFILE) = 10 lstat64("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", {st_mode=S_IFREG|0644, st_size=10701816, ...}) = 0 open("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", O_RDONLY|O_LARGEFILE) = 12 lstat64("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", {st_mode=S_IFREG|0644, st_size=10701900, ...}) = 0 open("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_07_37/TravisCI.changes", O_RDONLY|O_LARGEFILE) = 14
This is the famous case when we can exhaust the maximum number of opened files... I don't remembered if we installed a workaround at image side? But obviously we do not behave so well with respect to external resources...
Then I see patterns where we read .changes a few times every 2ms... like this:
open("/media/psf/Home/Smalltalk/OpenSmalltalk/opensmalltalk-vm/smalltalkCI-master/_builds/2017_12_04_22_ 07_37/TravisCI.changes", O_RDONLY|O_LARGEFILE) = 9 fcntl64(9, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE) fstat64(9, {st_mode=S_IFREG|0644, st_size=10762271, ...}) = 0 fstat64(9, {st_mode=S_IFREG|0644, st_size=10762271, ...}) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=234913}, NULL) = 0 sigreturn({mask=[]}) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2079) = 2079 _llseek(9, 0, [0], SEEK_SET) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2042) = 2042 read(9, ": '' prior: 44316480!\roverride ^"..., 4096) = 37 read(9, "", 4096) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=237225}, NULL) = 0 sigreturn({mask=[]}) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=239103}, NULL) = 0 sigreturn({mask=[]}) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2078) = 2078 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=241003}, NULL) = 0 sigreturn({mask=[]}) = 2078 _llseek(9, 10762270, [10762270], SEEK_SET) = 0 read(9, "!", 4096) = 1 read(9, "", 4096) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2078) = 2078 read(9, "!", 4096) = 1 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=243052}, NULL) = 0 sigreturn({mask=[]}) = 1 read(9, "", 4096) = 0 recvmsg(4, {msg_namelen=0}, 0) = -1 EAGAIN (Resource temporarily unavailable) _newselect(5, [4], [], [4], {tv_sec=0, tv_usec=0}) = 0 (Timeout) read(9, "", 4096) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 read(9, "", 4096) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=245075}, NULL) = 0 sigreturn({mask=[]}) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2079) = 2079 read(9, "", 4096) = 0 read(9, "", 4096) = 0 read(9, "", 4096) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=247097}, NULL) = 0 sigreturn({mask=[]}) = 0 read(9, "", 4096) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2079) = 2079 read(9, "", 4096) = 0 read(9, "", 4096) = 0 read(9, "", 4096) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=248983}, NULL) = 0 sigreturn({mask=[]}) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 read(9, "", 4096) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2079) = 2079 read(9, "", 4096) = 0 read(9, "", 4096) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=251019}, NULL) = 0 sigreturn({mask=[]}) = 0 read(9, "", 4096) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 read(9, "", 4096) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2079) = 2079 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422430, tv_usec=253017}, NULL) = 0 sigreturn({mask=[]}) = 2079 ...
It looks like we are looping like this during 103 seconds (I let sufficient time before pressing ctrl+alt+.)
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422533, tv_usec=555087}, NULL) = 0 sigreturn({mask=[]}) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2079) = 2079 read(9, "", 4096) = 0 read(9, "", 4096) = 0 read(9, "", 4096) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422533, tv_usec=556985}, NULL) = 0 sigreturn({mask=[]}) = 0 _llseek(9, 0, [10762271], SEEK_CUR) = 0 read(9, "", 4096) = 0 _llseek(9, 10760192, [10760192], SEEK_SET) = 0 read(9, "ceVariableNames: ''\r\tclassVariab"..., 2079) = 2079 read(9, "", 4096) = 0 read(9, "", 4096) = 0 --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} --- gettimeofday({tv_sec=1512422533, tv_usec=559009}, NULL) = 0 sigreturn({mask=[]}) = 0 gettimeofday({tv_sec=1512422533, tv_usec=559419}, NULL) = 0 gettimeofday({tv_sec=1512422533, tv_usec=559628}, NULL) = 0 gettimeofday({tv_sec=1512422533, tv_usec=559830}, NULL) = 0
It's not the good way to find the bug, bt it's interesting...
2017-12-04 21:58 GMT+01:00 Nicolas Cellier < nicolas.cellier.aka.nice@gmail.com>:
Hi Fabio, no, I opened the test image --headfull and it is blocked in tests:
MCMockPackageInfo(PackageInfo) changeRecordForOverriddenMethod:
with parameter: a MethodReference MCMethodDefinitionTest >> #override
This is invoked from MCMethodDefinition>>tearDown.
It is blocked in this infinite loop:
[file position < (position-1)] "then pick it up from the front" whileTrue: [chunk := file nextChunk].
here file position is 0, and inst. var. readLimit is 0 too... So nextChunk invariably return '' and the position does not advance.
Why is readLimit 0??? The file is TravisCI.changes and I can open and read it normally in the FileList. The problem comes from SourceFiles which already has an incorrect readLimit set to zero (image attached)
It remains to discover how this ever happened, and why only in linux...
2017-12-04 7:35 GMT+01:00 Fabio Niephaus lists@fniephaus.com:
Hi Nicolas, Is it possible that this was related to this: http://forum.world.st/Squeak-trunk-updates-fail-td5059208.html
Best, Fabio
On Sun, 3 Dec 2017 at 11:08 am, Nicolas Cellier < nicolas.cellier.aka.nice@gmail.com> wrote:
Hi, for quite some times the travis build for linux32x86 times out during the .travis_test.sh phase.
It's very hard for me to build a 32bits vm from 64bits ubuntu (14.xx). So I've tried with a 32bits VM (debian9), changed to opensmalltalk root directory of my working copy, and
export ARCH="linux32x86" export FLAVOR="squeak.cog.spur" export TRAVIS_BUILD_DIR=`pwd` export TRAVIS_OS_NAME=linux ./.travis_build.sh ./.travis_test.sh
The tests effectively seem to block with 100% CPU.
So I performed a few stack dump via kill -USR1, and it seems that tests are stuck in a very long operation, here is one of the samples:
All Smalltalk process stacks (active first): Process 0x192cda8 priority 40 0xbfc67d94 M MultiByteFileStream(StandardFileStream)>basicNext 0x129bdc8: a(n) MultiByteFileStream 0xbfc67db0 M UTF8TextConverter>skipSeparatorsAndPeekNextFrom: 0x129bd58: a(n) UTF8TextConverter 0xbfc67dd0 M UTF8TextConverter>parseLangTagFor:fromStream: 0x129bd58: a(n) UTF8TextConverter 0xbfc67df0 M UTF8TextConverter>nextChunkFromStream: 0x129bd58: a(n) UTF8TextConverter 0xbfc67e0c M MultiByteFileStream>nextChunk 0x129bdc8: a(n) MultiByteFileStream 0xbfc67e5c M [] in MCMockPackageInfo(PackageInfo)>changeRecordsForMethod:do: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc67e7c M BlockClosure>ensure: 0x129bf80: a(n) BlockClosure 0xbfc74bb0 M MCMockPackageInfo(PackageInfo)>changeRecordsForMethod:do: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc74bd0 M MCMockPackageInfo(PackageInfo)
changeRecordForOverriddenMethod: 0x1a265d0: a(n) MCMockPackageInfo
0xbfc74bec M MCMockPackageInfo(PackageInfo)>isOverrideOfYourMethod: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc74c0c M [] in MCMockPackageInfo(PackageInfo)>overriddenMethodsDo: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc74c30 M [] in MCMockPackageInfo(PackageInfo)>methodsInCategory:ofClass:do: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc74c54 M Array(SequenceableCollection)>do: 0x129d178: a(n) Array 0xbfc74c70 M MCMockPackageInfo(PackageInfo)>methodsInCategory:ofClass:do: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc74c9c M [] in MCMockPackageInfo(PackageInfo)>overriddenMethodsInClass:do: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc74cbc M [] in MCMockPackageInfo(PackageInfo)
overrideCategoriesForClass:do: 0x1a265d0: a(n) MCMockPackageInfo
0xbfc74ce0 M Array(SequenceableCollection)>do: 0x129aa48: a(n) Array 0xbfc74cfc M MCMockPackageInfo(PackageInfo)
overrideCategoriesForClass:do: 0x1a265d0: a(n) MCMockPackageInfo
0xbfc74d1c M MCMockPackageInfo(PackageInfo)>overriddenMethodsInClass:do: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc74d40 M [] in MCMockPackageInfo(PackageInfo)>allOverriddenMethodsDo: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc74d60 M [] in MCTestCase class(Behavior)>allSubclassesDo: 0x1b38d88: a(n) MCTestCase class 0xbfc74d84 M Array(SequenceableCollection)>do: 0x1ae4c70: a(n) Array 0xbfc74da0 M MCTestCase class(Class)>subclassesDo: 0x1b38d88: a(n) MCTestCase class 0xbfc74dbc M MCTestCase class(Behavior)>allSubclassesDo: 0x1b38d88: a(n) MCTestCase class 0xbfc74ddc M [] in TestCase class(Behavior)>allSubclassesDo: 0x1b35988: a(n) TestCase class 0xbfc74e00 M Array(SequenceableCollection)>do: 0x27fa510: a(n) Array 0xbfc74e1c M TestCase class(Class)>subclassesDo: 0x1b35988: a(n) TestCase class 0xbfc74e38 M TestCase class(Behavior)>allSubclassesDo: 0x1b35988: a(n) TestCase class 0xbfc74e58 M [] in Object class(Behavior)>allSubclassesDo: 0x1a25910: a(n) Object class 0xbfc74e7c M Array(SequenceableCollection)>do: 0x1297d50: a(n) Array 0xbfc6bb9c M Object class(Class)>subclassesDo: 0x1a25910: a(n) Object class 0xbfc6bbb8 M Object class(Behavior)>allSubclassesDo: 0x1a25910: a(n) Object class 0xbfc6bbd8 M [] in ProtoObject class(Behavior)>allSubclassesDo: 0x1a25a98: a(n) ProtoObject class 0xbfc6bbfc M Array(SequenceableCollection)>do: 0x4334a28: a(n) Array 0xbfc6bc18 M ProtoObject class(Class)>subclassesDo: 0x1a25a98: a(n) ProtoObject class 0xbfc6bc34 M ProtoObject class(Behavior)>allSubclassesDo: 0x1a25a98: a(n) ProtoObject class 0xbfc6bc58 I ProtoObject class(Behavior)>withAllSubclassesDo: 0x1a25a98: a(n) ProtoObject class 0xbfc6bc74 M MCMockPackageInfo(PackageInfo)>allOverriddenMethodsDo: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc6bc90 M MCMockPackageInfo(PackageInfo)>overriddenMethodsDo: 0x1a265d0: a(n) MCMockPackageInfo 0xbfc6bcac M [] in MCMockPackageInfo(PackageInfo)>overriddenMethods 0x1a265d0: a(n) MCMockPackageInfo 0xbfc6bcd0 M Array class(SequenceableCollection class)>new:streamContents: 0x1a124a8: a(n) Array class 0xbfc6bcf0 M Array class(SequenceableCollection class)>streamContents: 0x1a124a8: a(n) Array class 0xbfc6bd0c M MCMockPackageInfo(PackageInfo)>overriddenMethods 0x1a265d0: a(n) MCMockPackageInfo 0xbfc6bd2c M [] in MCPackage>snapshot 0x129ca58: a(n) MCPackage 0xbfc6bd48 M BlockClosure>on:do: 0x129cac8: a(n) BlockClosure 0xbfc6bd6c M CurrentReadOnlySourceFiles class>cacheDuring: 0x1baa718: a(n) CurrentReadOnlySourceFiles class 0xbfc6bd94 M MCPackage>snapshot 0x129ca58: a(n) MCPackage 0xbfc6bdb4 M MCPackageLoader>updatePackage:withSnapshot: 0x129cc40: a(n) MCPackageLoader 0xbfc6bde0 I MCPackageLoader class>updatePackage:withSnapshot: 0x1c00d30: a(n) MCPackageLoader class 0xbfc6be08 I MCSnapshot>updatePackage: 0x4148418: a(n) MCSnapshot 0xbfc6be2c I MCMethodDefinitionTest(MCTestCase)>restoreMocks 0x4049e20: a(n) MCMethodDefinitionTest 0xbfc6be44 M MCMethodDefinitionTest>tearDown 0x4049e20: a(n) MCMethodDefinitionTest 0xbfc6be5c M [] in MCMethodDefinitionTest(TestCase)>runCase 0x4049e20: a(n) MCMethodDefinitionTest 0xbfc6be7c M MethodContext(ContextPart)>resume: 0x129c2e0: a(n) MethodContext 0xbfc68c2c M BlockClosure>ensure: 0x129c128: a(n) BlockClosure 0xbfc68c48 M MCMethodDefinitionTest(TestCase)>runCase 0x4049e20: a(n) MCMethodDefinitionTest 0xbfc68c60 M SCISqueakTestRunner(SCITestRunner)>basicRunCase: 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68c80 M [] in SCISqueakTestRunner(SCITestRunner)>runCase: 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68c9c M BlockClosure>on:do: 0x129c218: a(n) BlockClosure 0xbfc68cc4 M [] in SCISqueakTestRunner(SCITestRunner)>runCase: 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68ce0 M BlockClosure>on:do: 0x129c340: a(n) BlockClosure 0xbfc68d08 M [] in SCISqueakTestRunner(SCITestRunner)>runCase: 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68d24 M Time class>millisecondsToRun: 0x1a10700: a(n) Time class 0xbfc68d40 M SmalltalkCI class>timeToRun: 0x3afeee8: a(n) SmalltalkCI class 0xbfc68d64 M SCISqueakTestRunner(SCITestRunner)>runCase: 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68d80 M MCMethodDefinitionTest(TestCase)>run: 0x4049e20: a(n) MCMethodDefinitionTest 0xbfc68d9c M [] in SCISqueakTestRunner(SCITestRunner)>runAll 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68dbc M OrderedCollection>do: 0x401f7f0: a(n) OrderedCollection 0xbfc68de0 I SCISqueakTestRunner(SCITestRunner)>runAll 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68df8 M [] in SCISqueakTestRunner(SCITestRunner)>run 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68e1c I Time class>millisecondsToRun: 0x1a10700: a(n) Time class 0xbfc68e40 I SmalltalkCI class>timeToRun: 0x3afeee8: a(n) SmalltalkCI class 0xbfc68e5c M [] in SCISqueakTestRunner(SCITestRunner)>run 0x4050a68: a(n) SCISqueakTestRunner 0xbfc68e7c M BlockClosure>ensure: 0x4050b80: a(n) BlockClosure 0x4050c10 s SCISqueakTestRunner(SCITestRunner)>run 0x41492c8 s SCISqueakTestRunner class(SCITestRunner class)>runSuite:spec: 0x401e3f0 s SCISqueakTestRunner class(SCITestRunner class)>runClasses:spec: 0x4040da0 s SCISqueakTestRunner class(SCITestRunner class)>runSpec: 0x4148790 s SmalltalkCISqueak(SmalltalkCI)>runTests 0x414a428 s [] in SmalltalkCISqueak(SmalltalkCI)>basicTest 0x3bab9b0 s SmalltalkCISqueak class(SmalltalkCI class)>run:spec:in: 0x401e4c0 s [] in SmalltalkCISqueak(SmalltalkCI)>basicTest 0x4040e00 s [] in SmalltalkCISqueak class(SmalltalkCI class)>fold:on:block: 0x41487f0 s Time class>millisecondsToRun: 0x414a488 s SmalltalkCI class>timeToRun: 0x401e560 s SmalltalkCISqueak class(SmalltalkCI class)>fold:on:block: 0x4040e60 s SmalltalkCISqueak class(SmalltalkCI class)>fold:block: 0x4148850 s SmalltalkCISqueak class(SmalltalkCI class)>stage:id:block: 0x401e5c0 s SmalltalkCISqueak(SmalltalkCI)>basicTest 0x401e620 s [] in SmalltalkCISqueak(SmalltalkCI)>test 0x401da40 s BlockClosure>on:do: 0x401dae0 s [] in SmalltalkCISqueak(SmalltalkCI)>test 0x4040bc0 s [] in SmalltalkCISqueak class(SmalltalkCI class)>withBuildStatusReportingDo: 0x401db70 s BlockClosure>on:do: 0x401dbe8 s SmalltalkCISqueak class(SmalltalkCI class)>withBuildStatusReportingDo: 0x401dc48 s SmalltalkCISqueak(SmalltalkCI)>test 0x4040c20 s SmalltalkCI class>test:projectDirectory: 0x41486d0 s SmalltalkCI class>test: 0x401dd48 s UndefinedObject>DoIt 0x401de88 s Compiler>evaluateCue:ifFail: 0x401df20 s Compiler>evaluateCue:ifFail:logged: 0x4040c80 s Compiler>evaluate:in:to:notifying:ifFail:logged: 0x401e178 s Compiler class>evaluate:for:notifying:logged: 0x4040ce0 s Compiler class>evaluate:for:logged: 0x4148730 s Compiler class>evaluate:logged: 0x414a3c8 s [] in ReadStream(PositionableStream)>fileInAnnouncing: 0x401e1f0 s BlockClosure>on:do: 0x401e268 s [] in ReadStream(PositionableStream)>fileInAnnouncing: 0x4040d40 s [] in MorphicUIManager>displayProgress:at:from:to:during: 0x401e2e8 s BlockClosure>on:do: 0x401e360 s [] in MorphicUIManager>displayProgress:at:from:to:during: 0x401d240 s BlockClosure>ensure: 0x401d2f0 s MorphicUIManager>displayProgress:at:from:to:during: 0x40409e0 s ProgressInitiationException>defaultResumeValue 0x41484f0 s ProgressInitiationException(Exception)>resume 0x414a248 s ProgressInitiationException>defaultAction 0x3bab890 s UndefinedObject>handleSignal: 0x401d3b8 s ProgressInitiationException(Exception)>signal 0x401d418 s ProgressInitiationException>display:at:from:to:during: 0x4040a40 s ProgressInitiationException class>display:at:from:to:durin g: 0x4148550 s ByteString(String)>displayProgressAt:from:to:during: 0x414a2a8 s ByteString(String)>displayProgressFrom:to:during: 0x401d4a0 s ReadStream(PositionableStream)>fileInAnnouncing: 0x4040aa0 s ReadStream(PositionableStream)>fileIn 0x41485b0 s CodeLoader>installSourceFile: 0x414a308 s [] in CodeLoader>installSourceFiles 0x3bab8f0 s Array(SequenceableCollection)>do: 0x401d780 s CodeLoader>installSourceFiles 0x401d930 s ProjectLauncher>startUpAfterLogin 0x4040b00 s ProjectLauncher>startUp 0x4148610 s [] in AutoStart class>startUp: 0x414a368 s WorldState>runStepMethodsIn: 0x3bab950 s PasteUpMorph>runStepMethods 0x401d9c8 s WorldState>doOneCycleNowFor: 0x4040b60 s WorldState>doOneCycleFor: 0x4148670 s PasteUpMorph>doOneCycle 0x1e09b00 s [] in MorphicProject>spawnNewProcess 0x1ad4dd8 s [] in BlockClosure>newProcess
It' like MCMethodDefinitionTest>tearDown never finish (or is very very long) because MCMockPackageInfo(PackageInfo)>overriddenMethods is very very long.
I don't know what is different on linux32x86 VM compared to OSX, but it would be interesting to understand what's going on exactly...