Skip to content

Commit c0c7bb5

Browse files
authored
print stats with --times (#18930)
1 parent e0100ac commit c0c7bb5

File tree

5 files changed

+188
-86
lines changed

5 files changed

+188
-86
lines changed

src/Compiler/Checking/TypeRelations.fs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -35,8 +35,8 @@ let getTypeSubsumptionCache =
3535
let factory (g: TcGlobals) =
3636
let options =
3737
match g.compilationMode with
38-
| CompilationMode.OneOff -> Caches.CacheOptions.getDefault() |> Caches.CacheOptions.withNoEviction
39-
| _ -> { Caches.CacheOptions.getDefault() with TotalCapacity = 65536; HeadroomPercentage = 75 }
38+
| CompilationMode.OneOff -> Caches.CacheOptions.getDefault HashIdentity.Structural |> Caches.CacheOptions.withNoEviction
39+
| _ -> { Caches.CacheOptions.getDefault HashIdentity.Structural with TotalCapacity = 65536; HeadroomPercentage = 75 }
4040
new Caches.Cache<TTypeCacheKey, bool>(options, "typeSubsumptionCache")
4141
Extras.WeakMap.getOrCreate factory
4242

src/Compiler/Driver/fsc.fs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -569,6 +569,7 @@ let main1
569569
exiter.Exit 1
570570

571571
if tcConfig.showTimes then
572+
Caches.CacheMetrics.CaptureStatsAndWriteToConsole() |> disposables.Register
572573
Activity.Profiling.addConsoleListener () |> disposables.Register
573574

574575
tcConfig.writeTimesToFile

src/Compiler/Utilities/Caches.fs

Lines changed: 159 additions & 58 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ open System.Collections.Concurrent
77
open System.Threading
88
open System.Diagnostics
99
open System.Diagnostics.Metrics
10+
open System.IO
1011

1112
module CacheMetrics =
1213
let Meter = new Meter("FSharp.Compiler.Cache")
@@ -22,57 +23,153 @@ module CacheMetrics =
2223
let creations = Meter.CreateCounter<int64>("creations", "count")
2324
let disposals = Meter.CreateCounter<int64>("disposals", "count")
2425

25-
let mkTag name = KeyValuePair<_, obj>("name", name)
26+
let mutable private nextCacheId = 0
2627

27-
let Add (tag: KeyValuePair<_, _>) = adds.Add(1L, tag)
28-
let Update (tag: KeyValuePair<_, _>) = updates.Add(1L, tag)
29-
let Hit (tag: KeyValuePair<_, _>) = hits.Add(1L, tag)
30-
let Miss (tag: KeyValuePair<_, _>) = misses.Add(1L, tag)
31-
let Eviction (tag: KeyValuePair<_, _>) = evictions.Add(1L, tag)
32-
let EvictionFail (tag: KeyValuePair<_, _>) = evictionFails.Add(1L, tag)
33-
let Created (tag: KeyValuePair<_, _>) = creations.Add(1L, tag)
34-
let Disposed (tag: KeyValuePair<_, _>) = disposals.Add(1L, tag)
28+
let mkTags (name: string) =
29+
let cacheId = Interlocked.Increment &nextCacheId
30+
// Avoid TagList(ReadOnlySpan<...>) to support net472 runtime
31+
let mutable tags = TagList()
32+
tags.Add("name", box name)
33+
tags.Add("cacheId", box cacheId)
34+
tags
3535

36-
// Currently the Cache emits telemetry for raw cache events: hits, misses, evictions etc.
37-
// This class observes those counters and keeps a snapshot of readings. It is used in tests and can be used to print cache stats in debug mode.
38-
type CacheMetricsListener(tag) =
39-
let totals = Map [ for counter in CacheMetrics.allCounters -> counter.Name, ref 0L ]
36+
let Add (tags: inref<TagList>) = adds.Add(1L, &tags)
37+
let Update (tags: inref<TagList>) = updates.Add(1L, &tags)
38+
let Hit (tags: inref<TagList>) = hits.Add(1L, &tags)
39+
let Miss (tags: inref<TagList>) = misses.Add(1L, &tags)
40+
let Eviction (tags: inref<TagList>) = evictions.Add(1L, &tags)
41+
let EvictionFail (tags: inref<TagList>) = evictionFails.Add(1L, &tags)
42+
let Created (tags: inref<TagList>) = creations.Add(1L, &tags)
43+
let Disposed (tags: inref<TagList>) = disposals.Add(1L, &tags)
4044

41-
let incr key v =
42-
Interlocked.Add(totals[key], v) |> ignore
45+
type Stats() =
46+
let totals = Map [ for counter in allCounters -> counter.Name, ref 0L ]
47+
let total key = totals[key].Value
4348

44-
let total key = totals[key].Value
49+
let mutable ratio = Double.NaN
4550

46-
let mutable ratio = Double.NaN
51+
let updateRatio () =
52+
ratio <- float (total hits.Name) / float (total hits.Name + total misses.Name)
4753

48-
let updateRatio () =
49-
ratio <-
50-
float (total CacheMetrics.hits.Name)
51-
/ float (total CacheMetrics.hits.Name + total CacheMetrics.misses.Name)
54+
member _.Incr key v =
55+
assert (totals.ContainsKey key)
56+
Interlocked.Add(totals[key], v) |> ignore
5257

53-
let listener = new MeterListener()
58+
if key = hits.Name || key = misses.Name then
59+
updateRatio ()
5460

55-
do
61+
member _.GetTotals() =
62+
[ for k in totals.Keys -> k, total k ] |> Map.ofList
63+
64+
member _.Ratio = ratio
65+
66+
override _.ToString() =
67+
let parts =
68+
[
69+
for kv in totals do
70+
yield $"{kv.Key}={kv.Value.Value}"
71+
if not (Double.IsNaN ratio) then
72+
yield $"hit-ratio={ratio:P2}"
73+
]
74+
75+
String.Join(", ", parts)
76+
77+
let statsByName = ConcurrentDictionary<string, Stats>()
78+
79+
let getStatsByName name =
80+
statsByName.GetOrAdd(name, fun _ -> Stats())
81+
82+
let ListenToAll () =
83+
let listener = new MeterListener()
5684

57-
for instrument in CacheMetrics.allCounters do
85+
for instrument in allCounters do
5886
listener.EnableMeasurementEvents instrument
5987

6088
listener.SetMeasurementEventCallback(fun instrument v tags _ ->
61-
if tags[0] = tag then
62-
incr instrument.Name v
63-
64-
if instrument = CacheMetrics.hits || instrument = CacheMetrics.misses then
65-
updateRatio ())
89+
match tags[0].Value with
90+
| :? string as name ->
91+
let stats = getStatsByName name
92+
stats.Incr instrument.Name v
93+
| _ -> assert false)
6694

