Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Resource Leakeage in version 4.2.22 #614

Open
ellerysammy opened this issue Jul 3, 2022 · 12 comments
Open

Resource Leakeage in version 4.2.22 #614

ellerysammy opened this issue Jul 3, 2022 · 12 comments

Comments

@ellerysammy
Copy link

ellerysammy commented Jul 3, 2022

When a Memory Leakeage analysis is performed in the package, using infersharp, the analysis found 13 issues for two different categories.

  • DOTNET_RESOURCE_LEAK
  • THREAD_SAFETY_VIOLATION

The classes with issues are:

  • ProfilingActionFilter.cs
  • MvcDiagnosticListener.cs
  • MemoryCacheStorage.cs
  • ProfiledDbDataAdapter.cs
  • MiniProfiler.cs
  • Timing.cs

Below the report, for you to take a look (you can read it as a .sarif file)

{ "$schema": "http://json.schemastore.org/sarif-2.1.0-rtm.5", "version": "2.1.0", "runs": [ { "tool": { "driver": { "name": "Infer", "informationUri": "https://github.com/facebook/infer", "version": "1.1.0", "rules": [ { "id": "DOTNET_RESOURCE_LEAK", "shortDescription": { "text": "Dotnet Resource Leak" }, "helpUri": "https://fbinfer.com/docs/next/all-issue-types#dotnet_resource_leak" }, { "id": "THREAD_SAFETY_VIOLATION", "shortDescription": { "text": "Thread Safety Violation" }, "helpUri": "https://fbinfer.com/docs/next/all-issue-types#thread_safety_violation" } ] } }, "results": [ { "message": { "text": "Leaked resource (returned from StackExchange.Profiling.Timing StackExchange.Profiling.MiniProfilerExtensions::Step(StackExchange.Profiling.MiniProfiler,System.String) at Line 47) of type StackExchange.Profiling.Timing, Leaked resource (returned from StackExchange.Profiling.Timing StackExchange.Profiling.MiniProfilerExtensions::Step(StackExchange.Profiling.MiniProfiler,System.String) at Line 54) of type StackExchange.Profiling.Timing in method \"Void ProfilingActionFilter.OnActionExecuting(ActionExecutingContext)\"." }, "level": "error", "ruleId": "DOTNET_RESOURCE_LEAK", "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore.Mvc\\Internal\\ProfilingActionFilter.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore.Mvc\\Internal\\ProfilingActionFilter.cs" }, "region": { "startLine": 26, "startColumn": 13 } } } ] }, { "message": { "text": "Leaked resource (output of StackExchange.Profiling.Timing::.ctor() at Line 98) of type StackExchange.Profiling.Timing in method \"Object MvcDiagnosticListener.StartFilter(T,String)\"." }, "level": "error", "ruleId": "DOTNET_RESOURCE_LEAK", "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore.Mvc\\MvcDiagnosticListener.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore.Mvc\\MvcDiagnosticListener.cs" }, "region": { "startLine": 95, "startColumn": 13 } } } ] }, { "message": { "text": "Leaked resource (output of StackExchange.Profiling.Timing::.ctor() at Line 108) of type StackExchange.Profiling.Timing in method \"Object MvcDiagnosticListener.StartView(T,String)\"." }, "level": "error", "ruleId": "DOTNET_RESOURCE_LEAK", "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore.Mvc\\MvcDiagnosticListener.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore.Mvc\\MvcDiagnosticListener.cs" }, "region": { "startLine": 105, "startColumn": 13 } } } ] }, { "message": { "text": "Leaked resource (output of StackExchange.Profiling.Timing::.ctor() at Line 116) of type StackExchange.Profiling.Timing in method \"Object MvcDiagnosticListener.Start(T,String)\"." }, "level": "error", "ruleId": "DOTNET_RESOURCE_LEAK", "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore.Mvc\\MvcDiagnosticListener.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore.Mvc\\MvcDiagnosticListener.cs" }, "region": { "startLine": 115, "startColumn": 13 } } } ] }, { "message": { "text": "Read/Write race. Non-private methodMemoryCacheStorage.Save(...)indirectly reads without synchronization fromthis.StackExchange.Profiling.Storage.MemoryCacheStorage.k__BackingField. Potentially races with write in method MemoryCacheStorage.set_CacheDuration(...).\n Reporting because this access may occur on a background thread." }, "level": "warning", "ruleId": "THREAD_SAFETY_VIOLATION", "codeFlows": [ { "threadFlows": [ { "locations": [ { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs" }, "region": { "startLine": 158, "startColumn": 13 } }, "message": { "text": "<Read trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs" }, "region": { "startLine": 158, "startColumn": 13 } }, "message": { "text": "call to TimeSpan MemoryCacheStorage.get_CacheDuration()" } } }, { "nestingLevel": 1, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs" }, "region": { "startLine": 28, "startColumn": 41 } }, "message": { "text": "access to this.StackExchange.Profiling.Storage.MemoryCacheStorage.k__BackingField" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs" }, "region": { "startLine": 28, "startColumn": 46 } }, "message": { "text": "<Write trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs" }, "region": { "startLine": 28, "startColumn": 46 } }, "message": { "text": "access to this.StackExchange.Profiling.Storage.MemoryCacheStorage.k__BackingField" } } } ] } ] } ], "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.AspNetCore\\Storage\\MemoryCacheStorage.cs" }, "region": { "startLine": 158, "startColumn": 13 } } } ] }, { "message": { "text": "Leaked resource Data.ProfiledDbDataAdapter.StackExchange.Profiling.Data.ProfiledDbDataAdapter.TokenReader of type System.Data.DataTableReader, Leaked resource (output of System.Data.DataTable::.ctor() at Line 15) of type System.Data.DataTable in method \"Void ProfiledDbDataAdapter..cctor()\"." }, "level": "error", "ruleId": "DOTNET_RESOURCE_LEAK", "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Data\\ProfiledDbDataAdapter.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Data\\ProfiledDbDataAdapter.cs" }, "region": { "startLine": 15, "startColumn": 9 } } } ] }, { "message": { "text": "Leaked resource (output of StackExchange.Profiling.Timing::.ctor() at Line 52) of type StackExchange.Profiling.Timing in method \"MiniProfiler..ctor(String,MiniProfilerBaseOptions)\"." }, "level": "error", "ruleId": "DOTNET_RESOURCE_LEAK", "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\MiniProfiler.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\MiniProfiler.cs" }, "region": { "startLine": 26, "startColumn": 59 } } } ] }, { "message": { "text": "Read/Write race. Non-private method Timing.get_CustomTimings()reads without synchronization fromthis.StackExchange.Profiling.Timing.k__BackingField. Potentially races with write in method Timing.RemoveCustomTiming(...).\n Reporting because another access to the same memory occurs on a background thread, although this access may not." }, "level": "warning", "ruleId": "THREAD_SAFETY_VIOLATION", "codeFlows": [ { "threadFlows": [ { "locations": [ { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 71 } }, "message": { "text": "<Read trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 71 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } }, "message": { "text": "<Write trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } }, "message": { "text": "call to List1<!0> Timing.GetCustomTimingList(String)"
}
}
},
{
"nestingLevel": 1,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 351,
"startColumn": 25
}
},
"message": {
"text": "call to Void Timing.set_CustomTimings(Dictionary2<!0,!1>)" } } }, { "nestingLevel": 2, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } } ] } ] } ], "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 71 } } } ] }, { "message": { "text": "Unprotected write. Non-private method Timing.set_CustomTimings(...)writes to fieldthis.StackExchange.Profiling.Timing.k__BackingFieldoutside of synchronization.\n Reporting because another access to the same memory occurs on a background thread, although this access may not." }, "level": "warning", "ruleId": "THREAD_SAFETY_VIOLATION", "codeFlows": [ { "threadFlows": [ { "locations": [ { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "<Write on unknown thread>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "access tothis.StackExchange.Profiling.Timing.k__BackingField" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } }, "message": { "text": "<Write on background thread>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } }, "message": { "text": "call to List1<!0> Timing.GetCustomTimingList(String)"
}
}
},
{
"nestingLevel": 1,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 351,
"startColumn": 25
}
},
"message": {
"text": "call to Void Timing.set_CustomTimings(Dictionary2<!0,!1>)" } } }, { "nestingLevel": 2, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } } ] } ] } ], "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } } } ] }, { "message": { "text": "Read/Write race. Non-private method Timing.get_CustomTimingsJson()indirectly reads without synchronization fromthis.StackExchange.Profiling.Timing.k__BackingField. Potentially races with write in method Timing.RemoveCustomTiming(...).\n Reporting because another access to the same memory occurs on a background thread, although this access may not." }, "level": "warning", "ruleId": "THREAD_SAFETY_VIOLATION", "codeFlows": [ { "threadFlows": [ { "locations": [ { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 144, "startColumn": 20 } }, "message": { "text": "<Read trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 144, "startColumn": 20 } }, "message": { "text": "call to Dictionary2<!0,!1> Timing.get_CustomTimings()"
}
}
},
{
"nestingLevel": 1,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 132,
"startColumn": 71
}
},
"message": {
"text": "access to this.StackExchange.Profiling.Timing.<CustomTimings>k__BackingField"
}
}
},
{
"nestingLevel": 0,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 329,
"startColumn": 13
}
},
"message": {
"text": ""
}
}
},
{
"nestingLevel": 0,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 329,
"startColumn": 13
}
},
"message": {
"text": "call to List1<!0> Timing.GetCustomTimingList(String)" } } }, { "nestingLevel": 1, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 351, "startColumn": 25 } }, "message": { "text": "call to Void Timing.set_CustomTimings(Dictionary2<!0,!1>)"
}
}
},
{
"nestingLevel": 2,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 132,
"startColumn": 76
}
},
"message": {
"text": "access to this.StackExchange.Profiling.Timing.<CustomTimings>k__BackingField"
}
}
}
]
}
]
}
],
"locations": [
{
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 144,
"startColumn": 20
}
}
}
]
},
{
"message": {
"text": "Unprotected write. Non-private method Timing.set_CustomTimingsJson(...) indirectly writes to field this.StackExchange.Profiling.Timing.<CustomTimings>k__BackingField outside of synchronization.\n Reporting because another access to the same memory occurs on a background thread, although this access may not."
},
"level": "warning",
"ruleId": "THREAD_SAFETY_VIOLATION",
"codeFlows": [
{
"threadFlows": [
{
"locations": [
{
"nestingLevel": 0,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 145,
"startColumn": 20
}
},
"message": {
"text": ""
}
}
},
{
"nestingLevel": 0,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 145,
"startColumn": 20
}
},
"message": {
"text": "call to Void Timing.set_CustomTimings(Dictionary2<!0,!1>)" } } }, { "nestingLevel": 1, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } }, "message": { "text": "<Write on background thread>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } }, "message": { "text": "call to List1<!0> Timing.GetCustomTimingList(String)"
}
}
},
{
"nestingLevel": 1,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 351,
"startColumn": 25
}
},
"message": {
"text": "call to Void Timing.set_CustomTimings(Dictionary2<!0,!1>)" } } }, { "nestingLevel": 2, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } } ] } ] } ], "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 145, "startColumn": 20 } } } ] }, { "message": { "text": "Read/Write race. Non-private method Timing.AddCustomTiming(...)indirectly reads without synchronization fromthis.StackExchange.Profiling.Timing.k__BackingField. Potentially races with write in method Timing.set_CustomTimings(...).\n Reporting because this access may occur on a background thread." }, "level": "warning", "ruleId": "THREAD_SAFETY_VIOLATION", "codeFlows": [ { "threadFlows": [ { "locations": [ { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 320, "startColumn": 13 } }, "message": { "text": "<Read trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 320, "startColumn": 13 } }, "message": { "text": "call to List1<!0> Timing.GetCustomTimingList(String)"
}
}
},
{
"nestingLevel": 1,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 343,
"startColumn": 13
}
},
"message": {
"text": "call to Dictionary2<!0,!1> Timing.get_CustomTimings()" } } }, { "nestingLevel": 2, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 71 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "<Write trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } } ] } ] } ], "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 320, "startColumn": 13 } } } ] }, { "message": { "text": "Read/Write race. Non-private method Timing.RemoveCustomTiming(...)indirectly reads without synchronization fromthis.StackExchange.Profiling.Timing.k__BackingField. Potentially races with write in method Timing.set_CustomTimings(...).\n Reporting because this access may occur on a background thread." }, "level": "warning", "ruleId": "THREAD_SAFETY_VIOLATION", "codeFlows": [ { "threadFlows": [ { "locations": [ { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } }, "message": { "text": "<Read trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } }, "message": { "text": "call to List1<!0> Timing.GetCustomTimingList(String)"
}
}
},
{
"nestingLevel": 1,
"location": {
"physicalLocation": {
"artifactLocation": {
"uri": "file:C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs",
"uriBaseId": "/__w/1/s/C:\projects\dotnet\src\MiniProfiler.Shared\Timing.cs"
},
"region": {
"startLine": 343,
"startColumn": 13
}
},
"message": {
"text": "call to Dictionary2<!0,!1> Timing.get_CustomTimings()" } } }, { "nestingLevel": 2, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 71 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "<Write trace>" } } }, { "nestingLevel": 0, "location": { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 132, "startColumn": 76 } }, "message": { "text": "access to this.StackExchange.Profiling.Timing.k__BackingField" } } } ] } ] } ], "locations": [ { "physicalLocation": { "artifactLocation": { "uri": "file:C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs", "uriBaseId": "/__w/1/s/C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Timing.cs" }, "region": { "startLine": 329, "startColumn": 13 } } } ] } ] } ] }

