1 /* **************************************************************************** 2 * 3 * Copyright (c) Microsoft Corporation. 4 * 5 * This source code is subject to terms and conditions of the Apache License, Version 2.0. A 6 * copy of the license can be found in the License.html file at the root of this distribution. If 7 * you cannot locate the Apache License, Version 2.0, please send an email to 8 * dlr@microsoft.com. By using this source code in any fashion, you are agreeing to be bound 9 * by the terms of the Apache License, Version 2.0. 10 * 11 * You must not remove this notice, or any other, from this software. 12 * 13 * 14 * ***************************************************************************/ 15 16 #if FEATURE_CORE_DLR 17 using System.Linq.Expressions; 18 #else 19 using Microsoft.Scripting.Ast; 20 #endif 21 22 using System; 23 using System.Collections.Generic; 24 using System.Diagnostics; 25 using Microsoft.Scripting.Utils; 26 using System.Dynamic; 27 using System.IO; 28 29 namespace Microsoft.Scripting { 30 /// <summary> 31 /// This class is useful for quickly collecting performance counts for expensive 32 /// operations. Usually this means operations involving either reflection or 33 /// code gen. Long-term we need to see if this can be plugged better into the 34 /// standard performance counter architecture. 35 /// </summary> 36 public static class PerfTrack { 37 [System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Naming", "CA1717:OnlyFlagsEnumsShouldHavePluralNames")] // TODO: fix 38 [System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Design", "CA1034:NestedTypesShouldNotBeVisible")] // TODO: fix 39 public enum Categories { 40 /// <summary> 41 /// temporary categories for quick investigation, use a custom key if you 42 /// need to track multiple items, and if you want to keep it then create 43 /// a new Categories entry and rename all your temporary entries. 44 /// </summary> 45 Temporary, 46 ReflectedTypes, 47 Exceptions, // exceptions thrown 48 Properties, // properties got or set 49 Fields, // fields got or set 50 Methods, // methods called through MethodBase.Invoke()... 51 Compiler, // Methods compiled via the ReflectOptimizer 52 DelegateCreate, // we've created a new method for delegates 53 DictInvoke, // Dictionary accesses 54 OperatorInvoke, // Invoking an operator against a type 55 OverAllocate, // a spot where we have an un-ideal algorithm that needs to allocate more than necessary 56 Rules, // related to rules / actions. 57 RuleEvaluation, // a rule was evaluated 58 Binding, // a rule was bound 59 BindingSlow, 60 BindingFast, 61 BindingTarget, // a rule was bound against a target of a specific type 62 Count 63 } 64 65 [MultiRuntimeAware] 66 private static int totalEvents; 67 private static readonly Dictionary<Categories, Dictionary<string, int>> _events = MakeEventsDictionary(); 68 private static readonly Dictionary<Categories, int> summaryStats = new Dictionary<Categories, int>(); 69 MakeEventsDictionary()70 private static Dictionary<Categories, Dictionary<string, int>> MakeEventsDictionary() { 71 Dictionary<Categories, Dictionary<string, int>> result = new Dictionary<Categories, Dictionary<string, int>>(); 72 73 // We do not use Enum.GetValues here since it is not available in SILVERLIGHT 74 for (int i = 0; i <= (int)Categories.Count; i++) { 75 result[(Categories)i] = new Dictionary<string, int>(); 76 } 77 78 return result; 79 } 80 81 #if FEATURE_BASIC_CONSOLE DumpHistogram(IDictionary<TKey, int> histogram)82 public static void DumpHistogram<TKey>(IDictionary<TKey, int> histogram) { 83 DumpHistogram(histogram, Console.Out); 84 } 85 DumpStats()86 public static void DumpStats() { 87 DumpStats(Console.Out); 88 } 89 #endif 90 DumpHistogram(IDictionary<TKey, int> histogram, TextWriter output)91 public static void DumpHistogram<TKey>(IDictionary<TKey, int> histogram, TextWriter output) { 92 var keys = ArrayUtils.MakeArray(histogram.Keys); 93 var values = ArrayUtils.MakeArray(histogram.Values); 94 95 #if !WIN8 // TODO: 96 Array.Sort(values, keys); 97 #endif 98 for (int i = 0; i < keys.Length; i++) { 99 output.WriteLine("{0} {1}", keys[i], values[i]); 100 } 101 } 102 AddHistograms(IDictionary<TKey, int> result, IDictionary<TKey, int> addend)103 public static void AddHistograms<TKey>(IDictionary<TKey, int> result, IDictionary<TKey, int> addend) { 104 foreach (var entry in addend) { 105 int value; 106 result[entry.Key] = entry.Value + (result.TryGetValue(entry.Key, out value) ? value : 0); 107 } 108 } 109 IncrementEntry(IDictionary<TKey, int> histogram, TKey key)110 public static void IncrementEntry<TKey>(IDictionary<TKey, int> histogram, TKey key) { 111 int value; 112 histogram.TryGetValue(key, out value); 113 histogram[key] = value + 1; 114 } 115 DumpStats(TextWriter output)116 public static void DumpStats(TextWriter output) { 117 if (totalEvents == 0) return; 118 119 // numbers from AMD Opteron 244 1.8 Ghz, 2.00GB of ram, 120 // running on IronPython 1.0 Beta 4 against Whidbey RTM. 121 const double CALL_TIME = 0.0000051442355; 122 const double THROW_TIME = 0.000025365656; 123 const double FIELD_TIME = 0.0000018080093; 124 125 output.WriteLine(); 126 output.WriteLine("---- Performance Details ----"); 127 output.WriteLine(); 128 129 foreach (KeyValuePair<Categories, Dictionary<string, int>> kvpCategories in _events) { 130 if (kvpCategories.Value.Count > 0) { 131 output.WriteLine("Category : " + kvpCategories.Key); 132 DumpHistogram(kvpCategories.Value, output); 133 output.WriteLine(); 134 } 135 } 136 137 output.WriteLine(); 138 output.WriteLine("---- Performance Summary ----"); 139 output.WriteLine(); 140 double knownTimes = 0; 141 foreach (KeyValuePair<Categories, int> kvp in summaryStats) { 142 switch (kvp.Key) { 143 case Categories.Exceptions: 144 output.WriteLine("Total Exception ({0}) = {1} (throwtime = ~{2} secs)", kvp.Key, kvp.Value, kvp.Value * THROW_TIME); 145 knownTimes += kvp.Value * THROW_TIME; 146 break; 147 case Categories.Fields: 148 output.WriteLine("Total field = {0} (time = ~{1} secs)", kvp.Value, kvp.Value * FIELD_TIME); 149 knownTimes += kvp.Value * FIELD_TIME; 150 break; 151 case Categories.Methods: 152 output.WriteLine("Total calls = {0} (calltime = ~{1} secs)", kvp.Value, kvp.Value * CALL_TIME); 153 knownTimes += kvp.Value * CALL_TIME; 154 break; 155 //case Categories.Properties: 156 default: 157 output.WriteLine("Total {1} = {0}", kvp.Value, kvp.Key); 158 break; 159 } 160 } 161 162 output.WriteLine(); 163 output.WriteLine("Total Known Times: {0}", knownTimes); 164 } 165 166 [Conditional("DEBUG")] NoteEvent(Categories category, object key)167 public static void NoteEvent(Categories category, object key) { 168 if (!DebugOptions.TrackPerformance) return; 169 170 Dictionary<string, int> categoryEvents = _events[category]; 171 totalEvents++; 172 lock (categoryEvents) { 173 string name = key.ToString(); 174 Exception ex = key as Exception; 175 if (ex != null) name = ex.GetType().ToString(); 176 int v; 177 if (!categoryEvents.TryGetValue(name, out v)) categoryEvents[name] = 1; 178 else categoryEvents[name] = v + 1; 179 180 if (!summaryStats.TryGetValue(category, out v)) summaryStats[category] = 1; 181 else summaryStats[category] = v + 1; 182 } 183 } 184 } 185 } 186