Appearance
| 1 | namespace Logging is | |
| 2 | use IO.Std | |
| 3 | ||
| 4 | use System.Text.StringBuilder | |
| 5 | ||
| 6 | use Collections.MAP | |
| 7 | ||
| 8 | class TIMER is | |
| 9 | _name: string | |
| 10 | _execute_time: System.TimeSpan | |
| 11 | ||
| 12 | _started_at: System.DateTime | |
| 13 | ||
| 14 | name: string => _name | |
| 15 | ||
| 16 | valid: bool => execute_count > 0 | |
| 17 | execute_count: int | |
| 18 | average_milliseconds: double => _execute_time.divide(cast double(execute_count)).total_milliseconds | |
| 19 | moving_average_milliseconds: double | |
| 20 | ||
| 21 | max_average_milliseconds: double is | |
| 22 | if !valid then | |
| 23 | return 0.0D | |
| 24 | fi | |
| 25 | ||
| 26 | let result = average_milliseconds | |
| 27 | ||
| 28 | if result > moving_average_milliseconds then | |
| 29 | return result | |
| 30 | else | |
| 31 | return moving_average_milliseconds | |
| 32 | fi | |
| 33 | si | |
| 34 | ||
| 35 | init(name: string) is | |
| 36 | _name = name | |
| 37 | _execute_time = System.TimeSpan(0L) | |
| 38 | si | |
| 39 | ||
| 40 | start() is | |
| 41 | _started_at = System.DateTime.now | |
| 42 | si | |
| 43 | ||
| 44 | // Count an occurrence without timing it. For names used only as | |
| 45 | // counters the report renders count with zero accumulated time. | |
| 46 | bump() is | |
| 47 | execute_count = execute_count + 1 | |
| 48 | si | |
| 49 | ||
| 50 | finish() is | |
| 51 | let elapsed = System.DateTime.now.subtract(_started_at) | |
| 52 | ||
| 53 | execute_count = execute_count + 1 | |
| 54 | _execute_time = _execute_time.add(elapsed) | |
| 55 | ||
| 56 | moving_average_milliseconds = moving_average_milliseconds * 0.8D + elapsed.total_milliseconds * 0.2D | |
| 57 | si | |
| 58 | ||
| 59 | to_string() -> string => | |
| 60 | if execute_count > 0 then | |
| 61 | "{_name} count: {execute_count} total time: {_execute_time.total_milliseconds} average: {average_milliseconds} moving average: {moving_average_milliseconds:N3} ms" | |
| 62 | else | |
| 63 | "{_name} count: 0" | |
| 64 | fi | |
| 65 | si | |
| 66 | ||
| 67 | class TIMERS is | |
| 68 | _timers: MAP[string,TIMER] | |
| 69 | ||
| 70 | init() is | |
| 71 | _timers = MAP() | |
| 72 | si | |
| 73 | ||
| 74 | [name: string]: TIMER is | |
| 75 | if !_timers.contains_key(name) then | |
| 76 | _timers[name] = TIMER(name) | |
| 77 | fi | |
| 78 | ||
| 79 | return _timers[name] | |
| 80 | si | |
| 81 | ||
| 82 | all: Collections.Iterable[TIMER] => _timers.values | |
| 83 | ||
| 84 | // The names of the timers whose readings are reported to the | |
| 85 | // client as a request's elapsed time. Named here rather than | |
| 86 | // spelled out at each recording site: an accessor that names a | |
| 87 | // timer nothing records reads as an instant request rather than | |
| 88 | // as a mistake. | |
| 89 | compile_timer_name: string static => "compile" | |
| 90 | ||
| 91 | edit_single_timer_name: string static => "edit-single" | |
| 92 | ||
| 93 | edit_single_timer: TIMER => | |
| 94 | self[edit_single_timer_name] | |
| 95 | ||
| 96 | compile_timer: TIMER => | |
| 97 | self[compile_timer_name] | |
| 98 | ||
| 99 | start(name: string) is | |
| 100 | self[name].start() | |
| 101 | si | |
| 102 | ||
| 103 | finish(name: string) is | |
| 104 | self[name].finish() | |
| 105 | si | |
| 106 | ||
| 107 | bump(name: string) is | |
| 108 | self[name].bump() | |
| 109 | si | |
| 110 | ||
| 111 | // Create a counter without recording an occurrence, so a name | |
| 112 | // that has not fired still appears in the report at count zero. | |
| 113 | // The indexer creates on first read. | |
| 114 | declare(name: string) is | |
| 115 | let _ = self[name] | |
| 116 | si | |
| 117 | ||
| 118 | to_string() -> string => ( | |
| 119 | let result = StringBuilder() | |
| 120 | ||
| 121 | for t in _timers.values do | |
| 122 | if t.execute_count > 0 then | |
| 123 | result | |
| 124 | .append(t) | |
| 125 | .append('\n') | |
| 126 | fi | |
| 127 | od | |
| 128 | ||
| 129 | result.to_string() | |
| 130 | ) | |
| 131 | si | |
| 132 | si |