@kinsaiduck
Copy link

I discovered the same issue with the timings. I make a StackOverflow post about with without real success..
It seems as if Timings are not being disposed..

https://stackoverflow.com/questions/72615050/miniprofiler-not-disposing-timings

@NickCraver
Copy link
Member

What storage are you using for MiniProfiler? If it's memory storage: all of this is working as expected, it's holding on to things in-memory as configured. You can set limits on this or change how things are saved but fundamentally: yes, they're in memory. If you're seeing this with another provider: I'm very curious!

@ellerysammy
Copy link
Author

I tested using sqllite as storage with the same results
Probably it is something with we need to deal unless the miniprofiler team found a real solution

@kinsaiduck
Copy link

Hi, I used the Memory-Storage for the mini example in StackOverflow, set with and without SizeLimit and every property I could find. For production I used a custom storage for further processing the results, which lead my down this road.

@NickCraver
Copy link
Member

If anyone has a reproduction of this in an app (as in: contained repo I can run) - happy to take a look, but I do expect this to be a configuration issue since this basic config is used in very high traffic environments without issue/growth. If we can improve the docs here for some confusion or something: happy to do so to make it better and help whoever's hitting this.

@kinsaiduck
Copy link

Hi @NickCraver !
I posted a working example on the stackoverflow link above:
https://stackoverflow.com/questions/72615050/miniprofiler-not-disposing-timings

