After ScriptLoader loadOBAlpha problems, I'm now playing a bit with strace.
very instructive. strace build/squeak *.image `pwd`/loadOBAlpha.st > tmp.trace 2>&1 Notice a (SourceFiles at: 2) truncate: SmalltalkImage current lastQuitLogPosition. This is because repeated ScriptLoader loadOBAlpha are quickly spoiling the change log. Tracing is really slow, especially with these unbuffered writes write(6, "^", 1) = 1 write(6, "s", 1) = 1 write(6, "e", 1) = 1 write(6, "l", 1) = 1 write(6, "f", 1) = 1 I remember Eliot noticed this easy potential speed-up already. I noticed a bunch of try...catch style of open file at startup. grep ENOENT ../pharo0.1-10268dev09.04.1/tmp.trace | wc -l 4012 Most are plugin/library search and Freetype related. But a few search concern icons and wonderland... Some room for more etoys clean-up here? On my linux box, I can now confirm the socket problem encountered by loadOBAlpha is really a (Too many open files) problem. Some @!*^# code is trying to open more than 1018 change log files which is a bit too much. Some file closing happens from time to time but very sparsely. This happens while loading Installer wiresong project: 'ob'; install: 'OB-Refactory'. Consequently, the following instruction fails. Installer lukas project: 'ob'; install: 'OB-Regex'; You can find tmp.trace at http://ncellier.ifrance.com/Squeak/tmp.trace.gz 26MB gzipped. ------------------------------------------------------------------------------------------------------- Now it's easier to debug the change log opener in image. But it's not obvious whether we can reproduce in debugger because of UI, debugger, GC interactions... So we gonna use the MessageTally/Notification tricks: build/squeak *.image `pwd`/TraceOpenFile.st & Tally results are copied in OpenFileTally.txt. Highly suspect is #readOnlyCopy... RemoteString is guilty for not closing the file and relying on some finalization actions... And OBDynamicProtocols is abusing of this stuff... So fixing RemoteString by gently closing the file does fix the linux problem... build/squeak *.image `pwd`/loadOBAlpha.st & Now this is a good workaround, but what change introduced the problem ? there are two solutions: - either recent versions of OB are creating the problem - or recent changes in Polling UI/or Process changed finalization order This should be tested in a 3.10.2 image _______________________________________________ Pharo-project mailing list [hidden email] http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project OpenFileTally.txt (9K) Download Attachment loadOBAlpha.st (1K) Download Attachment TraceOpenFile.st (2K) Download Attachment RemoteString_FixFileClose-nice.1.cs (2K) Download Attachment |
See patch for http://code.google.com/p/pharo/issues/detail?id=786
in PharoInbox/SLICE-RemoteString-closeFile-nice.1 2009/5/1 Nicolas Cellier <[hidden email]>: > After ScriptLoader loadOBAlpha problems, I'm now playing a bit with strace. > very instructive. > > strace build/squeak *.image `pwd`/loadOBAlpha.st > tmp.trace 2>&1 > > Notice a > (SourceFiles at: 2) truncate: SmalltalkImage current lastQuitLogPosition. > This is because repeated ScriptLoader loadOBAlpha are quickly spoiling > the change log. > > Tracing is really slow, especially with these unbuffered writes > write(6, "^", 1) = 1 > write(6, "s", 1) = 1 > write(6, "e", 1) = 1 > write(6, "l", 1) = 1 > write(6, "f", 1) = 1 > I remember Eliot noticed this easy potential speed-up already. > > I noticed a bunch of try...catch style of open file at startup. > grep ENOENT ../pharo0.1-10268dev09.04.1/tmp.trace | wc -l > 4012 > Most are plugin/library search and Freetype related. > But a few search concern icons and wonderland... Some room for more > etoys clean-up here? > > On my linux box, I can now confirm the socket problem encountered by > loadOBAlpha is really a (Too many open files) problem. > Some @!*^# code is trying to open more than 1018 change log files > which is a bit too much. > Some file closing happens from time to time but very sparsely. > This happens while loading > Installer wiresong > project: 'ob'; > install: 'OB-Refactory'. > > Consequently, the following instruction fails. > Installer lukas > project: 'ob'; > install: 'OB-Regex'; > > You can find tmp.trace at http://ncellier.ifrance.com/Squeak/tmp.trace.gz > 26MB gzipped. > > ------------------------------------------------------------------------------------------------------- > Now it's easier to debug the change log opener in image. > But it's not obvious whether we can reproduce in debugger because of > UI, debugger, GC interactions... > So we gonna use the MessageTally/Notification tricks: > > build/squeak *.image `pwd`/TraceOpenFile.st & > > Tally results are copied in OpenFileTally.txt. > Highly suspect is #readOnlyCopy... > RemoteString is guilty for not closing the file and relying on some > finalization actions... > And OBDynamicProtocols is abusing of this stuff... > > So fixing RemoteString by gently closing the file does fix the linux problem... > build/squeak *.image `pwd`/loadOBAlpha.st & > > > Now this is a good workaround, but what change introduced the problem ? > there are two solutions: > - either recent versions of OB are creating the problem > - or recent changes in Polling UI/or Process changed finalization order > > This should be tested in a 3.10.2 image > _______________________________________________ Pharo-project mailing list [hidden email] http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project |
In reply to this post by Nicolas Cellier
That is the multibyte file stream handing the UTF8 logic, where it
writes one byte at a time to the file system. Er slow eh? I'll guess we are reading/writting change files now as UTF8? You can watch the system messages thunder into 100's of millions... for the VM. I'll bet that is why MC loading is so slow now? Because of this for Sophie we build a SophieMultiByteMemoryFileStream which streamed data in or out of a memory based stream with setup or close logic to read or flush the entire in memory stream to/from a target stream (usually a file). Technically what is required is a file stream subclass that does block read/writes so that you can read/write data in 64K chunks versus byte by byte. On 1-May-09, at 10:07 AM, Nicolas Cellier wrote: > Tracing is really slow, especially with these unbuffered writes > write(6, "^", 1) = 1 > write(6, "s", 1) = 1 > write(6, "e", 1) = 1 > write(6, "l", 1) = 1 > write(6, "f", 1) = 1 > I remember Eliot noticed this easy potential speed-up already. -- = = = ======================================================================== John M. McIntosh <[hidden email]> Twitter: squeaker68882 Corporate Smalltalk Consulting Ltd. http://www.smalltalkconsulting.com = = = ======================================================================== _______________________________________________ Pharo-project mailing list [hidden email] http://lists.gforge.inria.fr/cgi-bin/mailman/listinfo/pharo-project |
Free forum by Nabble | Edit this page |