Exemple #1
0
        static void Main(string[] argv)
        {
            BlockData.DebugLog = Console.Out;

            if (argv.Length != 1)
            {
                Console.WriteLine("Please specify one input file");
                return;
            }
            SyncLogFileReader    reader = new SyncLogFileReader(argv [0]);
            ProfilerEventHandler data   = new ProfilerEventHandler();

            data.LoadedElements.RecordHeapSnapshots = false;
            while (!reader.HasEnded)
            {
                BlockData currentBlock = null;
                try {
                    currentBlock = reader.ReadBlock();
                    currentBlock.Decode(data, reader);
                } catch (DecodingException e) {
                    Console.WriteLine("Stopping decoding after a DecodingException in block of code {0}, length {1}, file offset {2}, block offset {3}: {4}", e.FailingData.Code, e.FailingData.Length, e.FailingData.FileOffset, e.OffsetInBlock, e.Message);
                    break;
                }
            }

            PrintData(Console.Out, data);
        }
Exemple #2
0
        static void PrintClassAllocationData(TextWriter writer, ProfilerEventHandler data, LoadedClass c, ulong totalAllocatedBytes)
        {
            double allocatedBytesPerClass = (double)c.AllocatedBytes;

            writer.WriteLine("{0,5:F2}% ({1} bytes) {2}", ((allocatedBytesPerClass / totalAllocatedBytes) * 100), c.AllocatedBytes, c.Name);

            if (data.Directives.AllocationsHaveStackTrace)
            {
                LoadedClass.AllocationsPerMethod[] allocationsPerMethodArray = c.Methods;
                double cumulativeAllocatedBytesPerMethod = 0;

                if (c.MethodsAtJitTimeCount > 0)
                {
                    LoadedClass.AllocationsPerMethod[] allocationsPerMethodAtJitTime = c.MethodsAtJitTime;
                    LoadedClass.AllocationsPerMethod[] totalAllocationsPerMethod     = new LoadedClass.AllocationsPerMethod [allocationsPerMethodArray.Length + allocationsPerMethodAtJitTime.Length];
                    Array.Copy(allocationsPerMethodArray, totalAllocationsPerMethod, allocationsPerMethodArray.Length);
                    Array.Copy(allocationsPerMethodAtJitTime, 0, totalAllocationsPerMethod, allocationsPerMethodArray.Length, allocationsPerMethodAtJitTime.Length);
                    allocationsPerMethodArray = totalAllocationsPerMethod;
                }

                if (allocationsPerMethodArray.Length != 0)
                {
                    Array.Sort(allocationsPerMethodArray, LoadedClass.AllocationsPerMethod.CompareByAllocatedBytes);
                    Array.Reverse(allocationsPerMethodArray);

                    foreach (LoadedClass.AllocationsPerMethod allocationsPerMethod in allocationsPerMethodArray)
                    {
                        PrintMethodAllocationsPerClass(writer, allocationsPerMethod, false, cumulativeAllocatedBytesPerMethod < allocatedBytesPerClass * 0.7, 0.7);
                        cumulativeAllocatedBytesPerMethod += (double)allocationsPerMethod.AllocatedBytes;
                    }
                }
            }
            else
            {
                LoadedClass.AllocationsPerMethod[] allocationsPerMethodArray = c.Methods;
                if (allocationsPerMethodArray.Length != 0)
                {
                    Array.Sort(allocationsPerMethodArray, LoadedClass.AllocationsPerMethod.CompareByAllocatedBytes);
                    Array.Reverse(allocationsPerMethodArray);

                    foreach (LoadedClass.AllocationsPerMethod allocationsPerMethod in allocationsPerMethodArray)
                    {
                        PrintMethodAllocationsPerClass(writer, allocationsPerMethod, false, false, 0);
                    }
                }
                if (c.MethodsAtJitTimeCount > 0)
                {
                    allocationsPerMethodArray = c.MethodsAtJitTime;
                    Array.Sort(allocationsPerMethodArray, LoadedClass.AllocationsPerMethod.CompareByAllocatedBytes);
                    Array.Reverse(allocationsPerMethodArray);
                    foreach (LoadedClass.AllocationsPerMethod allocationsPerMethod in allocationsPerMethodArray)
                    {
                        PrintMethodAllocationsPerClass(writer, allocationsPerMethod, true, false, 0);
                    }
                }
            }
        }
        void InitializeBlocks()
        {
            uint         fileOffset = 0;
            bool         hasEnded   = false;
            List <Block> result     = new List <Block> ();
            ulong        counter    = 0;

            byte [] header = new byte [BlockData.BLOCK_HEADER_SIZE];
            ProfilerEventHandler eventProcessor = new ProfilerEventHandler();

            while (!hasEnded)
            {
                int bytesRead = stream.Read(header, 0, BlockData.BLOCK_HEADER_SIZE);
                if (bytesRead != BlockData.BLOCK_HEADER_SIZE)
                {
                    if (bytesRead == 0)
                    {
                        Console.WriteLine("WARNING: File truncated at offset {0} without end block", fileOffset);
                        break;
                    }
                    else
                    {
                        throw new Exception(String.Format("At file offset {0} block header is not complete", fileOffset));
                    }
                }
                fileOffset += (uint)BlockData.BLOCK_HEADER_SIZE;
                counter    += BlockData.DecodeHeaderBlockCounterDelta(header);

                Block block = new Block(fileOffset, BlockData.DecodeHeaderBlockCode(header), (uint)BlockData.DecodeHeaderBlockLength(header), counter);
                result.Add(block);

                fileOffset += block.Length;
                stream.Seek(fileOffset, SeekOrigin.Begin);
                if (block.Code == BlockCode.INTRO)
                {
                    ReadBlock(block).Decode(eventProcessor);
                    startCounter = eventProcessor.StartCounter;
                    startTime    = eventProcessor.StartTime;
                }
                if (block.Code == BlockCode.END)
                {
                    hasEnded = true;
                    ReadBlock(block).Decode(eventProcessor);
                    endCounter = eventProcessor.EndCounter;
                    endTime    = eventProcessor.EndTime;
                }
            }

            blocks = result.ToArray();

            foreach (Block block in blocks)
            {
                block.TimeFromStart = eventProcessor.ClicksToTimeSpan(block.Counter);
            }
        }
 public GcStatistics(ProfilerEventHandler data, uint collection)
 {
     this.data         = data;
     this.collection   = collection;
     startCounter      = 0;
     endCounter        = 0;
     markStartCounter  = 0;
     markEndCounter    = 0;
     sweepStartCounter = 0;
     sweepEndCounter   = 0;
     generation        = 0;
     newHeapSize       = null;
 }
