internal void ReadFile(long startFileOffset, long endFileOffset, ReadLogResult readLogResult) { ProgressForm progressForm = new ProgressForm(); progressForm.Text = string.Format("Progress loading {0}", fileName); progressForm.Visible = progressFormVisible; progressForm.setProgress(0); if (stacktraceTable == null) stacktraceTable = new StacktraceTable(); if (timePos == null) timePos = new TimePos[1000]; AddTypeName(0, "Free Space"); try { Stream s = new FileStream(fileName, FileMode.Open, FileAccess.Read, FileShare.ReadWrite); r = new StreamReader(s); for (timePosIndex = timePosCount; timePosIndex > 0; timePosIndex--) if (timePos[timePosIndex-1].pos <= startFileOffset) break; // start at the beginning if no later start point available or asked for info that can only // be constructed by reading the whole file. if (timePosIndex <= 1 || readLogResult.relocatedHistogram != null || readLogResult.finalizerHistogram != null || readLogResult.criticalFinalizerHistogram != null || readLogResult.liveObjectTable != null) { pos = 0; timePosIndex = 1; } else { timePosIndex--; pos = timePos[timePosIndex].pos; } if (timePosCount == 0) { timePos[0] = new TimePos(0.0, 0); timePosCount = timePosIndex = 1; } s.Position = pos; buffer = new byte[4096]; bufPos = 0; bufLevel = 0; int maxProgress = (int)(r.BaseStream.Length/1024); progressForm.setMaximum(maxProgress); line = 1; StringBuilder sb = new StringBuilder(); ulong[] ulongStack = new ulong[1000]; int[] intStack = new int[1000]; int stackPtr = 0; c = ReadChar(); bool thisIsR = false, previousWasR; bool extendedRootInfoSeen = false; int lastTickIndex = 0; bool newGcEvent = false; while (c != -1) { if (pos > endFileOffset) break; if ((line % 1024) == 0) { int currentProgress = (int)(pos/1024); if (currentProgress <= maxProgress) { progressForm.setProgress(currentProgress); Application.DoEvents(); if (progressForm.DialogResult == DialogResult.Cancel) break; } } lastLineStartPos = pos-1; previousWasR = thisIsR; thisIsR = false; switch (c) { case -1: break; case 'F': case 'f': { c = ReadChar(); int funcIndex = ReadInt(); while (c == ' ' || c == '\t') c = ReadChar(); sb.Length = 0; // Name may contain spaces if they are in angle brackets. // Example: <Module>::std_less<unsigned void>.() // The name may be truncated at 255 chars by profilerOBJ.dll int angleBracketsScope = 0; while (c > ' ' || angleBracketsScope != 0 && sb.Length < 255) { if (c == '<') angleBracketsScope++; sb.Append((char)c); c = ReadChar(); if (c == '>' && angleBracketsScope > 0) angleBracketsScope--; } string name = sb.ToString(); while (c == ' ' || c == '\t') c = ReadChar(); sb.Length = 0; while (c > '\r') { sb.Append((char)c); if (c == ')') { c = ReadChar(); break; } c = ReadChar(); } string signature = sb.ToString(); ulong addr = ReadULong(); uint size = ReadUInt(); int modIndex = ReadInt(); int stackIndex = ReadInt(); if (c != -1) { EnsureStringCapacity(funcIndex, ref funcName); funcName[funcIndex] = name; EnsureStringCapacity(funcIndex, ref funcSignature); funcSignature[funcIndex] = signature; EnsureIntCapacity(funcIndex, ref funcModule); funcModule[funcIndex] = modIndex; string nameAndSignature = name; if (signature != null) nameAndSignature = name + ' '+signature; if (stackIndex >= 0 && readLogResult.functionList != null) { funcSignatureIdHash[nameAndSignature] = funcIndex; readLogResult.functionList.Add(funcIndex, stackIndex, size, modIndex); } } break; } case 'T': case 't': { c = ReadChar(); int typeIndex = ReadInt(); while (c == ' ' || c == '\t') c = ReadChar(); if (c != -1 && Char.IsDigit((char)c)) { if (ReadInt() != 0) { finalizableTypes[typeIndex] = true; } } while (c == ' ' || c == '\t') c = ReadChar(); sb.Length = 0; while (c > '\r') { sb.Append((char)c); c = ReadChar(); } string typeName = sb.ToString(); if (c != -1) { AddTypeName(typeIndex, typeName); } break; } // 'A' with thread identifier case '!': { c = ReadChar(); int threadId = ReadInt(); ulong id = ReadULong(); int typeSizeStackTraceIndex = ReadInt(); typeSizeStackTraceIndex = stacktraceTable.MapTypeSizeStacktraceId(typeSizeStackTraceIndex); if (c != -1) { if (readLogResult.liveObjectTable != null) readLogResult.liveObjectTable.InsertObject(id, typeSizeStackTraceIndex, lastTickIndex, lastTickIndex, true, readLogResult.sampleObjectTable); if (pos >= startFileOffset && pos < endFileOffset && readLogResult.allocatedHistogram != null) { // readLogResult.calls.Add(new CallOrAlloc(false, threadId, typeSizeStackTraceIndex)); readLogResult.allocatedHistogram.AddObject(typeSizeStackTraceIndex, 1); } List<string> prev; if (assembliesJustLoaded.TryGetValue(threadId, out prev) && prev.Count != 0) { foreach(string assemblyName in prev) { assemblies[assemblyName] = -typeSizeStackTraceIndex; } prev.Clear(); } } readLogResult.hadAllocInfo = true; readLogResult.hadCallInfo = true; break; } case 'A': case 'a': { c = ReadChar(); ulong id = ReadULong(); int typeSizeStackTraceIndex = ReadInt(); typeSizeStackTraceIndex = stacktraceTable.MapTypeSizeStacktraceId(typeSizeStackTraceIndex); if (c != -1) { if (readLogResult.liveObjectTable != null) readLogResult.liveObjectTable.InsertObject(id, typeSizeStackTraceIndex, lastTickIndex, lastTickIndex, true, readLogResult.sampleObjectTable); if (pos >= startFileOffset && pos < endFileOffset && readLogResult.allocatedHistogram != null) { // readLogResult.calls.Add(new CallOrAlloc(false, typeSizeStackTraceIndex)); readLogResult.allocatedHistogram.AddObject(typeSizeStackTraceIndex, 1); } } readLogResult.hadAllocInfo = true; readLogResult.hadCallInfo = true; break; } case 'C': case 'c': { c = ReadChar(); if (pos < startFileOffset || pos >= endFileOffset) { while (c >= ' ') c = ReadChar(); break; } int threadIndex = ReadInt(); int stackTraceIndex = ReadInt(); stackTraceIndex = stacktraceTable.MapTypeSizeStacktraceId(stackTraceIndex); if (c != -1) { if (readLogResult.callstackHistogram != null) { readLogResult.callstackHistogram.AddObject(stackTraceIndex, 1); } List<string> prev; if (assembliesJustLoaded.TryGetValue(threadIndex, out prev) && prev.Count != 0) { foreach(string assemblyName in prev) { assemblies[assemblyName] = stackTraceIndex; } prev.Clear(); } } readLogResult.hadCallInfo = true; break; } case 'E': case 'e': { c = ReadChar(); extendedRootInfoSeen = true; thisIsR = true; if (pos < startFileOffset || pos >= endFileOffset) { while (c >= ' ') c = ReadChar(); break; } if (!previousWasR) { heapDumpEventList.AddEvent(lastTickIndex, null); if (readLogResult.objectGraph != null && !readLogResult.objectGraph.empty) { readLogResult.objectGraph.BuildTypeGraph(new FilterForm()); readLogResult.objectGraph.Neuter(); } readLogResult.objectGraph = new ObjectGraph(this, lastTickIndex); Histogram[] h = readLogResult.heapDumpHistograms; if (h != null) { readLogResult.heapDumpHistograms = new Histogram[h.Length+1]; for (int i = 0; i < h.Length; i++) readLogResult.heapDumpHistograms[i] = h[i]; readLogResult.heapDumpHistograms[h.Length] = new Histogram(this); } } ulong objectID = ReadULong(); GcRootKind rootKind = (GcRootKind)ReadInt(); GcRootFlags rootFlags = (GcRootFlags)ReadInt(); ulong rootID = ReadULong(); ObjectGraph objectGraph = readLogResult.objectGraph; if (c != -1 && objectID > 0 && objectGraph != null && (rootFlags & GcRootFlags.WeakRef) == 0) { string rootName; switch (rootKind) { case GcRootKind.Stack: rootName = "Stack"; break; case GcRootKind.Finalizer: rootName = "Finalizer"; break; case GcRootKind.Handle: rootName = "Handle"; break; default: rootName = "Other"; break; } if ((rootFlags & GcRootFlags.Pinning) != 0) rootName += ", Pinning"; if ((rootFlags & GcRootFlags.WeakRef) != 0) rootName += ", WeakRef"; if ((rootFlags & GcRootFlags.Interior) != 0) rootName += ", Interior"; if ((rootFlags & GcRootFlags.Refcounted) != 0) rootName += ", RefCounted"; int rootTypeId = objectGraph.GetOrCreateGcType(rootName); ulongStack[0] = objectID; ObjectGraph.GcObject rootObject = objectGraph.CreateObject(rootTypeId, 1, ulongStack); objectGraph.AddRootObject(rootObject, rootID); } break; } case 'R': case 'r': { c = ReadChar(); thisIsR = true; if (extendedRootInfoSeen || pos < startFileOffset || pos >= endFileOffset) { while (c >= ' ') c = ReadChar(); break; } if (!previousWasR) { heapDumpEventList.AddEvent(lastTickIndex, null); if (readLogResult.objectGraph != null && !readLogResult.objectGraph.empty) { readLogResult.objectGraph.BuildTypeGraph(new FilterForm()); readLogResult.objectGraph.Neuter(); } readLogResult.objectGraph = new ObjectGraph(this, lastTickIndex); Histogram[] h = readLogResult.heapDumpHistograms; if (h != null) { readLogResult.heapDumpHistograms = new Histogram[h.Length+1]; for (int i = 0; i < h.Length; i++) readLogResult.heapDumpHistograms[i] = h[i]; readLogResult.heapDumpHistograms[h.Length] = new Histogram(this); } } stackPtr = 0; ulong objectID; while ((objectID = ReadULong()) != ulong.MaxValue) { if (objectID > 0) { ulongStack[stackPtr] = objectID; stackPtr++; if (stackPtr >= ulongStack.Length) ulongStack = GrowULongVector(ulongStack); } } if (c != -1) { if (readLogResult.objectGraph != null) readLogResult.objectGraph.AddRoots(stackPtr, ulongStack); } break; } case 'O': case 'o': { c = ReadChar(); if (pos < startFileOffset || pos >= endFileOffset || readLogResult.objectGraph == null) { while (c >= ' ') c = ReadChar(); break; } ulong objectId = ReadULong(); int typeIndex = ReadInt(); uint size = ReadUInt(); stackPtr = 0; ulong objectID; while ((objectID = ReadULong()) != ulong.MaxValue) { if (objectID > 0) { ulongStack[stackPtr] = objectID; stackPtr++; if (stackPtr >= ulongStack.Length) ulongStack = GrowULongVector(ulongStack); } } if (c != -1) { ObjectGraph objectGraph = readLogResult.objectGraph; objectGraph.GetOrCreateGcType(typeIndex); int typeSizeStackTraceId = -1; int allocTickIndex = 0; // try to find the allocation stack trace and allocation time // from the live object table if (readLogResult.liveObjectTable != null) { LiveObjectTable.LiveObject liveObject; readLogResult.liveObjectTable.GetNextObject(objectId, objectId, out liveObject); if (liveObject.id == objectId) { typeSizeStackTraceId = liveObject.typeSizeStacktraceIndex; allocTickIndex = liveObject.allocTickIndex; Histogram[] h = readLogResult.heapDumpHistograms; if (h != null) h[h.Length-1].AddObject(liveObject.typeSizeStacktraceIndex, 1); } } if (typeSizeStackTraceId == -1) typeSizeStackTraceId = stacktraceTable.GetOrCreateTypeSizeId(typeIndex, (int)size); ObjectGraph.GcObject gcObject = objectGraph.CreateAndEnterObject(objectId, typeSizeStackTraceId, stackPtr, ulongStack); gcObject.AllocTickIndex = allocTickIndex; } break; } case 'M': case 'm': { c = ReadChar(); int modIndex = ReadInt(); sb.Length = 0; while (c > '\r') { sb.Append((char)c); c = ReadChar(); } if (c != -1) { string lineString = sb.ToString(); int addrPos = lineString.LastIndexOf(" 0x"); if (addrPos <= 0) addrPos = lineString.Length; int backSlashPos = lineString.LastIndexOf(@"\"); if (backSlashPos <= 0) backSlashPos = -1; string basicName = lineString.Substring(backSlashPos + 1, addrPos - backSlashPos - 1); string fullName = lineString.Substring(0, addrPos); EnsureStringCapacity(modIndex, ref modBasicName); modBasicName[modIndex] = basicName; EnsureStringCapacity(modIndex, ref modFullName); modFullName[modIndex] = fullName; } break; } case 'U': case 'u': { c = ReadChar(); ulong oldId = ReadULong(); ulong newId = ReadULong(); uint length = ReadUInt(); Histogram reloHist = null; if (pos >= startFileOffset && pos < endFileOffset) reloHist = readLogResult.relocatedHistogram; if (readLogResult.liveObjectTable != null) readLogResult.liveObjectTable.UpdateObjects(reloHist, oldId, newId, length, lastTickIndex, readLogResult.sampleObjectTable); break; } case 'V': case 'v': { c = ReadChar(); ulong startId = ReadULong(); uint length = ReadUInt(); Histogram reloHist = null; if (pos >= startFileOffset && pos < endFileOffset) reloHist = readLogResult.relocatedHistogram; if (readLogResult.liveObjectTable != null) readLogResult.liveObjectTable.UpdateObjects(reloHist, startId, startId, length, lastTickIndex, readLogResult.sampleObjectTable); break; } case 'B': case 'b': c = ReadChar(); int startGC = ReadInt(); int induced = ReadInt(); int condemnedGeneration = ReadInt(); if (startGC != 0) newGcEvent = gcEventList.AddEvent(lastTickIndex, null); if (newGcEvent) { if (startGC != 0) { if (induced != 0) { for (int gen = 0; gen <= condemnedGeneration; gen++) inducedGcCount[gen]++; } } else { int condemnedLimit = condemnedGeneration; if (condemnedLimit == 2) condemnedLimit = 3; for (int gen = 0; gen <= condemnedLimit; gen++) { cumulativeGenerationSize[gen] += generationSize[gen]; gcCount[gen]++; } } } for (int gen = 0; gen <= 3; gen++) generationSize[gen] = 0; while (c >= ' ') { ulong rangeStart = ReadULong(); ulong rangeLength = ReadULong(); ulong rangeLengthReserved = ReadULong(); int rangeGeneration = ReadInt(); if (c == -1 || rangeGeneration < 0) break; if (readLogResult.liveObjectTable != null) { if (startGC != 0) { if (rangeGeneration > condemnedGeneration && condemnedGeneration != 2) readLogResult.liveObjectTable.Preserve(rangeStart, rangeLength, lastTickIndex); } else { readLogResult.liveObjectTable.GenerationInterval(rangeStart, rangeLength, rangeGeneration, lastTickIndex); } } generationSize[rangeGeneration] += rangeLength; } if (startGC == 0 && readLogResult.liveObjectTable != null) { readLogResult.liveObjectTable.RecordGc(lastTickIndex, condemnedGeneration, readLogResult.sampleObjectTable, false); } break; case 'L': case 'l': { c = ReadChar(); int isCritical = ReadInt(); ulong objectId = ReadULong(); if (pos >= startFileOffset && pos < endFileOffset && readLogResult.liveObjectTable != null) { // try to find the allocation stack trace and allocation time // from the live object table LiveObjectTable.LiveObject liveObject; readLogResult.liveObjectTable.GetNextObject(objectId, objectId, out liveObject); if (liveObject.id == objectId) { if (isCritical != 0 && readLogResult.criticalFinalizerHistogram != null) readLogResult.criticalFinalizerHistogram.AddObject(liveObject.typeSizeStacktraceIndex, 1); if (readLogResult.finalizerHistogram != null) readLogResult.finalizerHistogram.AddObject(liveObject.typeSizeStacktraceIndex, 1); } } break; } case 'I': case 'i': c = ReadChar(); int tickCount = ReadInt(); if (c != -1) { lastTickIndex = AddTimePos(tickCount, lastLineStartPos); if (maxTickIndex < lastTickIndex) maxTickIndex = lastTickIndex; } break; case 'G': case 'g': c = ReadChar(); int gcGen0Count = ReadInt(); int gcGen1Count = ReadInt(); int gcGen2Count = ReadInt(); // if the newer 'b' lines occur, disregard the 'g' lines. if (gcCount[0] == 0 && readLogResult.liveObjectTable != null) { if (c == -1 || gcGen0Count < 0) readLogResult.liveObjectTable.RecordGc(lastTickIndex, 0, readLogResult.sampleObjectTable, gcGen0Count < 0); else readLogResult.liveObjectTable.RecordGc(lastTickIndex, gcGen0Count, gcGen1Count, gcGen2Count, readLogResult.sampleObjectTable); } break; case 'N': case 'n': { c = ReadChar(); int funcIndex; int stackTraceIndex = ReadInt(); stackPtr = 0; int flag = ReadInt(); int matched = flag / 4; int hadTypeId = (flag & 2); bool hasTypeId = (flag & 1) == 1; if (hasTypeId) { intStack[stackPtr++] = ReadInt(); intStack[stackPtr++] = ReadInt(); } if (matched > 0 && c != -1) { /* use some other stack trace as a reference */ int otherStackTraceId = ReadInt(); otherStackTraceId = stacktraceTable.MapTypeSizeStacktraceId(otherStackTraceId); int[] stacktrace = stacktraceTable.IndexToStacktrace(otherStackTraceId); if (matched > stacktrace.Length - hadTypeId) matched = stacktrace.Length - hadTypeId; for(int i = 0; i < matched; i++) { int funcId = stacktrace[i + hadTypeId]; Debug.Assert(funcId < funcName.Length && funcName[funcId] != null); intStack[stackPtr++] = funcId; if (stackPtr >= intStack.Length) { intStack = GrowIntVector(intStack); } } } while ((funcIndex = ReadInt()) >= 0) { intStack[stackPtr] = funcIndex; stackPtr++; if (stackPtr >= intStack.Length) intStack = GrowIntVector(intStack); } if (c != -1) { stacktraceTable.Add(stackTraceIndex, intStack, stackPtr, hasTypeId); } break; } case 'y': case 'Y': { c = ReadChar(); int threadid = ReadInt(); if(!assembliesJustLoaded.ContainsKey(threadid)) { assembliesJustLoaded[threadid] = new List<string>(); } /* int assemblyId = */ ReadInt(); while (c == ' ' || c == '\t') { c = ReadChar(); } sb.Length = 0; while (c > '\r') { sb.Append((char)c); c = ReadChar(); } string assemblyName = sb.ToString(); assembliesJustLoaded[threadid].Add(assemblyName); break; } case 'S': case 's': { c = ReadChar(); int stackTraceIndex = ReadInt(); int funcIndex; stackPtr = 0; while ((funcIndex = ReadInt()) >= 0) { intStack[stackPtr] = funcIndex; stackPtr++; if (stackPtr >= intStack.Length) intStack = GrowIntVector(intStack); } if (c != -1) { stacktraceTable.Add(stackTraceIndex, intStack, stackPtr, false); } break; } case 'Z': case 'z': { sb.Length = 0; c = ReadChar(); while (c == ' ' || c == '\t') c = ReadChar(); while (c > '\r') { sb.Append((char)c); c = ReadChar(); } if (c != -1) { lastTickIndex = AddTimePos(lastLineStartPos); if (maxTickIndex < lastTickIndex) maxTickIndex = lastTickIndex; commentEventList.AddEvent(lastTickIndex, sb.ToString()); } break; } case 'H': case 'h': { c = ReadChar(); int threadId = ReadInt(); ulong handleId = ReadULong(); ulong initialObjectId = ReadULong(); int stacktraceId = ReadInt(); if (c != -1) { if (readLogResult.handleHash != null) readLogResult.handleHash[handleId] = new HandleInfo(threadId, handleId, initialObjectId, lastTickIndex, stacktraceId); if (readLogResult.createdHandlesHistogram != null) readLogResult.createdHandlesHistogram.AddObject(stacktraceId, 1); } break; } case 'J': case 'j': { c = ReadChar(); int threadId = ReadInt(); ulong handleId = ReadULong(); int stacktraceId = ReadInt(); if (c != -1) { if (readLogResult.handleHash != null) { if (readLogResult.handleHash.ContainsKey(handleId)) readLogResult.handleHash.Remove(handleId); else { // Console.WriteLine("Non-existent handle {0:x} destroyed in line {1}", handleId, line); int[] stacktrace = stacktraceTable.IndexToStacktrace(stacktraceId); for (int i = stacktrace.Length; --i >= 0; ) { Console.WriteLine(" {0}", funcName[stacktrace[i]]); } } } if (readLogResult.destroyedHandlesHistogram != null) readLogResult.destroyedHandlesHistogram.AddObject(stacktraceId, 1); } break; } default: { // just ignore the unknown while(c != '\n' && c != '\r') { c = ReadChar(); } break; } } while (c == ' ' || c == '\t') c = ReadChar(); if (c == '\r') c = ReadChar(); if (c == '\n') { c = ReadChar(); line++; } } // readLogResult.functionList.ReportCallCountSizes(readLogResult.callstackHistogram); } // catch (Exception) // { // throw new Exception(string.Format("Bad format in log file {0} line {1}", fileName, line)); // throw; // } finally { progressForm.Visible = false; progressForm.Dispose(); if (r != null) r.Close(); } }
int AddTimePos(int tick, long pos) { double time = tick*0.001; // The time stamps can not always be taken at face value. // The two problems we try to fix here are: // - the time may wrap around (after about 50 days). // - on some MP machines, different cpus could drift apart // We solve the first problem by adding 2**32*0.001 if the // time appears to jump backwards by more than 2**31*0.001. // We "solve" the second problem by ignoring time stamps // that still jump backward in time. double lastTime = 0.0; if (timePosIndex > 0) lastTime = timePos[timePosIndex-1].time; // correct possible wraparound while (time + (1L<<31)*0.001 < lastTime) time += (1L<<32)*0.001; // ignore times that jump backwards if (time < lastTime) return timePosIndex - 1; while (timePosCount >= timePos.Length) GrowTimePos(); // we have only 23 bits to encode allocation time. // to avoid running out for long running measurements, we decrease time resolution // as we chew up slots. below algorithm uses 1 millisecond resolution for the first // million slots, 2 milliseconds for the second million etc. this gives about // 2 million seconds time range or 23 days. This is if we really have a time stamp // every millisecond - if not, the range is much larger... double minimumTimeInc = 0.000999*(1<<timePosIndex/(maxTimePosCount/8)); if (timePosCount < maxTimePosCount && (time - lastTime >= minimumTimeInc)) { if (timePosIndex < timePosCount) { // This is the case where we read the file again for whatever reason Debug.Assert(timePos[timePosIndex].time == time && timePos[timePosIndex].pos == pos); return timePosIndex++; } else { timePos[timePosCount] = new TimePos(time, pos); timePosIndex++; return timePosCount++; } } else return timePosIndex - 1; }
// variant of above to give comments their own tick index int AddTimePos(long pos) { double lastTime = 0.0; if (timePosIndex > 0) lastTime = timePos[timePosIndex-1].time; while (timePosCount >= timePos.Length) GrowTimePos(); // stop giving comments their own tick index if we have already // burned half the available slots if (timePosCount < maxTimePosCount/2) { if (timePosIndex < timePosCount) { // This is the case where we read the file again for whatever reason Debug.Assert(timePos[timePosIndex].time == lastTime && timePos[timePosIndex].pos == pos); return timePosIndex++; } else { timePos[timePosCount] = new TimePos(lastTime, pos); timePosIndex++; return timePosCount++; } } else return timePosIndex - 1; }
const int maxTimePosCount = (1<<23)-1; // ~8,000,000 entries void GrowTimePos() { TimePos[] newTimePos = new TimePos[2*timePos.Length]; for (int i = 0; i < timePos.Length; i++) newTimePos[i] = timePos[i]; timePos = newTimePos; }