GCTracing.cs | searchcode

/base/Kernel/Singularity/GCTracing.cs

#
C# | 634 lines | 390 code | 157 blank | 87 comment | 51 complexity | a75b1a819e65eb459bc7a60b3df47b75 MD5 | raw file

////////////////////////////////////////////////////////////////////////////////

//

//  Microsoft Research Singularity

//

//  Copyright (c) Microsoft Corporation.  All rights reserved.

//

//  File:  GCTracing.cs

//

//  Note:  Provides logging facilities for the garbage collector.

//  This is intended to be used in both kernel and SIPs, SIPs

//  will get a private memory buffer for these entries, separated from the kernel log

//



using System;

using System.Diagnostics;

using System.Text;

using System.Runtime.InteropServices;

using System.Runtime.CompilerServices;

using System.Threading;

using Microsoft.Singularity;

using Microsoft.Singularity.Isal;

using System.GCs;

using System.Collections;

using Microsoft.Singularity.Memory;

using Microsoft.Singularity.V1.Services;    

using Microsoft.Singularity.Eventing;    





namespace Microsoft.Singularity

{

    [CLSCompliant(false)]

    [AccessedByRuntime("output to header - methods defined in GCTracing.cpp")]

    public class GCProfilerLogger : GCProfiler

    {



        [CLSCompliant(false)]

        public class GCTypeSource : EventSource {





            public static GCTypeSource Create(string sourceName, uint typeSize, ulong options) {

                uint qos = QualityOfService.PermanentEvents;

                if (options != 0) {

                    qos |= QualityOfService.OOM_BreakOnRecycle;

                }



                EventingStorage storage = EventingStorage.CreateLocalStorage(qos, typeSize);



                if (storage == null) {



                    return null;                                                  

                }

                

                GCTypeSource Logger  = new GCTypeSource(sourceName, 

                                                        storage,

                                                        ENABLE_ALL_MASK);



                if (Logger != null) {



                    Logger.Register();

                }



                return Logger;

            }



            GCTypeSource(string sourceName, EventingStorage storage, uint controlFlags) 

                :base(sourceName, storage, controlFlags) {}

          

        }



        [CLSCompliant(false)]

        public class GCEventSource : EventSource {





            public static GCEventSource Create(string sourceName, uint typeSize, ulong options) {

                uint qos = QualityOfService.RecyclableEvents;

                if (options != 0) {

                    qos |= QualityOfService.OOM_BreakOnRecycle;

                }



                EventingStorage storage = EventingStorage.CreateLocalStorage(qos, typeSize);



                if (storage == null) {



                    return null;                                                  

                }

                

                GCEventSource Logger  = new GCEventSource(sourceName, 

                                                          storage,

                                                          ENABLE_ALL_MASK);



                if (Logger != null) {



                    Logger.Register();

                }



                return Logger;

            }



            GCEventSource(string sourceName, EventingStorage storage, uint controlFlags) 

                :base(sourceName, storage, controlFlags) {}

          

        }



        

        [CLSCompliant(false)]

        [AccessedByRuntime("output to header - methods defined in GCTracing.cpp")]

        public class ProfilerBuffer

        {

            

            private const int   cycleGranularity = 5000000;

            public Thread       OwningThread;

            private ulong       lastCycle;

            private ulong       firstCycle;



#if LEGACY_GCTRACING



            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void SetupBuffer(byte * memoryBuffer, ulong bufferSize);



#endif  //  LEGACY_GCTRACING



            //

            //  ABI entries

            //



            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void LogGenerations(int maxGeneration, int * generations);



            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void LogInterval(ulong Delta);

            

            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void LogAllocation(int threadId, UIntPtr objectAddress, uint stkNo);

            

            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void LogObject(uint ArraySize, UIntPtr * objectParameters);



            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void LogRoots(uint ArraySize, UIntPtr * objectRoots);



            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void LogType(uint typeId, string typeName); 

            

            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void LogStack(uint stackNo, uint typeNo, UIntPtr size, uint stackSize, uint * funcIDs); // 'n'

            

            [AccessedByRuntime("output to header : defined in GCTracing.cpp")]

            [MethodImpl(MethodImplOptions.InternalCall)]

            [StackBound(256)]

            [NoHeapAllocation]

            public static extern unsafe void LogFunction(uint funcNo, UIntPtr eip);

            

            public ProfilerBuffer()

            {

                firstCycle = Processor.CycleCount;

            }

            

            //

            //  Local definitions

            //