6795
listener.Start()
96+
listener :> IDisposable
97+
98+
let StatsToString () =
99+
use sw = new StringWriter()
100+
101+
let nameColumnWidth =
102+
[ yield! statsByName.Keys; "Cache name" ] |> Seq.map String.length |> Seq.max
103+
104+
let columns = allCounters |> List.map _.Name
105+
let columnWidths = columns |> List.map String.length |> List.map (max 8)
106+
107+
let header =
108+
"| "
109+
+ String.concat
110+
" | "
111+
[
112+
"Cache name".PadRight nameColumnWidth
113+
"hit-ratio"
114+
for w, c in (columnWidths, columns) ||> List.zip do
115+
$"{c.PadLeft w}"
116+
]
117+
+ " |"
118+
119+
sw.WriteLine(String('-', header.Length))
120+
sw.WriteLine(header)
121+
sw.WriteLine(header |> String.map (fun c -> if c = '|' then '|' else '-'))
122+
123+
for kv in statsByName do
124+
let name = kv.Key
125+
let stats = kv.Value
126+
let totals = stats.GetTotals()
127+
sw.Write $"| {name.PadLeft nameColumnWidth} | {stats.Ratio, 9:P2} |"
128+
129+
for w, c in (columnWidths, columns) ||> List.zip do
130+
sw.Write $" {totals[c].ToString().PadLeft(w)} |"
131+
132+
sw.WriteLine()
133+
134+
sw.WriteLine(String('-', header.Length))
135+
string sw
136+
137+
let CaptureStatsAndWriteToConsole () =
138+
let listener = ListenToAll()
139+
140+
{ new IDisposable with
141+
member _.Dispose() =
142+
listener.Dispose()
143+
Console.WriteLine(StatsToString())
144+
}
68145

69-
interface IDisposable with
70-
member _.Dispose() = listener.Dispose()
146+
// Currently the Cache emits telemetry for raw cache events: hits, misses, evictions etc.
147+
// This type observes those counters and keeps a snapshot of readings. It is used in tests and can be used to print cache stats in debug mode.
148+
type CacheMetricsListener(cacheTags: TagList) =
149+
150+
let stats = Stats()
151+
let listener = new MeterListener()
152+
153+
do
154+
for instrument in allCounters do
155+
listener.EnableMeasurementEvents instrument
156+
157+
listener.SetMeasurementEventCallback(fun instrument v tags _ ->
158+
let tagsMatch = tags[0] = cacheTags[0] && tags[1] = cacheTags[1]
71159

72-
member _.GetTotals() =
73-
[ for k in totals.Keys -> k, total k ] |> Map.ofList
160+
if tagsMatch then
161+
stats.Incr instrument.Name v)
74162

