Skip to content

Commit

Permalink
Fix noisy error logs related to GC in FunctionsLogs (Azure#8594)
Browse files Browse the repository at this point in the history
* Fix noisy error logs related to GC in FunctionsLogs
  • Loading branch information
safihamid authored Aug 8, 2022
1 parent 530e812 commit c52bb6f
Showing 1 changed file with 20 additions and 14 deletions.
34 changes: 20 additions & 14 deletions src/WebJobs.Script.WebHost/Middleware/ClrOptimizationMiddleware.cs
Original file line number Diff line number Diff line change
Expand Up @@ -21,12 +21,14 @@ internal class ClrOptimizationMiddleware
private readonly ILogger _logger;
private readonly RequestDelegate _next;
private readonly IScriptWebHostEnvironment _webHostEnvironment;
private readonly IEnvironment _environment;
private RequestDelegate _invoke;
private double _specialized = 0;

public ClrOptimizationMiddleware(RequestDelegate next, IScriptWebHostEnvironment webHostEnvironment, ILogger<SystemTraceMiddleware> logger)
public ClrOptimizationMiddleware(RequestDelegate next, IScriptWebHostEnvironment webHostEnvironment, IEnvironment environment, ILogger<ClrOptimizationMiddleware> logger)
{
_webHostEnvironment = webHostEnvironment;
_environment = environment;
_logger = logger;
_next = next;
_invoke = InvokeClrOptimizationCheck;
Expand All @@ -53,28 +55,31 @@ private void StartStopGCAsBestEffort()
{
try
{
if (_webHostEnvironment.InStandbyMode)
// optimization not intended for single core VMs
if (_webHostEnvironment.InStandbyMode && _environment.GetEffectiveCoresCount() > 1)
{
// This is just to make sure we do not enter NoGCRegion multiple times during standby mode.
if (GCSettings.LatencyMode != GCLatencyMode.NoGCRegion)
// If in placeholder mode and already in NoGCRegion, let's end it then start NoGCRegion again.
// This may happen if there are multiple warmup calls(few minutes apart) during placeholder mode and before specialization.
if (GCSettings.LatencyMode == GCLatencyMode.NoGCRegion)
{
GC.EndNoGCRegion();
}

// In standby mode, we enter NoGCRegion mode as best effort.
// This is to try to avoid GC during cold start specialization.
if (!GC.TryStartNoGCRegion(AllocationBudgetForGCDuringSpecialization, disallowFullBlockingGC: false))
{
// In standby mode, we enforce a GC then enter NoGCRegion mode as best effort.
// This is to try to avoid GC during cold start specialization.
GC.Collect();
if (!GC.TryStartNoGCRegion(AllocationBudgetForGCDuringSpecialization, disallowFullBlockingGC: false))
{
_logger.LogError($"CLR runtime failed to commit the requested amount of memory: {AllocationBudgetForGCDuringSpecialization}");
}
_logger.LogInformation($"Collection count for gen 0: {GC.CollectionCount(0)}, gen 1: {GC.CollectionCount(1)}, gen 2: {GC.CollectionCount(2)}");
_logger.LogError($"CLR runtime GC failed to commit the requested amount of memory: {AllocationBudgetForGCDuringSpecialization}");
}
_logger.LogInformation($"GC Collection count for gen 0: {GC.CollectionCount(0)}, gen 1: {GC.CollectionCount(1)}, gen 2: {GC.CollectionCount(2)}");
}
else
{
// if not in standby mode and we are in NoGCRegion then we end NoGCRegion.
if (GCSettings.LatencyMode == GCLatencyMode.NoGCRegion)
{
GC.EndNoGCRegion();
_logger.LogInformation($"Collection count for gen 0: {GC.CollectionCount(0)}, gen 1: {GC.CollectionCount(1)}, gen 2: {GC.CollectionCount(2)}");
_logger.LogInformation($"GC Collection count for gen 0: {GC.CollectionCount(0)}, gen 1: {GC.CollectionCount(1)}, gen 2: {GC.CollectionCount(2)}");
}

// This logic needs to run only once during specialization, so replacing the RequestDelegate after specialization
Expand All @@ -86,7 +91,8 @@ private void StartStopGCAsBestEffort()
}
catch (Exception ex)
{
_logger.LogError(ex.Message);
// Just logging it at informational.
_logger.LogInformation(ex, "GC optimization will not get applied.");
}
}
}
Expand Down

0 comments on commit c52bb6f

Please sign in to comment.