            public void LogTick() {

                

                //  Log an entry describing the delta in cycles



                ulong nowCycle = Processor.CycleCount;



                // Emit a tick-count record only if it's been a while since the last one.

                if (nowCycle > lastCycle + cycleGranularity) {



                    lastCycle = nowCycle;

                    ProfilerBuffer.LogInterval((ulong) ((lastCycle - firstCycle) / 1000000));

                }

            }

        }



        //

        //  Local variables

        //

        

        private const int   maxGeneration = 3;        // CLR Profiler only handles this many

        private int[]       generations;

        ProfilerBuffer      Buffer;



        private Hashtable   typeTable;                // hash of types->ids

        private uint        nextTypeNo;               // hand out IDs monotonically



        private Hashtable   stackTable;               // hash of stacks->ids

        private uint        nextStackNo;

        private const int   stackSize = 16;           // increase for bigger / slower stack traces

        private UIntPtr[]   stackEips;

        private uint[]      stackNos;



        private Hashtable   funcTable;                // hash of Eips->ids

        private uint        nextFuncNo;

        private uint[]      functionsIDs;



        private Thread      recurseThread;            // prevent recursion when the profiler allocates

        private SpinLock    allocationLock;

        

        private bool        enabled;                  // profiling is enabled?

        

        private ulong       options;   



        private const uint  tempBufferSize = 1024;   

        private UIntPtr[]   tempGCBuffer;

        private uint        tempGCBufferEntries;



 #if LEGACY_GCTRACING

        private ulong       bufferSize;   

        private static unsafe byte * bufferMemory;



#else  // LEGACY_GCTRACING



        private GCTypeSource typeSource;

        private GCEventSource EventSource;



        [AccessedByRuntime("referenced from Monitoring.cpp")]

        private static unsafe UIntPtr TypeStorageHandle = 0;

        [AccessedByRuntime("referenced from Monitoring.cpp")]

        private static unsafe UIntPtr StorageHandle = 0;



#endif  //  LEGACY_GCTRACING

       

        

        internal GCProfilerLogger()

        {

#if SINGULARITY_KERNEL

            // Initialize spinlock

            allocationLock = new SpinLock(SpinLock.Types.GCTracing);

#endif

        }



        internal static GCProfilerLogger CurrentProfiler = null;



        // The public API for a typical client app.

        static public void StartProfiling()

        {

            //  Query the diagnosis service whether the GC profiling is enabled

            //  This allows setting from the kernel debugger the buffer sizes

            //  for both kernel and SIP profiling. 

            //  Note, these are controlled independently, the implementation

            //  of GCProfileSettings is different between kernel and SIP



            if (CurrentProfiler != null) {



                //

                //  The profiler has been set already. No second attempt is allowed

                //

                

                return;

            }

            

            unsafe{



                int result;

                ulong defaultMemorySize = 0;

                ulong Options = 0;



                result = DiagnosisService.GCProfileSettingsImpl(

                    out defaultMemorySize,

                    out Options

                    );



                if ((result == 0) && (defaultMemorySize > 0)) {

                    

                    CurrentProfiler = new GCProfilerLogger();

                    CurrentProfiler.Initialize(defaultMemorySize, Options);

                    GC.SetProfiler(CurrentProfiler);

                    DebugStub.WriteLine("GC Profiling started");

                }

            }

        }

        

        // Initialization, prior to attempting to set this profiler into the GC.  It's

        // inappropriate to do this stuff inside a constructor.

        internal void Initialize(ulong Size, ulong Flags)

        {

            options = Flags;

            typeTable = new Hashtable();

            stackTable = new Hashtable();

            funcTable = new Hashtable();

            stackEips = new UIntPtr[stackSize];

            stackNos = new uint[stackSize];

            generations = new int[maxGeneration];

            functionsIDs = new uint[stackSize];

            Buffer = new ProfilerBuffer();

            tempGCBuffer = new UIntPtr[tempBufferSize]; 

            tempGCBufferEntries = 0;

#if LEGACY_GCTRACING



            bufferSize = Size;   

            unsafe{



                //  Allocate the memory indicated as parameter, as nonGC



#if SINGULARITY_KERNEL

                UIntPtr pages = Microsoft.Singularity.Memory.MemoryManager.PagesFromBytes(bufferSize);

                bufferMemory = (byte *)Microsoft.Singularity.Memory.MemoryManager.KernelAllocate(

                    pages, null, 0, System.GCs.PageType.NonGC).ToPointer();

#else  // !SINGULARITY_KERNEL

        

                bufferMemory = (byte *)PageTableService.Allocate(bufferSize);



#endif  //SINGULARITY_KERNEL



                if (bufferMemory != null) {



                    // When we set this, we are no longer single-threaded:

                    ProfilerBuffer.SetupBuffer(bufferMemory, bufferSize);

                    this.enabled = true;

                }

            }

#else  // LEGACY_GCTRACING



            typeSource = GCTypeSource.Create("GC.TypeDefinitions", (uint)Size, options);

            EventSource = GCEventSource.Create("GC.Events", (uint)Size, options);



            if ((typeSource == null) || (EventSource == null)) {



                typeSource = null;

                EventSource = null;

                this.enabled = false;



            } else {



                TypeStorageHandle = typeSource.Storage.GetHandle();

                StorageHandle = EventSource.Storage.GetHandle();

                this.enabled = true;

            }



#endif // LEGACY_GCTRACING



        }