75-
member _.GetStats() = [ "hit-ratio", ratio ] |> Map.ofList
163+
listener.Start()
164+
165+
interface IDisposable with
166+
member _.Dispose() = listener.Dispose()
167+
168+
member _.GetTotals() = stats.GetTotals()
169+
170+
member _.Ratio = stats.Ratio
171+
172+
override _.ToString() = stats.ToString()
76173

77174
[<RequireQualifiedAccess>]
78175
type EvictionMode =
@@ -97,22 +194,17 @@ type CacheOptions<'Key> =
97194
}
98195

99196
module CacheOptions =
100-
let getDefault () =
101-
{
102-
CacheOptions.TotalCapacity = 1024
103-
CacheOptions.HeadroomPercentage = 50
104-
CacheOptions.EvictionMode = EvictionMode.MailboxProcessor
105-
CacheOptions.Comparer = HashIdentity.Structural
106-
}
107197

108-
let getReferenceIdentity () =
198+
let getDefault comparer =
109199
{
110200
CacheOptions.TotalCapacity = 1024
111201
CacheOptions.HeadroomPercentage = 50
112202
CacheOptions.EvictionMode = EvictionMode.MailboxProcessor
113-
CacheOptions.Comparer = HashIdentity.Reference
203+
CacheOptions.Comparer = comparer
114204
}
115205

206+
let getReferenceIdentity () = getDefault HashIdentity.Reference
207+
116208
let withNoEviction options =
117209
{ options with
118210
CacheOptions.EvictionMode = EvictionMode.NoEviction
@@ -151,7 +243,7 @@ type EvictionQueueMessage<'Entity, 'Target> =
151243
| Update of 'Entity
152244

153245
[<Sealed; NoComparison; NoEquality>]
154-
[<DebuggerDisplay("{GetStats()}")>]
246+
[<DebuggerDisplay("{DebugDisplay()}")>]
155247
type Cache<'Key, 'Value when 'Key: not null> internal (options: CacheOptions<'Key>, ?name) =
156248

157249
do
@@ -178,7 +270,7 @@ type Cache<'Key, 'Value when 'Key: not null> internal (options: CacheOptions<'Ke
178270
let evicted = Event<_>()
179271
let evictionFailed = Event<_>()
180272

181-
let tag = CacheMetrics.mkTag name
273+
let tags = CacheMetrics.mkTags name
182274

183275
// Track disposal state (0 = not disposed, 1 = disposed)
184276
let mutable disposed = 0
@@ -211,10 +303,10 @@ type Cache<'Key, 'Value when 'Key: not null> internal (options: CacheOptions<'Ke
211303

212304
match store.TryRemove(first.Value.Key) with
213305
| true, _ ->
214-
CacheMetrics.Eviction tag
306+
CacheMetrics.Eviction &tags
215307
evicted.Trigger()
216308
| _ ->
217-
CacheMetrics.EvictionFail tag
309+
CacheMetrics.EvictionFail &tags
218310
evictionFailed.Trigger()
219311
deadKeysCount <- deadKeysCount + 1
220312

@@ -262,20 +354,24 @@ type Cache<'Key, 'Value when 'Key: not null> internal (options: CacheOptions<'Ke
262354

263355
post, dispose
264356

265-
do CacheMetrics.Created tag
357+
#if DEBUG
358+
let debugListener = new CacheMetrics.CacheMetricsListener(tags)
359+
#endif
360+
361+
do CacheMetrics.Created &tags
266362

267363
member val Evicted = evicted.Publish
268364
member val EvictionFailed = evictionFailed.Publish
269365

270366
member _.TryGetValue(key: 'Key, value: outref<'Value>) =
271367
match store.TryGetValue(key) with
272368
| true, entity ->
273-
CacheMetrics.Hit tag
369+
CacheMetrics.Hit &tags
274370
post (EvictionQueueMessage.Update entity)
275371
value <- entity.Value
276372
true
277373
| _ ->
278-
CacheMetrics.Miss tag
374+
CacheMetrics.Miss &tags
279375
value <- Unchecked.defaultof<'Value>
280376
false
281377

@@ -285,7 +381,7 @@ type Cache<'Key, 'Value when 'Key: not null> internal (options: CacheOptions<'Ke
285381
let added = store.TryAdd(key, entity)
286382

