Skip to content

Commit c52bb6f

Browse files
authored
Fix noisy error logs related to GC in FunctionsLogs (#8594)
* Fix noisy error logs related to GC in FunctionsLogs
1 parent 530e812 commit c52bb6f

File tree

1 file changed

+20
-14
lines changed

1 file changed

+20
-14
lines changed

src/WebJobs.Script.WebHost/Middleware/ClrOptimizationMiddleware.cs

Lines changed: 20 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -21,12 +21,14 @@ internal class ClrOptimizationMiddleware
2121
private readonly ILogger _logger;
2222
private readonly RequestDelegate _next;
2323
private readonly IScriptWebHostEnvironment _webHostEnvironment;
24+
private readonly IEnvironment _environment;
2425
private RequestDelegate _invoke;
2526
private double _specialized = 0;
2627

27-
public ClrOptimizationMiddleware(RequestDelegate next, IScriptWebHostEnvironment webHostEnvironment, ILogger<SystemTraceMiddleware> logger)
28+
public ClrOptimizationMiddleware(RequestDelegate next, IScriptWebHostEnvironment webHostEnvironment, IEnvironment environment, ILogger<ClrOptimizationMiddleware> logger)
2829
{
2930
_webHostEnvironment = webHostEnvironment;
31+
_environment = environment;
3032
_logger = logger;
3133
_next = next;
3234
_invoke = InvokeClrOptimizationCheck;
@@ -53,28 +55,31 @@ private void StartStopGCAsBestEffort()
5355
{
5456
try
5557
{
56-
if (_webHostEnvironment.InStandbyMode)
58+
// optimization not intended for single core VMs
59+
if (_webHostEnvironment.InStandbyMode && _environment.GetEffectiveCoresCount() > 1)
5760
{
58-
// This is just to make sure we do not enter NoGCRegion multiple times during standby mode.
59-
if (GCSettings.LatencyMode != GCLatencyMode.NoGCRegion)
61+
// If in placeholder mode and already in NoGCRegion, let's end it then start NoGCRegion again.
62+
// This may happen if there are multiple warmup calls(few minutes apart) during placeholder mode and before specialization.
63+
if (GCSettings.LatencyMode == GCLatencyMode.NoGCRegion)
64+
{
65+
GC.EndNoGCRegion();
66+
}
67+
68+
// In standby mode, we enter NoGCRegion mode as best effort.
69+
// This is to try to avoid GC during cold start specialization.
70+
if (!GC.TryStartNoGCRegion(AllocationBudgetForGCDuringSpecialization, disallowFullBlockingGC: false))
6071
{
61-
// In standby mode, we enforce a GC then enter NoGCRegion mode as best effort.
62-
// This is to try to avoid GC during cold start specialization.
63-
GC.Collect();
64-
if (!GC.TryStartNoGCRegion(AllocationBudgetForGCDuringSpecialization, disallowFullBlockingGC: false))
65-
{
66-
_logger.LogError($"CLR runtime failed to commit the requested amount of memory: {AllocationBudgetForGCDuringSpecialization}");
67-
}
68-
_logger.LogInformation($"Collection count for gen 0: {GC.CollectionCount(0)}, gen 1: {GC.CollectionCount(1)}, gen 2: {GC.CollectionCount(2)}");
72+
_logger.LogError($"CLR runtime GC failed to commit the requested amount of memory: {AllocationBudgetForGCDuringSpecialization}");
6973
}
74+
_logger.LogInformation($"GC Collection count for gen 0: {GC.CollectionCount(0)}, gen 1: {GC.CollectionCount(1)}, gen 2: {GC.CollectionCount(2)}");
7075
}
7176
else
7277
{
7378
// if not in standby mode and we are in NoGCRegion then we end NoGCRegion.
7479
if (GCSettings.LatencyMode == GCLatencyMode.NoGCRegion)
7580
{
7681
GC.EndNoGCRegion();
77-
_logger.LogInformation($"Collection count for gen 0: {GC.CollectionCount(0)}, gen 1: {GC.CollectionCount(1)}, gen 2: {GC.CollectionCount(2)}");
82+
_logger.LogInformation($"GC Collection count for gen 0: {GC.CollectionCount(0)}, gen 1: {GC.CollectionCount(1)}, gen 2: {GC.CollectionCount(2)}");
7883
}
7984

8085
// This logic needs to run only once during specialization, so replacing the RequestDelegate after specialization
@@ -86,7 +91,8 @@ private void StartStopGCAsBestEffort()
8691
}
8792
catch (Exception ex)
8893
{
89-
_logger.LogError(ex.Message);
94+
// Just logging it at informational.
95+
_logger.LogInformation(ex, "GC optimization will not get applied.");
9096
}
9197
}
9298
}

0 commit comments

Comments
 (0)