        // the API by which our base class calls us



        protected override void Shutdown()

        {

            // This is presumed to be called when the process is single-threaded, since

            // the entire GC heap is shutting down.

            if (enabled) {

                enabled = false;

            }

        }

        protected override void PreGC(int generation)

        {

            try {



                // Take ownership of the buffer to prevent mutating threads from

                // interleaving with us.

                

                DebugStub.Assert(Buffer.OwningThread == null);

                Buffer.OwningThread = Thread.CurrentThread;



                Buffer.LogTick();



                if (generation >= maxGeneration) {

                    generation = maxGeneration-1;

                }

                generations[generation]++;



                unsafe{

                    fixed (int * ptr = &generations[0]) {

                    

                        ProfilerBuffer.LogGenerations(maxGeneration, ptr);

                    }

                }

            }

            catch (Exception) {

                enabled = false;

                throw;

            }

        }



        // A GC has finished.  The world is in a sane place, except that we might not

        // have started up all the mutator threads if this is a StopTheWorld collection.

        protected override void PostGC()

        {

            try {

                // emit the fact a GC has happened, including the state of the heap.

                // TODO: have another function to log the tick count here to estimate the 

                // time spent in GC too.

                

                Buffer.LogTick();

                

                //  We should have an empty buffer, meaning we completed logging from the

                //  previous operation while entering this code.



                DebugStub.Assert(tempGCBufferEntries == 0);



                ScanRoots();



                unsafe{

                    fixed (UIntPtr * ptr = &tempGCBuffer[0]) {

                    

                        ProfilerBuffer.LogRoots(tempGCBufferEntries, ptr);

                        tempGCBufferEntries = 0;

                    }

                }



                // Write all the reachability graph of the heap

                ScanObjects();



                // Once we have finished writing everything, we can allow mutator threads to

                // share access to the fileBuffer with their own consistent entries.

                DebugStub.Assert(Buffer.OwningThread == Thread.CurrentThread);

                Buffer.OwningThread = null;

            }

            catch (Exception) {

                enabled = false;

                throw;

            }

        }



        // In the list of roots, we have found another object

        protected override void ScanOneRoot(UIntPtr objectAddress)

        {

            if (objectAddress != 0) {



                //

                //  If we filled in the temporary buffer, log it and resume

                //  from the beginning. 

                if (tempGCBufferEntries >= tempBufferSize) {

                    

                    unsafe {



                        fixed (UIntPtr * ptr = &tempGCBuffer[0]) {

                        

                            ProfilerBuffer.LogRoots(tempGCBufferEntries, ptr);

                            tempGCBufferEntries = 0;

                        }

                    }

                }

                tempGCBuffer[ tempGCBufferEntries++ ] = (UIntPtr)objectAddress;

            }

        }



        // In the heap reachability graph, we are starting to dump a new object

        protected override void StartScanOneObject(UIntPtr objectAddress, Type type, UIntPtr size)

        {



            DebugStub.Assert(tempGCBufferEntries == 0);

            

            tempGCBuffer[ tempGCBufferEntries++ ] = (UIntPtr)objectAddress;

            tempGCBuffer[ tempGCBufferEntries++ ] = (UIntPtr)GetTypeId(type);

            tempGCBuffer[ tempGCBufferEntries++ ] = (UIntPtr)size;

        }



        // This is one of the references that the current object holds.

        protected override void ScanOneObjectField(UIntPtr objectAddress)

        {

            if ((objectAddress != 0) && (tempGCBufferEntries < tempBufferSize)) {

                

                tempGCBuffer[ tempGCBufferEntries++ ] = (UIntPtr)objectAddress;

            }

        }



        // We are finished scanning one object

        protected override void EndScanOneObject()

