internal void SystemLog(GrpcEvent msg)
{
RpcLog systemLog = msg.Message.RpcLog;
LogLevel logLevel = (LogLevel)systemLog.Level;
switch (logLevel)
{
case LogLevel.Warning:
_workerChannelLogger.LogWarning(systemLog.Message);
break;
case LogLevel.Information:
_workerChannelLogger.LogInformation(systemLog.Message);
break;
case LogLevel.Error:
{
if (systemLog.Exception != null)
{
Workers.Rpc.RpcException exception = new Workers.Rpc.RpcException(systemLog.Message, systemLog.Exception.Message, systemLog.Exception.StackTrace);
_workerChannelLogger.LogError(exception, systemLog.Message);
}
else
{
_workerChannelLogger.LogError(systemLog.Message);
}
}
break;
default:
_workerChannelLogger.LogInformation(systemLog.Message);
break;
}
}
internal void WorkerInitResponse(GrpcEvent initEvent)
{
_startLatencyMetric?.Dispose();
_startLatencyMetric = null;
_workerChannelLogger.LogDebug("Received WorkerInitResponse. Worker process initialized");
_initMessage = initEvent.Message.WorkerInitResponse;
_workerChannelLogger.LogDebug($"Worker capabilities: {_initMessage.Capabilities}");
if (_initMessage.Result.IsFailure(out Exception exc))
{
HandleWorkerInitError(exc);
_workerInitTask.SetResult(false);
return;
}
_state = _state | RpcWorkerChannelState.Initialized;
_workerCapabilities.UpdateCapabilities(_initMessage.Capabilities);
_isSharedMemoryDataTransferEnabled = IsSharedMemoryDataTransferEnabled();
if (!_isSharedMemoryDataTransferEnabled)
{
// If the worker does not support using shared memory data transfer, caching must also be disabled
ScriptHost.IsFunctionDataCacheEnabled = false;
}
_workerInitTask.SetResult(true);
}
public void SharedMemoryDataTransferSetting_VerifyDisabledIfEnvironmentVariableAbsent()
{
// Enable shared memory data transfer capability in the worker
IDictionary <string, string> capabilities = new Dictionary <string, string>()
{
{ RpcWorkerConstants.SharedMemoryDataTransfer, "1" }
};
StartStream startStream = new StartStream()
{
WorkerId = _workerId
};
StreamingMessage startStreamMessage = new StreamingMessage()
{
StartStream = startStream
};
// Send worker init request and enable the capabilities
GrpcEvent rpcEvent = new GrpcEvent(_workerId, startStreamMessage);
_workerChannel.SendWorkerInitRequest(rpcEvent);
_testFunctionRpcService.PublishWorkerInitResponseEvent(capabilities);
Assert.False(_workerChannel.IsSharedMemoryDataTransferEnabled());
}
// send capabilities to worker, wait for WorkerInitResponse
internal void SendWorkerInitRequest(GrpcEvent startEvent)
{
_workerChannelLogger.LogDebug("Worker Process started. Received StartStream message");
_inboundWorkerEvents.Where(msg => msg.MessageType == MsgType.WorkerInitResponse)
.Timeout(_workerConfig.CountOptions.InitializationTimeout)
.Take(1)
.Subscribe(WorkerInitResponse, HandleWorkerInitError);
WorkerInitRequest initRequest = GetWorkerInitRequest();
// Run as Functions Host V2 compatible
if (_environment.IsV2CompatibilityMode())
{
_workerChannelLogger.LogDebug("Worker and host running in V2 compatibility mode");
initRequest.Capabilities.Add(RpcWorkerConstants.V2Compatable, "true");
}
if (ScriptHost.IsFunctionDataCacheEnabled)
{
// FunctionDataCache is available from the host side - we send this to the worker.
// As long as the worker replies back with the SharedMemoryDataTransfer capability, the cache
// can be used.
initRequest.Capabilities.Add(RpcWorkerConstants.FunctionDataCache, "true");
}
SendStreamingMessage(new StreamingMessage
{
WorkerInitRequest = initRequest
});
}
public void SendLoadRequestCollection_PublishesOutboundEvents()
{
StartStream startStream = new StartStream()
{
WorkerId = _workerId
};
StreamingMessage startStreamMessage = new StreamingMessage()
{
StartStream = startStream
};
GrpcEvent rpcEvent = new GrpcEvent(_workerId, startStreamMessage);
_workerChannel.SendWorkerInitRequest(rpcEvent);
_testFunctionRpcService.PublishWorkerInitResponseEvent(new Dictionary <string, string>()
{
{ RpcWorkerConstants.AcceptsListOfFunctionLoadRequests, "true" }
});
_metricsLogger.ClearCollections();
IEnumerable <FunctionMetadata> functionMetadata = GetTestFunctionsList("node");
_workerChannel.SetupFunctionInvocationBuffers(functionMetadata);
_workerChannel.SendFunctionLoadRequests(null, TimeSpan.FromMinutes(5));
var traces = _logger.GetLogMessages();
var functionLoadLogs = traces.Where(m => string.Equals(m.FormattedMessage, _expectedLogMsg));
AreExpectedMetricsGenerated();
Assert.True(functionLoadLogs.Count() == 2);
Assert.True(traces.Any(m => string.Equals(m.FormattedMessage, string.Format("Sending FunctionLoadRequestCollection with number of functions:'{0}'", functionMetadata.ToList().Count))));
}
internal void WorkerInitResponse(GrpcEvent initEvent)
{
_startLatencyMetric?.Dispose();
_startLatencyMetric = null;
_workerChannelLogger.LogDebug("Received WorkerInitResponse. Worker process initialized");
_initMessage = initEvent.Message.WorkerInitResponse;
_workerChannelLogger.LogDebug($"Worker capabilities: {_initMessage.Capabilities}");
if (_initMessage.Result.IsFailure(out Exception exc))
{
HandleWorkerInitError(exc);
_workerInitTask.SetResult(false);
return;
}
_state = _state | RpcWorkerChannelState.Initialized;
_workerCapabilities.UpdateCapabilities(_initMessage.Capabilities);
_workerInitTask.SetResult(true);
}
public void SendWorkerInitRequest_PublishesOutboundEvent()
{
StartStream startStream = new StartStream()
{
WorkerId = _workerId
};
StreamingMessage startStreamMessage = new StreamingMessage()
{
StartStream = startStream
};
GrpcEvent rpcEvent = new GrpcEvent(_workerId, startStreamMessage);
_workerChannel.SendWorkerInitRequest(rpcEvent);
_testFunctionRpcService.PublishWorkerInitResponseEvent();
var traces = _logger.GetLogMessages();
Assert.True(traces.Any(m => string.Equals(m.FormattedMessage, _expectedLogMsg)));
}
public void SendWorkerInitRequest_PublishesOutboundEvent_V2Compatable()
{
_testEnvironment.SetEnvironmentVariable(EnvironmentSettingNames.FunctionsV2CompatibilityModeKey, "true");
StartStream startStream = new StartStream()
{
WorkerId = _workerId
};
StreamingMessage startStreamMessage = new StreamingMessage()
{
StartStream = startStream
};
GrpcEvent rpcEvent = new GrpcEvent(_workerId, startStreamMessage);
_workerChannel.SendWorkerInitRequest(rpcEvent);
_testFunctionRpcService.PublishWorkerInitResponseEvent();
var traces = _logger.GetLogMessages();
Assert.True(traces.Any(m => string.Equals(m.FormattedMessage, _expectedLogMsg)));
Assert.True(traces.Any(m => string.Equals(m.FormattedMessage, "Worker and host running in V2 compatibility mode")));
}
internal void Log(GrpcEvent msg)
{
var rpcLog = msg.Message.RpcLog;
LogLevel logLevel = (LogLevel)rpcLog.Level;
if (_executingInvocations.TryGetValue(rpcLog.InvocationId, out ScriptInvocationContext context))
{
// Restore the execution context from the original invocation. This allows AsyncLocal state to flow to loggers.
System.Threading.ExecutionContext.Run(context.AsyncExecutionContext, (s) =>
{
if (rpcLog.Exception != null)
{
var exception = new Workers.Rpc.RpcException(rpcLog.Message, rpcLog.Exception.Message, rpcLog.Exception.StackTrace);
context.Logger.Log(logLevel, new EventId(0, rpcLog.EventId), rpcLog.Message, exception, (state, exc) => state);
}
else
{
context.Logger.Log(logLevel, new EventId(0, rpcLog.EventId), rpcLog.Message, null, (state, exc) => state);
}
}, null);
}
}
// send capabilities to worker, wait for WorkerInitResponse
internal void SendWorkerInitRequest(GrpcEvent startEvent)
{
_workerChannelLogger.LogDebug("Worker Process started. Received StartStream message");
_inboundWorkerEvents.Where(msg => msg.MessageType == MsgType.WorkerInitResponse)
.Timeout(workerInitTimeout)
.Take(1)
.Subscribe(WorkerInitResponse, HandleWorkerInitError);
WorkerInitRequest initRequest = GetWorkerInitRequest();
// Run as Functions Host V2 compatible
if (_environment.IsV2CompatibilityMode())
{
_workerChannelLogger.LogDebug("Worker and host running in V2 compatibility mode");
initRequest.Capabilities.Add(RpcWorkerConstants.V2Compatable, "true");
}
SendStreamingMessage(new StreamingMessage
{
WorkerInitRequest = initRequest
});
}
internal void Log(GrpcEvent msg)
{
var rpcLog = msg.Message.RpcLog;
LogLevel logLevel = (LogLevel)rpcLog.Level;
if (_executingInvocations.TryGetValue(rpcLog.InvocationId, out ScriptInvocationContext context))
{
// Restore the execution context from the original invocation. This allows AsyncLocal state to flow to loggers.
System.Threading.ExecutionContext.Run(context.AsyncExecutionContext, (s) =>
{
if (rpcLog.LogCategory == RpcLogCategory.CustomMetric)
{
if (rpcLog.PropertiesMap.TryGetValue(LogConstants.NameKey, out var metricName) &&
rpcLog.PropertiesMap.TryGetValue(LogConstants.MetricValueKey, out var metricValue))
{
// Strip off the name/value entries in the dictionary passed to Log Message and include the rest as the property bag passed to the backing ILogger
var rpcLogProperties = rpcLog.PropertiesMap
.Where(i => i.Key != LogConstants.NameKey && i.Key != LogConstants.MetricValueKey)
.ToDictionary(i => i.Key, i => i.Value.ToObject());
context.Logger.LogMetric(metricName.String, metricValue.Double, rpcLogProperties);
}
}
else
{
if (rpcLog.Exception != null)
{
// TODO fix RpcException catch all https://github.com/Azure/azure-functions-dotnet-worker/issues/370
var exception = new Workers.Rpc.RpcException(rpcLog.Message, rpcLog.Exception.Message, rpcLog.Exception.StackTrace);
context.Logger.Log(logLevel, new EventId(0, rpcLog.EventId), rpcLog.Message, exception, (state, exc) => state);
}
else
{
context.Logger.Log(logLevel, new EventId(0, rpcLog.EventId), rpcLog.Message, null, (state, exc) => state);
}
}
}, null);
}
}
public void SharedMemoryDataTransferSetting_VerifyDisabledIfWorkerCapabilityAbsent()
{
// Enable shared memory data transfer in the environment
_testEnvironment.SetEnvironmentVariable(RpcWorkerConstants.FunctionsWorkerSharedMemoryDataTransferEnabledSettingName, "1");
StartStream startStream = new StartStream()
{
WorkerId = _workerId
};
StreamingMessage startStreamMessage = new StreamingMessage()
{
StartStream = startStream
};
// Send worker init request and enable the capabilities
GrpcEvent rpcEvent = new GrpcEvent(_workerId, startStreamMessage);
_workerChannel.SendWorkerInitRequest(rpcEvent);
_testFunctionRpcService.PublishWorkerInitResponseEvent();
Assert.False(_workerChannel.IsSharedMemoryDataTransferEnabled());
}