[BUG?] Slow file writing due to excessive GC
Henrik Gedenryd
Henrik.Gedenryd at lucs.lu.se
Tue Oct 9 15:07:43 UTC 2001
When I file out a few files of source code in a fairly standard manner, I
get a very weird timing profile: Roughly half the time is spent on garbage
collection, even though Squeak reports 80M of free RAM, and the
open:forWrite: shouldn't fail for any other reason I have been able to find.
Some typical code for reproducing this is:
MessageTally spyOn: [
{ClassOrganizer. StandardFileStream. SystemDictionary.
WriteStream. Symbol. DisplayScreen}
do: [:c | c fileOut]]
Can anyone explain this behavior? This is a Mac VM (3.1.1, but it oughtn't
matter).
Henrik
- 510 tallies, 8804 msec.
**Tree**
100.0% {8804ms} ClassOrganizer class(Class)>>fileOut
100.0% {8804ms} ClassOrganizer class(Class)>>fileOutAsHtml:
45.7% {4023ms} FileStream class>>newFileNamed:
|45.7% {4023ms} StandardFileStream class>>newFileNamed:
| 45.7% {4023ms} StandardFileStream class>>isAFileNamed:
| 45.7% {4023ms} StandardFileStream>>open:forWrite:
| 45.7% {4023ms} StandardFileStream(Object)>>retryWithGC:until:
| 45.7% {4023ms} SystemDictionary>>garbageCollect
44.7% {3935ms} ClassOrganizer class(Class)>>fileOutOn:moveSource:toFile:
|44.7% {3935ms} ClassOrganizer
class(Class)>>fileOutOn:moveSource:toFile:initializing:
| 42.0% {3698ms} ClassOrganizer
class(ClassDescription)>>fileOutOn:moveSource:toFile:
| |41.2% {3627ms} ClassOrganizer
class(ClassDescription)>>fileOutCategory:on:moveSource:toFile:
| | 41.2% {3627ms} ClassOrganizer
class(ClassDescription)>>printMethodChunk:with...n:moveSource:toFile:
| | 25.9% {2280ms}
StandardFileStream(PositionableStream)>>copyMethodChunkFrom:
| | |25.9% {2280ms}
StandardFileStream(PositionableStream)>>nextChunkText
| | | 23.1% {2034ms}
StandardFileStream(PositionableStream)>>nextChunk
| | | |10.6% {933ms} WriteStream>>nextPut:
| | | |8.8% {775ms} StandardFileStream>>next
| | | | |5.1% {449ms} primitives
| | | | |3.7% {326ms} StandardFileStream>>basicNext
| | | |3.3% {291ms} primitives
| | | 2.2% {194ms}
StandardFileStream(PositionableStream)>>skipSeparatorsAndPeekNext
| | 11.4% {1004ms}
StandardFileStream(PositionableStream)>>copyPreamble:from:
| | |10.4% {916ms} StandardFileStream>>next:
| | | 10.4% {916ms}
StandardFileStream(PositionableStream)>>nextInto:
| | | 10.4% {916ms}
StandardFileStream>>next:into:startingAt:
| | 2.4% {211ms} ClassOrganizer>>categoryOfElement:
| | 2.4% {211ms} ClassOrganizer>>numberOfCategoryOfElement:
| 2.7% {238ms} Metaclass>>fileOutOn:moveSource:toFile:initializing:
| 2.7% {238ms}
Metaclass(ClassDescription)>>fileOutOn:moveSource:toFile:
| 2.7% {238ms}
Metaclass(ClassDescription)>>fileOutCategory:on:moveSource:toFile:
| 2.7% {238ms}
Metaclass(ClassDescription)>>printMethodChunk:with...n:moveSource:toFile:
9.4% {828ms} StandardFileStream>>close
**Leaves**
45.7% {4023ms} SystemDictionary>>garbageCollect
11.4% {1004ms} WriteStream>>nextPut:
11.2% {986ms} StandardFileStream>>next:into:startingAt:
9.4% {828ms} StandardFileStream>>close
6.5% {572ms} StandardFileStream>>basicNext
5.5% {484ms} StandardFileStream>>next
3.7% {326ms} StandardFileStream(PositionableStream)>>nextChunk
**Memory**
old +52,684 bytes
young -72,636 bytes
used -19,952 bytes
free +19,952 bytes
**GCs**
full 6 totalling 3,675ms (42.0% uptime), avg 613.0ms
incr 17 totalling 14ms (0.0% uptime), avg 1.0ms
tenures 0
root table 0 overflows
More information about the Squeak-dev
mailing list
|