        {

            unsafe{

                fixed (UIntPtr * ptr = &tempGCBuffer[0]) {

                

                    ProfilerBuffer.LogObject(tempGCBufferEntries, ptr);

                    tempGCBufferEntries = 0;

                }

            }

        }



        // Create a log entry for the allocation that just occurred on this thread.

        protected override void Allocation(UIntPtr objAddr, Type type, UIntPtr size)

        {

            bool iflag;



            // We cannot recurse inside an Allocation notification, or we will simply

            // blow the stack on the first entry.  Also, we don't want to log allocations

            // that occur as a consequence of logging the state of the GC heap -- though

            // we could support that if we chose to.



            if (enabled &&

                recurseThread != Thread.CurrentThread &&            // recurse?

                Buffer.OwningThread != Thread.CurrentThread) {      // GC logging?



                iflag = Processor.DisableLocalPreemption();

                allocationLock.Acquire();

                

                try {

                    

                    DebugStub.Assert(recurseThread == null);

                    recurseThread = Thread.CurrentThread;

                   

                    Buffer.LogTick();



                    uint stackSize = Isa.GetStackReturnAddresses(stackEips);

                    uint stkNo = 0;



                    if (stackSize > 0) {



                        stkNo = GetStackId(type, size, stackEips, stackSize);

                    }



                    ProfilerBuffer.LogAllocation(Thread.CurrentThread.GetThreadId(), objAddr, stkNo);

                }

                finally {

                    

                    recurseThread = null;

                    allocationLock.Release();

                    Processor.RestoreLocalPreemption(iflag);

                }

            }

        }



        // The rest of our implementation details:



        private uint GetStackId(Type type, UIntPtr size, UIntPtr[] stackEips, uint stackSize)

        {

            // First make sure that we have a type record for the object being

            // instantiated at this stack.



            uint typeNo = GetTypeId(type);



            DebugStub.Assert(stackSize <= stackEips.Length);



            // Then, make sure we have a function record for each Eip in the stack.  Of course

            // we don't know when a bunch of Eips map to different offsets in the same function.

            // So make a function for each unique Eip & fix it up in the post-processing.

            // Hopefully there aren't too many unique callsites in each method.

            

            ulong hash = typeNo; // perhaps "typeNo ^ size" ?

            

            for (int i = 0; i < stackSize; i++) {

                

                // Map the individual Eips into their corresponding functions

                stackNos[i] = GetFunctionId(stackEips[i]);

                hash = (hash << 11) + (hash ^ stackNos[i]);

            }



            // TODO: Note that we will statistically map some distinct stacks into the same

            // stack if they have the same hash.  

            object o = stackTable[hash];

            if (o != null) {

                return (uint) o;

            }



            // It's a novel stack.  Note that we embed the size into the stack, but we

            // don't include the size in the hash.  There's a technique for sharing

            // prefixes of stacks that could be explored here to get more accurate profiles

            // without huge stack expansion.

            // TODO: consider the above.



            uint stackNo = nextStackNo++;



            // Stacks are emitted backwards, presumably to support common prefixes better.

            for (int i = (int)stackSize - 1; i >= 0; i--) {



                functionsIDs[stackSize - 1 - i] = stackNos[i];

            }



            unsafe{

                fixed (uint * ptr = &functionsIDs[0]) {

                

                    ProfilerBuffer.LogStack(stackNo, typeNo, size, stackSize, ptr);

                }

            }

            stackTable[hash] = stackNo;



            return stackNo;

        }



        private uint GetFunctionId(UIntPtr eip)

        {

            // Given the EIP of a Function, make sure the function has been defined.  Since we

            // don't have enough runtime information to map Eips to functions, we must rely on

            // post-processing.

            object o = funcTable[eip];

            if (o != null) {

                return (uint) o;

            }



            uint funcNo = nextFuncNo++;

            ProfilerBuffer.LogFunction(funcNo, eip);

            funcTable[eip] = funcNo;



            return funcNo;

        }



        private uint GetTypeId(Type type)

        {

            // Given a Type, make sure that it has been defined.

            object o = typeTable[type];

            

            if (o != null) {

                return (uint) o;

            }



            uint typeNo = nextTypeNo++;



            // Log this entry before putting it into the hashtable, where other threads might

            // see it.  This means we may have duplicate conflicting entries for the same logical

            // type, but this is tolerated by the profiler.

            

            ProfilerBuffer.LogType(typeNo, type.FullName);



            typeTable[type] = typeNo;

            return typeNo;

        }



    }

}