287383
if added then
288-
CacheMetrics.Add tag
384+
CacheMetrics.Add &tags
289385
post (EvictionQueueMessage.Add(entity, store))
290386

291387
added
@@ -302,11 +398,11 @@ type Cache<'Key, 'Value when 'Key: not null> internal (options: CacheOptions<'Ke
302398

303399
if wasMiss then
304400
post (EvictionQueueMessage.Add(result, store))
305-
CacheMetrics.Add tag
306-
CacheMetrics.Miss tag
401+
CacheMetrics.Add &tags
402+
CacheMetrics.Miss &tags
307403
else
308404
post (EvictionQueueMessage.Update result)
309-
CacheMetrics.Hit tag
405+
CacheMetrics.Hit &tags
310406

311407
result.Value
312408

@@ -321,18 +417,19 @@ type Cache<'Key, 'Value when 'Key: not null> internal (options: CacheOptions<'Ke
321417

322418
// Returned value tells us if the entity was added or updated.
323419
if Object.ReferenceEquals(addValue, result) then
324-
CacheMetrics.Add tag
420+
CacheMetrics.Add &tags
325421
post (EvictionQueueMessage.Add(addValue, store))
326422
else
327-
CacheMetrics.Update tag
423+
CacheMetrics.Update &tags
328424
post (EvictionQueueMessage.Update result)
329425

330-
member _.CreateMetricsListener() = new CacheMetricsListener(tag)
426+
member _.CreateMetricsListener() =
427+
new CacheMetrics.CacheMetricsListener(tags)
331428

332429
member _.Dispose() =
333430
if Interlocked.Exchange(&disposed, 1) = 0 then
334431
disposeEvictionProcessor ()
335-
CacheMetrics.Disposed tag
432+
CacheMetrics.Disposed &tags
336433

337434
interface IDisposable with
338435
member this.Dispose() =
@@ -341,3 +438,7 @@ type Cache<'Key, 'Value when 'Key: not null> internal (options: CacheOptions<'Ke
341438

342439
// Finalizer to ensure eviction loop is cancelled if Dispose wasn't called.
343440
override this.Finalize() = this.Dispose()
441+
442+
#if DEBUG
443+
member _.DebugDisplay() = debugListener.ToString()
444+
#endif

src/Compiler/Utilities/Caches.fsi

Lines changed: 11 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -8,13 +8,16 @@ module internal CacheMetrics =
88
/// Global telemetry Meter for all caches. Exposed for testing purposes.
99
/// Set FSHARP_OTEL_EXPORT environment variable to enable OpenTelemetry export to external collectors in tests.
1010
val Meter: Meter
11+
val ListenToAll: unit -> IDisposable
12+
val StatsToString: unit -> string
13+
val CaptureStatsAndWriteToConsole: unit -> IDisposable
1114

12-
[<Class>]
13-
/// A local listener that can be created for a specific Cache instance to get its metrics. For testing purposes only.
14-
type internal CacheMetricsListener =
15-
member GetStats: unit -> Map<string, float>
16-
member GetTotals: unit -> Map<string, int64>
17-
interface IDisposable
15+
/// A local listener that can be created for a specific Cache instance to get its metrics. For testing purposes only.
16+
[<Class>]
17+
type internal CacheMetricsListener =
18+
member Ratio: float
19+
member GetTotals: unit -> Map<string, int64>
20+
interface IDisposable
1821

1922
[<RequireQualifiedAccess; NoComparison>]
2023
type internal EvictionMode =
@@ -43,7 +46,7 @@ type internal CacheOptions<'Key> =
4346

4447
module internal CacheOptions =
4548
/// Default options, using structural equality for keys and queued eviction.
46-
val getDefault: unit -> CacheOptions<'Key> when 'Key: equality
49+
val getDefault: IEqualityComparer<'Key> -> CacheOptions<'Key>
4750
/// Default options, using reference equality for keys and queued eviction.
4851
val getReferenceIdentity: unit -> CacheOptions<'Key> when 'Key: not struct
4952
/// Set eviction mode to NoEviction.
@@ -64,4 +67,4 @@ type internal Cache<'Key, 'Value when 'Key: not null> =
6467
/// For testing only.
6568
member EvictionFailed: IEvent<unit>
6669
/// For testing only. Creates a local telemetry listener for this cache instance.
67-
member CreateMetricsListener: unit -> CacheMetricsListener
70+
member CreateMetricsListener: unit -> CacheMetrics.CacheMetricsListener

0 commit comments

Comments
 (0)