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:during: 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...

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...

2017-12-05 23:02 GMT+01:00 Nicolas Cellier < nicolas.cellier.aka.nice@gmail.com>:

OK, it's more complex (readLimit only refers to available buffer length not file length) and more simple than that...

Just trying with:

../../../products/sqcogspurlinux/lib/squeak/5.0-201711262336/squeak TravisCI.image test.st

letting it run a few minutes and interrupting it, I'm in the infinite loop (nextChunk = ''). That's because the method thinks it is written at position 11319975 (it might differ for you, because I launched the test.st several times) But the read only copy thinks it is already atEnd at position 11320088 So it reads an empty chunk without making progress and will loop infinitely...

Ahem, I don't remember to which substance I was exposed yesterday, those are the wrong figures... But the diagnosis is correct/reproducible today:

10483842 is the position where we search for method source 10483729 is the current (file position) and (file atEnd) is true, so we cannot go beyond that... The readOnlyCopy looks like truncated...

Flushing the original before doing a readOnlyCopy is an effective workaround.

I think that (SourceFiles at: 2) was not flushed and the readOnlyCopy is

then shorten. This happens only in linux, because only in recent linux we have this problem that opening an already opened file does not take care of pending buffer of already opened file...

We can work around for now by forcing a flush in readOnlyCopy:

StandardFileStream>>readOnlyCopy self flush. ^ self class readOnlyFileNamed: self name.

Having this method in the image lets the tests pass in linux...

2017-12-04 23:19 GMT+01:00 Nicolas Cellier <nicolas.cellier.aka.nice@ gmail.com>:

...

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/opensmallta lk-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/opensmallta lk-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/opensmallta lk-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/opensmallta lk-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/opensmallta lk-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@gmai l.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...

2017-12-06 23:13 GMT+01:00 Ben Coman btc@openinworld.com:

On 7 December 2017 at 05:05, Nicolas Cellier <nicolas.cellier.aka.nice@ gmail.com> wrote:

...

2017-12-05 23:02 GMT+01:00 Nicolas Cellier <nicolas.cellier.aka.nice@gmai l.com>:

...

OK, it's more complex (readLimit only refers to available buffer length not file length) and more simple than that...

Just trying with:

../../../products/sqcogspurlinux/lib/squeak/5.0-201711262336/squeak TravisCI.image test.st

letting it run a few minutes and interrupting it, I'm in the infinite loop (nextChunk = ''). That's because the method thinks it is written at position 11319975 (it might differ for you, because I launched the test.st several times) But the read only copy thinks it is already atEnd at position 11320088 So it reads an empty chunk without making progress and will loop infinitely...

Ahem, I don't remember to which substance I was exposed yesterday, those are the wrong figures...

A HeinekenBug? Like a Heisenbug, but more amber. cheers -ben

:)

I shudder to think how horrible a bugweiser could be!

Since ESUG 2016 in Prague I recommend pils: it helps understanding the VM, or at least let you think so.

On Wed, Dec 06, 2017 at 11:30:37PM +0100, Nicolas Cellier wrote:

2017-12-06 23:13 GMT+01:00 Ben Coman btc@openinworld.com:

...

On 7 December 2017 at 05:05, Nicolas Cellier <nicolas.cellier.aka.nice@ gmail.com> wrote:

...

2017-12-05 23:02 GMT+01:00 Nicolas Cellier <nicolas.cellier.aka.nice@gmai l.com>:

...

OK, it's more complex (readLimit only refers to available buffer length not file length) and more simple than that...

Just trying with:

../../../products/sqcogspurlinux/lib/squeak/5.0-201711262336/squeak TravisCI.image test.st

letting it run a few minutes and interrupting it, I'm in the infinite loop (nextChunk = ''). That's because the method thinks it is written at position 11319975 (it might differ for you, because I launched the test.st several times) But the read only copy thinks it is already atEnd at position 11320088 So it reads an empty chunk without making progress and will loop infinitely...

Ahem, I don't remember to which substance I was exposed yesterday, those are the wrong figures...

A HeinekenBug? Like a Heisenbug, but more amber. cheers -ben

:)

I shudder to think how horrible a bugweiser could be!

Since ESUG 2016 in Prague I recommend pils: it helps understanding the VM, or at least let you think so.

A good pils is hard to beat, although I prefer something a bit hoppier. But local preferences aside, "Bugweiser" is brilliant. I want to buy the Bugweiser T-shirt.

Best of all, googling "bugweiser" turns up no hits at all, so Nicolas can take credit for it. And Ben gets the credit (and/or blame?) for provoking the idea.

Normally I would not be concerned with intellectual property rights in a case like this, but when I think of the potential revenues from Bugwieser T-shirts, I think it is important to give credit where credit is due.

;-)

Dave

On Thu, Dec 07, 2017 at 12:20:55PM +0800, Ben Coman wrote:

On 7 December 2017 at 11:45, David T. Lewis lewis@mail.msen.com wrote:

...

On Wed, Dec 06, 2017 at 11:30:37PM +0100, Nicolas Cellier wrote:

...

2017-12-06 23:13 GMT+01:00 Ben Coman btc@openinworld.com:

...

On 7 December 2017 at 05:05, Nicolas Cellier <nicolas.cellier.aka.nice@ gmail.com> wrote:

...

2017-12-05 23:02 GMT+01:00 Nicolas Cellier <nicolas.cellier.aka.nice@gmai l.com>:

Ahem, I don't remember to which substance I was exposed yesterday, those are the wrong figures...

A HeinekenBug? Like a Heisenbug, but more amber. cheers -ben

:)

I shudder to think how horrible a bugweiser could be!

Since ESUG 2016 in Prague I recommend pils: it helps understanding the VM, or at least let you think so.

A good pils is hard to beat, although I prefer something a bit hoppier. But local preferences aside, "Bugweiser" is brilliant. I want to buy the Bugweiser T-shirt.

But I'm not sure... Does this mean you're getting better at squashing bugs, or that the bugs are learning to fight back?

I am not really interested in spending time on squashing bugs, but I am interested in preventing them and understanding where the bugs come from in the first place. Bugweiser seems like a plausible explanation for quite a wide class of issues ;-)

Dave