I monitor the sql-queries to a db with long command text to reproduce the behaviour.
Any help is appreciated!

@joshbartley
Copy link

I just used dotMemory and saw that most of the memory were strings, the strings being SQL and stored in MiniProfiler's CustomTimings dictionary. This is a windows service that MiniProfiler has not been set up on but uses the return new StackExchange.Profiling.Data.ProfiledDbConnection(_context.Database.GetDbConnection(), StackExchange.Profiling.MiniProfiler.Current); method to get a SqlConnection

image

Looking at all the strings that are stored, it's from one service. That service is a Singleton. Timings are also stored outside of storage and the ProfiledDBConnection doesn't check if the profiler is active before starting a custom timing.

  1. Windows Service started, no MiniProfiler config setup
  2. Singleton is instantiated, requests a connection.
  3. Default MiniProfiler is created, CustomTimings stored in an unbounded dictionary outside of storage settings
  4. DB Query runs, stores SQL statement and replaces parameters so it's a unique string each time
  5. _connection.Close() runs, CustomTimings sticks around.

I'm not 100% sure what clears CustomTimings or if this is an issue where the EntityFramework GetDBConnection is holding on to something which sticks the ProfiledDBConnection in memory somehow. I'm going to wrap the ProfiledDBConnection in a #IF DEBUG statement to see if that clears this up and shows EF holding on to something with this singleton service or something else. Part of this comment too is just to document what I found in case someone else comes across this issue.