Exemple #5
0
        static void PrintExecutionTimeByCallStack(TextWriter writer, ProfilerEventHandler data, StackTrace stackFrame, double callerSeconds, int indentationLevel)
        {
            for (int i = 0; i < indentationLevel; i++)
            {
                writer.Write("    ");
            }
            LoadedMethod currentMethod  = stackFrame.TopMethod;
            double       currentSeconds = data.ClicksToSeconds(stackFrame.Clicks);

            writer.WriteLine("{0,5:F2}% ({1:F6}s, {2} calls) {3}.{4}", ((currentSeconds / callerSeconds) * 100), currentSeconds, stackFrame.Calls, currentMethod.Class.Name, currentMethod.Name);
            foreach (StackTrace calledFrame in stackFrame.CalledFrames)
            {
                PrintExecutionTimeByCallStack(writer, data, calledFrame, currentSeconds, indentationLevel + 1);
            }
        }
Exemple #6
0
        static void PrintData(TextWriter writer, ProfilerEventHandler data)
        {
            LoadedClass[]         classes             = data.LoadedElements.Classes;
            LoadedMethod[]        methods             = data.LoadedElements.Methods;
            IStatisticalHitItem[] statisticalHitItems = data.StatisticalHitItems;

            if ((data.Flags & ProfilerFlags.CLASS_EVENTS) != 0)
            {
                Array.Sort(classes, LoadedClass.CompareByAllocatedBytes);
                Array.Reverse(classes);
                ulong totalAllocatedBytes = 0;
                foreach (LoadedClass c in classes)
                {
                    totalAllocatedBytes += c.AllocatedBytes;
                }
                if (totalAllocatedBytes > 0)
                {
                    PrintSeparator(writer);
                    writer.WriteLine("Reporting allocations (on {0} classes)", classes.Length);
                    foreach (LoadedClass c in classes)
                    {
                        if (c.AllocatedBytes > 0)
                        {
                            PrintClassAllocationData(writer, data, c, totalAllocatedBytes);
                        }
                    }
                }
                else
                {
                    writer.WriteLine("No allocations reported (on {0} classes)", classes.Length);
                }
            }
            if ((data.Flags & ProfilerFlags.METHOD_EVENTS) != 0)
            {
                Array.Sort(methods, LoadedMethod.CompareByTotalClicks);
                Array.Reverse(methods);
                ulong totalExecutionClicks = 0;
                foreach (LoadedMethod m in methods)
                {
                    totalExecutionClicks += m.Clicks;
                }
                if (totalExecutionClicks > 0)
                {
                    PrintSeparator(writer);
                    writer.WriteLine("Reporting execution time (on {0} methods)", methods.Length);
                    foreach (LoadedMethod m in methods)
                    {
                        if (m.Clicks > 0)
                        {
                            writer.WriteLine("{0,5:F2}% ({1:F6}s) {2}.{3}", ((((double)m.Clicks) / totalExecutionClicks) * 100), data.ClicksToSeconds(m.Clicks), m.Class.Name, m.Name);
                            LoadedMethod.CallsPerCallerMethod[] callsPerCallerMethodArray = m.Callers;
                            if (callsPerCallerMethodArray.Length > 0)
                            {
                                Array.Sort(callsPerCallerMethodArray, LoadedMethod.CallsPerCallerMethod.CompareByCalls);
                                Array.Reverse(callsPerCallerMethodArray);
                                foreach (LoadedMethod.CallsPerCallerMethod callsPerCallerMethod in callsPerCallerMethodArray)
                                {
                                    writer.WriteLine("        {0} calls from {1}.{2}", callsPerCallerMethod.Calls, callsPerCallerMethod.Callees.Class.Name, callsPerCallerMethod.Callees.Name);
                                }
                            }
                        }
                    }

                    PrintSeparator(writer);
                    writer.WriteLine("Reporting execution time by stack frame");
                    foreach (StackTrace rootFrame in data.RootFrames)
                    {
                        PrintExecutionTimeByCallStack(writer, data, rootFrame, data.ClicksToSeconds(totalExecutionClicks), 0);
                    }
                }
                else
                {
                    writer.WriteLine("No execution time reported (on {0} methods)", methods.Length);
                }
            }
            if ((data.Flags & ProfilerFlags.JIT_COMPILATION) != 0)
            {
                Array.Sort(methods, LoadedMethod.CompareByJitClicks);
                Array.Reverse(methods);
                ulong totalJitClicks = 0;
                foreach (LoadedMethod m in methods)
                {
                    totalJitClicks += m.JitClicks;
                }
                if (totalJitClicks > 0)
                {
                    PrintSeparator(writer);
                    writer.WriteLine("Reporting jit time (on {0} methods)", methods.Length);
                    foreach (LoadedMethod m in methods)
                    {
                        if (m.JitClicks > 0)
                        {
                            writer.WriteLine("{0,5:F2}% ({1:F3}ms) {2}.{3}", ((((double)m.JitClicks) / totalJitClicks) * 100), data.ClicksToSeconds(m.JitClicks) * 1000, m.Class.Name, m.Name);
                        }
                    }
                }
                else
                {
                    writer.WriteLine("No jit time reported (on {0} methods)", methods.Length);
                }
            }
            if ((data.Flags & ProfilerFlags.STATISTICAL) != 0)
            {
                Array.Sort(statisticalHitItems, StatisticalHitItemCallCounts.CompareByStatisticalHits);
                Array.Reverse(statisticalHitItems);
                ulong totalHits = 0;
                foreach (IStatisticalHitItem s in statisticalHitItems)
                {
                    totalHits += s.StatisticalHits;
                }
                if (totalHits > 0)
                {
                    PrintSeparator(writer);
                    writer.WriteLine("Reporting statistical hits ({0} hits recorded)", totalHits);
                    foreach (IStatisticalHitItem s in statisticalHitItems)
                    {
                        if ((s.StatisticalHits > 0) || s.HasCallCounts)
                        {
                            writer.WriteLine("{0,5:F2}% ({1}) {2}", ((((double)s.StatisticalHits) / totalHits) * 100), s.StatisticalHits, s.Name);
                            if (s.HasCallCounts)
                            {
                                StatisticalHitItemCallCounts callCounts = s.CallCounts;
                                if (callCounts.CallersCount > 0)
                                {
                                    StatisticalHitItemCallInformation[] calls = callCounts.Callers;
                                    foreach (StatisticalHitItemCallInformation call in calls)
                                    {
                                        writer.WriteLine("    {0} calls from {1}", call.Calls, call.Item.Name);
                                    }
                                }
                                if (callCounts.CalleesCount > 0)
                                {
                                    StatisticalHitItemCallInformation[] calls = callCounts.Callees;
                                    foreach (StatisticalHitItemCallInformation call in calls)
                                    {
                                        writer.WriteLine("    {0} calls to {1}", call.Calls, call.Item.Name);
                                    }
                                }
                            }
                        }
                    }
                }
                else
                {
                    writer.WriteLine("No statistical hits reported (on {0} items)", statisticalHitItems.Length);
                }
            }

            if (data.GlobalMonitorStatistics.ContainsData)
            {
                PrintSeparator(writer);
                writer.WriteLine("Reporting monitor statistics.");
                data.GlobalMonitorStatistics.WriteStatistics(writer, data);
            }

            ProfilerEventHandler.GcStatistics[] gcStatistics = data.GarbageCollectioncStatistics;
            if (gcStatistics.Length > 0)
            {
                double totalTime   = data.ClicksToSeconds(data.EndCounter - data.StartCounter);
                double gcTime      = 0;
                double gcMarkTime  = 0;
                double gcSweepTime = 0;
                int    collections = 0;
                foreach (ProfilerEventHandler.GcStatistics gcs in gcStatistics)
                {
                    if (gcs.NewHeapSize == null)
                    {
                        collections++;
                        gcTime      += gcs.Duration;
                        gcMarkTime  += gcs.MarkDuration;
                        gcSweepTime += gcs.SweepDuration;
                    }
                }

                PrintSeparator(writer);
                writer.WriteLine("Reporting GC statistics for {0} collections (total {1:F3}ms, {2,5:F2}% of total time, mark {3,5:F2}%, sweep {4,5:F2}%)",
                                 collections,
                                 gcTime * 1000,
                                 (gcTime / totalTime) * 100,
                                 (gcMarkTime / gcTime) * 100,
                                 (gcSweepTime / gcTime) * 100);
                foreach (ProfilerEventHandler.GcStatistics gcs in gcStatistics)
                {
                    if (gcs.NewHeapSize == null)
                    {
                        ulong gcStartClicks = gcs.StartCounter - data.StartCounter;
                        writer.WriteLine("[{0}] Collection starting at {1:F3}s (generation {2}): duration {3:F3}ms, mark {4:F3}ms, sweep {5:F3}ms",
                                         gcs.Collection,
                                         data.ClicksToSeconds(gcStartClicks),
                                         gcs.Generation,
                                         gcs.Duration * 1000,
                                         gcs.MarkDuration * 1000,
                                         gcs.SweepDuration * 1000);
                    }
                    else
                    {
                        writer.WriteLine("[{0}] Heap resized to {1} bytes", gcs.Collection, gcs.NewHeapSize);
                    }
                }
            }

            AllocationSummary [] allocationSummaries = data.AllocationSummaries;
            if (allocationSummaries.Length > 0)
            {
                PrintSeparator(writer);
                writer.WriteLine("Reporting allocation summaries for {0} collections", allocationSummaries.Length);
                foreach (AllocationSummary allocationSummary in allocationSummaries)
                {
                    writer.WriteLine("Data for collection {0} written {1:F3}s since the application started",
                                     allocationSummary.Collection, ((double)(allocationSummary.StartTime - data.StartTime).Milliseconds) / 1000);
                    AllocationClassData <LoadedClass>[] classData = allocationSummary.Data;
                    foreach (AllocationClassData <LoadedClass> cData in classData)
                    {
                        writer.WriteLine("  Class {0}: {1} bytes in {2} instances (freed: {3} bytes in {4} instances)",
                                         cData.Class.Name,
                                         cData.ReachableBytes,
                                         cData.ReachableInstances,
                                         cData.UnreachableBytes,
                                         cData.UnreachableInstances);
                    }
                }
            }

            HeapSnapshot[] heapSnapshots = data.LoadedElements.HeapSnapshots;
            if (heapSnapshots.Length > 0)
            {
                PrintSeparator(writer);
                writer.WriteLine("Reporting heap data for {0} collections", heapSnapshots.Length);
                foreach (HeapSnapshot heapSnapshot in heapSnapshots)
                {
                    HeapSnapshot.AllocationStatisticsPerClass [] allocationStatistics = heapSnapshot.AllocationStatistics;
                    writer.WriteLine("Heap data collection {0} started at {1} (duration {2:F3}ms)",
                                     heapSnapshot.Collection,
                                     data.CounterToDateTime(heapSnapshot.StartCounter),
                                     data.ClicksToSeconds(heapSnapshot.EndCounter - heapSnapshot.StartCounter) * 1000);
                    if (allocationStatistics.Length > 0)
                    {
                        Array.Sort(allocationStatistics, HeapSnapshot.AllocationStatisticsPerClass.CompareByAllocatedBytes);
                        Array.Reverse(allocationStatistics);
                        uint totalAllocatedBytes = 0;
                        foreach (HeapSnapshot.AllocationStatisticsPerClass s in allocationStatistics)
                        {
                            totalAllocatedBytes += s.AllocatedBytes;
                        }
                        foreach (HeapSnapshot.AllocationStatisticsPerClass s in allocationStatistics)
                        {
                            if (s.AllocatedBytes > 0)
                            {
                                writer.WriteLine("    {0,5:F2}% {1} {2} bytes ({3} freed)", ((((double)s.AllocatedBytes) / totalAllocatedBytes) * 100), s.Class.Name, s.AllocatedBytes, s.FreedBytes);
                            }
                        }
                    }
                    else
                    {
                        writer.WriteLine("No allocation statistics for this collection)", statisticalHitItems.Length);
                    }
                }
            }
        }