@NickCraver
Copy link
Member

@joshbartley How is the MiniProfiler started and stopped there? It sounds like it's open indefinitely from your description, which would add up over time. Am I misunderstanding the lifetime?

@joshbartley
Copy link

Good news, I was able to recreate the issue. I think it's an EntityFramework lifecycle issue that interacts with MiniProfiler. If I leave EntityFramework out of it everything works. If I have a long running EntityFramework context that does custom SQL and uses a ProfileDBConnection memory usage grows very very quickly.

image

Old EF thread about not calling dispose on connections using this pattern.

var _connection = _context.Database.GetDbConnection()
            try
            {
                var row = _connection.QueryFirst(@SELECT 1",);          
            }
            finally
            {
                _connection.Close();
            }

Reproduction code.

using Dapper;
using Microsoft.Data.SqlClient;
using Microsoft.EntityFrameworkCore;
using Microsoft.Extensions.Configuration;
using StackExchange.Profiling.Data;

namespace MiniProfilerTest
{
    internal class Program
    {
        static async Task Main(string[] args)
        {

            var singleton = new TestClass();

            for (int i = 0; i < 1_000_000; i++)
            {

                if (i % 10000 == 0)
                    Console.WriteLine("Memory used before collection: {0:N0}", GC.GetTotalMemory(false));

                await singleton.Run(i);

                if (i % 10000 == 0)
                {
                    GC.Collect(); //since this is a background service it never collects anything
                    Console.WriteLine("Memory used after full collection: {0:N0}", GC.GetTotalMemory(true));
                }

            }

        }


        public class TestClass
        {
            private FakeContext _context;

            public TestClass()
            {
                var optionsBuilder = new DbContextOptionsBuilder<FakeContext>();
                optionsBuilder.UseSqlServer("Server =.\\; Database=master;Trusted_Connection=True;TrustServerCertificate=Yes;");
                _context = new FakeContext(optionsBuilder.Options);
            }

            public async Task Run(long i)
            {
                var con = new ProfiledDbConnection(_context.Database.GetDbConnection(), StackExchange.Profiling.MiniProfiler.Current);
                try
                {

                    var returnValue = await con.QuerySingleAsync($"SELECT {i} --very long comment in sql to act like a long sql statement very long comment in sql to act like a long sql statement very long comment in sql to act like a long sql statement", new { i = i });
                } finally { 
                    con.Close(); 
                }
            }
        }

        public partial class FakeContext : DbContext
        {
            public FakeContext(DbContextOptions<FakeContext> options) : base(options)
            { }
            public FakeContext()
            { }

            public virtual DbSet<FakeTable> FakeTables { get; set; }
            protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
            {
                if (!optionsBuilder.IsConfigured)
                {
                    optionsBuilder.UseSqlServer(@"Server=(localdb)\mssqllocaldb;Database=EFProviders.InMemory;Trusted_Connection=True;"/*, options=> options.MaxBatchSize(10)*/);
                }
            }

            protected override void OnModelCreating(ModelBuilder modelBuilder)
            {
                modelBuilder.Entity<FakeTable>(entity =>
                {
                    entity.HasKey(e => e.Id);
                });
            }
        }

        public class FakeTable
        {
            public long Id { get; set; }
        }
    }
}

tl;dr;

If you do the below code with a long running EntityFramework context you will run out of memory. If you create a new SqlConnection straight from a connection string you are fine. If you do the below in an ASP.NET environment without a Singleton object, likely you are fine.

var _connection = new ProfiledDbConnection(_context.Database.GetDbConnection(), StackExchange.Profiling.MiniProfiler.Current); //this is bad and can store timings forever.
            try
            {
                var row = _connection.QueryFirst("SELECT 1",);          
            }
            finally
            {
                _connection.Close();
            }

@NickCraver
Copy link
Member

I'm not sure what to advise here: if you create a massive profile, then yep it'll be massive. It's not recommended to run this indefinitely no operations that large. You can always use the components, wrap them, etc. to construct a profiler that's doing sampling or some such instead of everything, but out of the box we're 1:1 so memory usage would be linearly matching load.

@joshbartley
Copy link

@NickCraver I think it's a pattern that runs into this issue. You have a web project that uses MiniProfiler. You then create some sort of background service/windows service and you don't setup MiniProfiler for the background service. Memory grows overtime. I think another key point is that I'm not actively creating a profile here. There was not MiniProfiler setup, just some code that used a ProfiledDbConnection.

https://github.com/MiniProfiler/dotnet/blob/main/samples/Samples.ConsoleCore/Program.cs#L101C23-L101C103
says that if MiniProfiler.Current is null then nothing will be recorded. Sample code above is recording something but I never set MiniProfiler.Current to anything.
https://miniprofiler.com/dotnet/HowTo/ProfileSql
Doesn't list anything about the MiniProfiler.Current which may be part of the disconnect here on how to properly use MiniProfiler in a background service.

My fix is that I am wrapping #if DEBUG around all of these ProfiledDBConnection statements which seems to fix my problem in this background jobs that only get restarted during a release.

@NickCraver
Copy link
Member

You then create some sort of background service/windows service and you don't setup MiniProfiler for the background service. Memory grows overtime.

I agree this should not happen - but I've also never seen it happen nor can I reproduce it. Timings are accumulated on the profiler, so if it's actually never started then I'm not sure where you're racking up references. I'd guess it's more likely the background service was started when there was a MiniProfiler active (propagated via AsyncLocal<T>). It should be easy to see this though, check MiniProfiler.Current.

If that's null where the memory is racking up I'm extremely curious. If that's not happening and MiniProfiler.Current is an active profiler, then the question is how you're starting MiniProfiler and how that's propagating to EF Core when the service starts. It's possible we could add some additional suppression mechanisms there. For example today you can do something like this in case the hint helps resolve already:

using (MiniProfiler.Current.Ignore())
{
    // ignored stuff, we're in a suppression block
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants