OpenTelemetry support in worker (#1049)

* Detect if OpenTelemetry module is present and environment variable is set
* Pre-instrument invocations with a span using Invocation ID + parent span ID
* Forward all user logs to the module to be sent to OTel endpoint
This commit is contained in:
andystaples 2024-04-12 12:00:00 -07:00 коммит произвёл GitHub
Родитель 80dfaa3a20
Коммит f0c7eec1e3
Не найден ключ, соответствующий данной подписи
Идентификатор ключа GPG: B5690EEEBB952194
16 изменённых файлов: 655 добавлений и 73 удалений

Просмотреть файл

@ -32,7 +32,8 @@ message StreamingMessage {
WorkerInitRequest worker_init_request = 17;
// Worker responds after initializing with its capabilities & status
WorkerInitResponse worker_init_response = 16;
// MESSAGE NOT USED
// Worker periodically sends empty heartbeat message to host
WorkerHeartbeat worker_heartbeat = 15;
@ -85,6 +86,13 @@ message StreamingMessage {
// Host gets the list of function load responses
FunctionLoadResponseCollection function_load_response_collection = 32;
// Host sends required metadata to worker to warmup the worker
WorkerWarmupRequest worker_warmup_request = 33;
// Worker responds after warming up with the warmup result
WorkerWarmupResponse worker_warmup_response = 34;
}
}
@ -120,7 +128,7 @@ message WorkerInitRequest {
// Worker responds with the result of initializing itself
message WorkerInitResponse {
// NOT USED
// PROPERTY NOT USED
// TODO: Remove from protobuf during next breaking change release
string worker_version = 1;
@ -173,7 +181,7 @@ message StatusResult {
repeated RpcLog logs = 3;
}
// NOT USED
// MESSAGE NOT USED
// TODO: Remove from protobuf during next breaking change release
message WorkerHeartbeat {}
@ -187,7 +195,7 @@ message WorkerTerminate {
message FileChangeEventRequest {
// Types of File change operations (See link for more info: https://msdn.microsoft.com/en-us/library/t6xf43e0(v=vs.110).aspx)
enum Type {
Unknown = 0;
Unknown = 0;
Created = 1;
Deleted = 2;
Changed = 4;
@ -237,8 +245,26 @@ message FunctionEnvironmentReloadRequest {
}
message FunctionEnvironmentReloadResponse {
enum CapabilitiesUpdateStrategy {
// overwrites existing values and appends new ones
// ex. worker init: {A: foo, B: bar} + env reload: {A:foo, B: foo, C: foo} -> {A: foo, B: foo, C: foo}
merge = 0;
// existing capabilities are cleared and new capabilities are applied
// ex. worker init: {A: foo, B: bar} + env reload: {A:foo, C: foo} -> {A: foo, C: foo}
replace = 1;
}
// After specialization, worker sends capabilities & metadata.
// Worker metadata captured for telemetry purposes
WorkerMetadata worker_metadata = 1;
// A map of worker supported features/capabilities
map<string, string> capabilities = 2;
// Status of the response
StatusResult result = 3;
// If no strategy is defined, the host will default to merge
CapabilitiesUpdateStrategy capabilities_update_strategy = 4;
}
// Tell the out-of-proc worker to close any shared memory maps it allocated for given invocation
@ -322,10 +348,13 @@ message RpcFunctionMetadata {
// A flag indicating if managed dependency is enabled or not
bool managed_dependency_enabled = 14;
// The optional function execution retry strategy to use on invocation failures.
RpcRetryOptions retry_options = 15;
// Properties for function metadata
// They're usually specific to a worker and largely passed along to the controller API for use
// outside the host
map<string,string> Properties = 16;
map<string,string> properties = 16;
}
// Host tells worker it is ready to receive metadata
@ -369,14 +398,14 @@ message InvocationRequest {
// Host sends ActivityId, traceStateString and Tags from host
message RpcTraceContext {
// This corresponds to Activity.Current?.Id
string trace_parent = 1;
// This corresponds to Activity.Current?.Id
string trace_parent = 1;
// This corresponds to Activity.Current?.TraceStateString
string trace_state = 2;
// This corresponds to Activity.Current?.TraceStateString
string trace_state = 2;
// This corresponds to Activity.Current?.Tags
map<string, string> attributes = 3;
// This corresponds to Activity.Current?.Tags
map<string, string> attributes = 3;
}
// Host sends retry context for a function invocation
@ -396,8 +425,8 @@ message InvocationCancel {
// Unique id for invocation
string invocation_id = 2;
// Time period before force shutdown
google.protobuf.Duration grace_period = 1; // could also use absolute time
// PROPERTY NOT USED
google.protobuf.Duration grace_period = 1;
}
// Worker responds with status of Invocation
@ -415,6 +444,15 @@ message InvocationResponse {
StatusResult result = 3;
}
message WorkerWarmupRequest {
// Full path of worker.config.json location
string worker_directory = 1;
}
message WorkerWarmupResponse {
StatusResult result = 1;
}
// Used to encapsulate data which could be a variety of types
message TypedData {
oneof data {
@ -429,6 +467,8 @@ message TypedData {
CollectionString collection_string = 9;
CollectionDouble collection_double = 10;
CollectionSInt64 collection_sint64 = 11;
ModelBindingData model_binding_data = 12;
CollectionModelBindingData collection_model_binding_data = 13;
}
}
@ -496,20 +536,20 @@ message ParameterBinding {
// Used to describe a given binding on load
message BindingInfo {
// Indicates whether it is an input or output binding (or a fancy inout binding)
enum Direction {
in = 0;
out = 1;
inout = 2;
}
// Indicates whether it is an input or output binding (or a fancy inout binding)
enum Direction {
in = 0;
out = 1;
inout = 2;
}
// Indicates the type of the data for the binding
enum DataType {
undefined = 0;
string = 1;
binary = 2;
stream = 3;
}
// Indicates the type of the data for the binding
enum DataType {
undefined = 0;
string = 1;
binary = 2;
stream = 3;
}
// Type of binding (e.g. HttpTrigger)
string type = 2;
@ -518,6 +558,9 @@ message BindingInfo {
Direction direction = 3;
DataType data_type = 4;
// Properties for binding metadata
map<string, string> properties = 5;
}
// Used to send logs back to the Host
@ -582,13 +625,13 @@ message RpcException {
// Textual message describing the exception
string message = 2;
// Worker specifies whether exception is a user exception,
// for purpose of application insights logging. Defaults to false.
// Worker specifies whether exception is a user exception,
// for purpose of application insights logging. Defaults to false.
bool is_user_exception = 4;
// Type of exception. If it's a user exception, the type is passed along to app insights.
// Otherwise, it's ignored for now.
string type = 5;
string type = 5;
}
// Http cookie type. Note that only name and value are used for Http requests
@ -647,3 +690,52 @@ message RpcHttp {
map<string,NullableString> nullable_params = 21;
map<string,NullableString> nullable_query = 22;
}
// Message representing Microsoft.Azure.WebJobs.ParameterBindingData
// Used for hydrating SDK-type bindings in out-of-proc workers
message ModelBindingData
{
// The version of the binding data content
string version = 1;
// The extension source of the binding data
string source = 2;
// The content type of the binding data content
string content_type = 3;
// The binding data content
bytes content = 4;
}
// Used to encapsulate collection model_binding_data
message CollectionModelBindingData {
repeated ModelBindingData model_binding_data = 1;
}
// Retry policy which the worker sends the host when the worker indexes
// a function.
message RpcRetryOptions
{
// The retry strategy to use. Valid values are fixed delay or exponential backoff.
enum RetryStrategy
{
exponential_backoff = 0;
fixed_delay = 1;
}
// The maximum number of retries allowed per function execution.
// -1 means to retry indefinitely.
int32 max_retry_count = 2;
// The delay that's used between retries when you're using a fixed delay strategy.
google.protobuf.Duration delay_interval = 3;
// The minimum retry delay when you're using an exponential backoff strategy
google.protobuf.Duration minimum_interval = 4;
// The maximum retry delay when you're using an exponential backoff strategy
google.protobuf.Duration maximum_interval = 5;
RetryStrategy retry_strategy = 6;
}

Просмотреть файл

@ -9,12 +9,10 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.Durable
using System.Collections.ObjectModel;
using System.Linq;
using System.Management.Automation;
using System.Reflection.Metadata;
using Microsoft.Azure.Functions.PowerShellWorker.PowerShell;
using Microsoft.Azure.Functions.PowerShellWorker.Utility;
using Microsoft.Azure.WebJobs.Script.Grpc.Messages;
using Newtonsoft.Json;
using LogLevel = WebJobs.Script.Grpc.Messages.RpcLog.Types.Level;
internal class PowerShellServices : IPowerShellServices
{
@ -43,36 +41,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.Durable
public bool isExternalDurableSdkLoaded()
{
// Search for the external DF SDK in the current session
var matchingModules = _pwsh.AddCommand(Utils.GetModuleCmdletInfo)
.AddParameter("FullyQualifiedName", Utils.ExternalDurableSdkName)
.InvokeAndClearCommands<PSModuleInfo>();
// If we get at least one result, we know the external SDK was imported
var numCandidates = matchingModules.Count();
var isModuleInCurrentSession = numCandidates > 0;
if (isModuleInCurrentSession)
{
var candidatesInfo = matchingModules.Select(module => string.Format(
PowerShellWorkerStrings.FoundExternalDurableSdkInSession, module.Name, module.Version, module.Path));
var externalSDKModuleInfo = string.Join('\n', candidatesInfo);
if (numCandidates > 1)
{
// If there's more than 1 result, there may be runtime conflicts
// warn user of potential conflicts
_logger.Log(isUserOnlyLog: false, LogLevel.Warning, String.Format(
PowerShellWorkerStrings.MultipleExternalSDKsInSession,
numCandidates, Utils.ExternalDurableSdkName, externalSDKModuleInfo));
}
else
{
// a single external SDK is in session. Report its metadata
_logger.Log(isUserOnlyLog: false, LogLevel.Trace, externalSDKModuleInfo);
}
}
return isModuleInCurrentSession;
return PowerShellModuleDetector.IsPowerShellModuleLoaded(_pwsh, _logger, Utils.ExternalDurableSdkName);
}
public void EnableExternalDurableSDK()

Просмотреть файл

@ -0,0 +1,20 @@
using System;
using System.Collections.Generic;
namespace Microsoft.Azure.Functions.PowerShellWorker.Utility
{
internal class LoggingEventHandler
{
private Action<string, string, Exception> _eventHandler = (a, b, c) => { };
public void Subscribe(Action<string, string, Exception> handler)
{
_eventHandler = handler;
}
public void LogToHandlers(string level, string message, Exception exception = null)
{
_eventHandler(level, message, exception);
}
}
}

Просмотреть файл

@ -18,6 +18,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.Utility
private readonly MessagingStream _msgStream;
private string _invocationId;
private string _requestId;
public LoggingEventHandler outputLogHandler = new LoggingEventHandler();
internal RpcLogger(MessagingStream msgStream)
{
@ -55,6 +56,8 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.Utility
};
_msgStream.Write(logMessage);
outputLogHandler.LogToHandlers(logLevel.ToString(), message, exception);
}
else
{

Просмотреть файл

@ -0,0 +1,16 @@
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;
namespace Microsoft.Azure.Functions.PowerShellWorker.OpenTelemetry
{
internal interface IPowerShellServicesForOpenTelemetry
{
bool? IsModuleLoaded();
void AddStartOpenTelemetryInvocationCommand(OpenTelemetryInvocationContext otelContext);
void StopOpenTelemetryInvocation(OpenTelemetryInvocationContext otelContext, bool invokeCommands);
void StartFunctionsLoggingListener(bool invokeCommands);
}
}

Просмотреть файл

@ -0,0 +1,104 @@
using System;
using Microsoft.Azure.Functions.PowerShellWorker.Utility;
namespace Microsoft.Azure.Functions.PowerShellWorker.OpenTelemetry
{
using PowerShell = System.Management.Automation.PowerShell;
internal class OpenTelemetryController
{
private IPowerShellServicesForOpenTelemetry _services;
private const string OTelEnabledEnvironmentVariableName = "OTEL_FUNCTIONS_WORKER_ENABLED";
private static bool? _isOpenTelemetryCapable;
private static bool? _isOpenTelemetryModuleLoaded;
private static bool? _isOpenTelmetryEnvironmentEnabled;
public OpenTelemetryController(ILogger logger, PowerShell pwsh)
: this(new PowerShellServicesForOpenTelemetry(logger, pwsh))
{ }
public OpenTelemetryController(IPowerShellServicesForOpenTelemetry services)
{
_services = services;
}
public bool IsOpenTelemetryCapable()
{
if (_isOpenTelemetryCapable.HasValue)
{
return _isOpenTelemetryCapable.Value;
}
_isOpenTelemetryCapable = IsOpenTelemetryEnvironmentEnabled() && IsOpenTelemetryModuleLoaded();
return _isOpenTelemetryCapable.Value;
}
public static bool IsOpenTelemetryEnvironmentEnabled()
{
if (_isOpenTelmetryEnvironmentEnabled.HasValue)
{
return _isOpenTelmetryEnvironmentEnabled.Value;
}
string enabledEnvVarValue = Environment.GetEnvironmentVariable(OTelEnabledEnvironmentVariableName);
if (!string.IsNullOrEmpty(enabledEnvVarValue) && bool.TryParse(enabledEnvVarValue, out bool isEnabled))
{
_isOpenTelmetryEnvironmentEnabled = isEnabled;
}
else
{
_isOpenTelmetryEnvironmentEnabled = false;
}
return _isOpenTelmetryEnvironmentEnabled.Value;
}
public bool IsOpenTelemetryModuleLoaded()
{
var isLoaded = _services.IsModuleLoaded();
_isOpenTelemetryModuleLoaded = isLoaded;
return _isOpenTelemetryModuleLoaded.Value;
}
public static void ResetOpenTelemetryModuleStatus()
{
_isOpenTelemetryCapable = null;
_isOpenTelemetryModuleLoaded = null;
_isOpenTelmetryEnvironmentEnabled = null;
}
public void AddStartOpenTelemetryInvocationCommand(OpenTelemetryInvocationContext otelContext)
{
if (!IsOpenTelemetryCapable())
{
return;
}
_services.AddStartOpenTelemetryInvocationCommand(otelContext);
}
public void StopOpenTelemetryInvocation(OpenTelemetryInvocationContext otelContext, bool invokeCommands = true)
{
if (!IsOpenTelemetryCapable())
{
return;
}
_services.StopOpenTelemetryInvocation(otelContext, invokeCommands);
}
internal void StartFunctionsLoggingListener(bool invokeCommands = true)
{
if (!IsOpenTelemetryCapable())
{
return;
}
_services.StartFunctionsLoggingListener(invokeCommands);
}
}
}

Просмотреть файл

@ -0,0 +1,27 @@
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;
namespace Microsoft.Azure.Functions.PowerShellWorker.OpenTelemetry
{
internal class OpenTelemetryInvocationContext
{
public OpenTelemetryInvocationContext(string invocationId, string traceParent, string traceState)
{
InvocationId = invocationId;
TraceParent = traceParent;
TraceState = traceState;
}
public bool IsValid()
{
return InvocationId != null && TraceParent != null;
}
public string InvocationId { get; set; }
public string TraceParent { get; set; }
public string TraceState { get; set; }
}
}

Просмотреть файл

@ -0,0 +1,76 @@
using Microsoft.Azure.Functions.PowerShellWorker.PowerShell;
using Microsoft.Azure.Functions.PowerShellWorker.Utility;
using System.Linq;
using System;
namespace Microsoft.Azure.Functions.PowerShellWorker.OpenTelemetry
{
using PowerShell = System.Management.Automation.PowerShell;
using LogLevel = Microsoft.Azure.WebJobs.Script.Grpc.Messages.RpcLog.Types.Level;
internal class PowerShellServicesForOpenTelemetry : IPowerShellServicesForOpenTelemetry
{
private const string StartOpenTelemetryInvocationCmdlet = "Start-OpenTelemetryInvocationInternal";
private const string StopOpenTelemetryInvocationCmdlet = "Stop-OpenTelemetryInvocationInternal";
private const string GetFunctionsLogHandlerCmdlet = "Get-FunctionsLogHandlerInternal";
private readonly ILogger _logger;
public readonly PowerShell _pwsh;
public PowerShellServicesForOpenTelemetry(ILogger logger, PowerShell pwsh)
{
_logger = logger;
_pwsh = pwsh;
}
public bool? IsModuleLoaded()
{
return PowerShellModuleDetector.IsPowerShellModuleLoaded(_pwsh, _logger, Utils.OpenTelemetrySdkName);
}
public void AddStartOpenTelemetryInvocationCommand(OpenTelemetryInvocationContext otelContext)
{
if (!otelContext.IsValid())
{
_logger.Log(false, LogLevel.Warning, PowerShellWorkerStrings.InvalidOpenTelemetryContext);
}
_pwsh.AddCommand(StartOpenTelemetryInvocationCmdlet)
.AddParameter("InvocationId", otelContext.InvocationId)
.AddParameter("TraceParent", otelContext.TraceParent)
.AddParameter("TraceState", otelContext.TraceState);
}
public void StopOpenTelemetryInvocation(OpenTelemetryInvocationContext otelContext, bool invokeCommands)
{
_pwsh.AddCommand(StopOpenTelemetryInvocationCmdlet)
.AddParameter("InvocationId", otelContext.InvocationId);
if (invokeCommands)
{
_pwsh.InvokeAndClearCommands();
}
}
public void StartFunctionsLoggingListener(bool invokeCommands)
{
_pwsh.AddCommand(GetFunctionsLogHandlerCmdlet);
if (!invokeCommands)
{
return;
}
var eventHandlers =
_pwsh.InvokeAndClearCommands<Action<string, string, Exception>>();
if (eventHandlers.Any())
{
if (_logger is RpcLogger rpcLogger)
{
rpcLogger.outputLogHandler.Subscribe(eventHandlers.First());
}
}
}
}
}

Просмотреть файл

@ -15,7 +15,7 @@ using LogLevel = Microsoft.Azure.WebJobs.Script.Grpc.Messages.RpcLog.Types.Level
namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
{
using Microsoft.Azure.Functions.PowerShellWorker.DurableWorker;
using Microsoft.Azure.Functions.PowerShellWorker.OpenTelemetry;
using System.Management.Automation;
using System.Text;
@ -37,6 +37,8 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
private readonly ErrorRecordFormatter _errorRecordFormatter = new ErrorRecordFormatter();
private OpenTelemetryController _openTelemetryController;
/// <summary>
/// Gets the Runspace InstanceId.
/// </summary>
@ -106,6 +108,9 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
// Run the profile.ps1
InvokeProfile(FunctionLoader.FunctionAppProfilePath);
_openTelemetryController = new OpenTelemetryController(Logger, _pwsh);
_openTelemetryController.StartFunctionsLoggingListener();
_runspaceInited = true;
}
}
@ -202,7 +207,8 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
TraceContext traceContext,
RetryContext retryContext,
IList<ParameterBinding> inputData,
FunctionInvocationPerformanceStopwatch stopwatch)
FunctionInvocationPerformanceStopwatch stopwatch,
OpenTelemetryInvocationContext otelContext)
{
var outputBindings = FunctionMetadata.GetOutputBindingHashtable(_pwsh.Runspace.InstanceId);
var durableFunctionsUtils = new DurableController(functionInfo.DurableFunctionInfo, _pwsh, Logger);
@ -212,6 +218,12 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
durableFunctionsUtils.InitializeBindings(inputData, out bool hasExternalDFsdk);
Logger.Log(isUserOnlyLog: false, LogLevel.Trace, String.Format(PowerShellWorkerStrings.UtilizingExternalDurableSDK, hasExternalDFsdk));
ImportEntryPointModule(functionInfo);
// This cmdlet must be run in the same .InvokeAndClearCommands() run as the function code itself
// If it is not, the Activity.Current context that we are trying to preserve is dropped
_openTelemetryController.AddStartOpenTelemetryInvocationCommand(otelContext);
AddEntryPointInvocationCommand(functionInfo);
stopwatch.OnCheckpoint(FunctionInvocationPerformanceStopwatch.Checkpoint.FunctionCodeReady);
@ -224,7 +236,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
try
{
if(functionInfo.DurableFunctionInfo.IsOrchestrationFunction)
if (functionInfo.DurableFunctionInfo.IsOrchestrationFunction)
{
return durableFunctionsUtils.InvokeOrchestrationFunction();
}
@ -255,6 +267,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
}
finally
{
_openTelemetryController.StopOpenTelemetryInvocation(otelContext);
durableFunctionsUtils.AfterFunctionInvocation();
outputBindings.Clear();
ResetRunspace();
@ -314,6 +327,17 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
return result;
}
private void ImportEntryPointModule(AzFunctionInfo functionInfo)
{
if (!string.IsNullOrEmpty(functionInfo.EntryPoint))
{
// If an entry point is defined, we import the script module.
_pwsh.AddCommand(Utils.ImportModuleCmdletInfo)
.AddParameter("Name", functionInfo.ScriptPath)
.InvokeAndClearCommands();
}
}
private void AddEntryPointInvocationCommand(AzFunctionInfo functionInfo)
{
if (string.IsNullOrEmpty(functionInfo.EntryPoint))
@ -322,11 +346,6 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
}
else
{
// If an entry point is defined, we import the script module.
_pwsh.AddCommand(Utils.ImportModuleCmdletInfo)
.AddParameter("Name", functionInfo.ScriptPath)
.InvokeAndClearCommands();
_pwsh.AddCommand(functionInfo.EntryPoint);
}
}

Просмотреть файл

@ -0,0 +1,56 @@
using Microsoft.Azure.Functions.PowerShellWorker.Utility;
using System;
using System.Linq;
using System.Management.Automation;
namespace Microsoft.Azure.Functions.PowerShellWorker.PowerShell
{
using LogLevel = WebJobs.Script.Grpc.Messages.RpcLog.Types.Level;
internal class PowerShellModuleDetector
{
public static bool IsPowerShellModuleLoaded(System.Management.Automation.PowerShell pwsh, ILogger logger, string moduleName)
{
// Search for the module in the current session
var matchingModules = pwsh.AddCommand(Utils.GetModuleCmdletInfo)
.AddParameter("FullyQualifiedName", moduleName)
.InvokeAndClearCommands<PSModuleInfo>();
// If we get at least one result, we know the module was imported
var numCandidates = matchingModules.Count();
var isModuleInCurrentSession = numCandidates > 0;
if (isModuleInCurrentSession)
{
string successMessage = PowerShellWorkerStrings.FoundExternalModuleInSession;
if (moduleName == Utils.ExternalDurableSdkName)
{
successMessage = PowerShellWorkerStrings.FoundExternalDurableSdkInSession;
}
else if (moduleName == Utils.OpenTelemetrySdkName)
{
successMessage = PowerShellWorkerStrings.FoundOpenTelemetrySdkInSession;
}
var candidatesInfo = matchingModules.Select(module => string.Format(successMessage, module.Name, module.Version, module.Path));
var externalSDKModuleInfo = string.Join('\n', candidatesInfo);
if (numCandidates > 1)
{
// If there's more than 1 result, there may be runtime conflicts
// warn user of potential conflicts
logger.Log(isUserOnlyLog: false, LogLevel.Warning, String.Format(
PowerShellWorkerStrings.MultipleExternalSDKsInSession,
numCandidates, moduleName, externalSDKModuleInfo));
}
else
{
// a single module is in session. Report its metadata
logger.Log(isUserOnlyLog: false, LogLevel.Trace, externalSDKModuleInfo);
}
}
return isModuleInCurrentSession;
}
}
}

Просмотреть файл

@ -21,6 +21,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker
using System.Diagnostics;
using LogLevel = Microsoft.Azure.WebJobs.Script.Grpc.Messages.RpcLog.Types.Level;
using System.Runtime.InteropServices;
using Microsoft.Azure.Functions.PowerShellWorker.OpenTelemetry;
internal class RequestProcessor
{
@ -113,6 +114,11 @@ namespace Microsoft.Azure.Functions.PowerShellWorker
response.WorkerInitResponse.Capabilities.Add("RpcHttpBodyOnly", "true");
response.WorkerInitResponse.Capabilities.Add("WorkerStatus", "true");
if (OpenTelemetryController.IsOpenTelemetryEnvironmentEnabled())
{
response.WorkerInitResponse.Capabilities.Add("WorkerOpenTelemetryEnabled", "true");
}
// If the environment variable is set, spin up the custom named pipe server.
// This is typically used for debugging. It will throw a friendly exception if the
// pipe name is not a valid pipename.
@ -354,7 +360,10 @@ namespace Microsoft.Azure.Functions.PowerShellWorker
var retryContext = GetRetryContext(functionInfo, invocationRequest);
stopwatch.OnCheckpoint(FunctionInvocationPerformanceStopwatch.Checkpoint.MetadataAndTraceContextReady);
return psManager.InvokeFunction(functionInfo, triggerMetadata, traceContext, retryContext, invocationRequest.InputData, stopwatch);
OpenTelemetryInvocationContext otelContext = new OpenTelemetryInvocationContext(invocationRequest.InvocationId,
invocationRequest.TraceContext?.TraceParent, invocationRequest.TraceContext?.TraceState);
return psManager.InvokeFunction(functionInfo, triggerMetadata, traceContext, retryContext, invocationRequest.InputData, stopwatch, otelContext);
}
internal StreamingMessage ProcessInvocationCancelRequest(StreamingMessage request)
@ -384,6 +393,15 @@ namespace Microsoft.Azure.Functions.PowerShellWorker
StreamingMessage.ContentOneofCase.FunctionEnvironmentReloadResponse,
out StatusResult status);
// This will force the OpenTelemetryController to check the environment variables and module presence again
OpenTelemetryController.ResetOpenTelemetryModuleStatus();
if (OpenTelemetryController.IsOpenTelemetryEnvironmentEnabled())
{
// Note: The ability to edit worker capabilities is new within the last few months. I am unsure if we need to
// report all prior capabilities that were sent at worker init. Going with minimal change for now.
response.FunctionEnvironmentReloadResponse.Capabilities.Add("WorkerOpenTelemetryEnabled", "true");
}
return response;
}

Просмотреть файл

@ -23,12 +23,13 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.Utility
internal readonly static CmdletInfo RemoveJobCmdletInfo = new CmdletInfo("Remove-Job", typeof(RemoveJobCommand));
internal readonly static CmdletInfo OutStringCmdletInfo = new CmdletInfo("Out-String", typeof(OutStringCommand));
internal readonly static CmdletInfo WriteInformationCmdletInfo = new CmdletInfo("Write-Information", typeof(WriteInformationCommand));
internal const string InternalDurableSdkName = "Microsoft.Azure.Functions.PowerShellWorker";
internal const string ExternalDurableSdkName = "AzureFunctions.PowerShell.Durable.SDK";
internal const string IsOrchestrationFailureKey = "IsOrchestrationFailure";
internal const string TracePipelineObjectCmdlet = "Microsoft.Azure.Functions.PowerShellWorker\\Trace-PipelineObject";
internal const string ExternalDurableSdkEnvVariable = "ExternalDurablePowerShellSDK";
internal const string OpenTelemetrySdkName = "AzureFunctions.PowerShell.OpenTelemetry.SDK";
internal readonly static object BoxedTrue = (object)true;
internal readonly static object BoxedFalse = (object)false;

Просмотреть файл

@ -355,6 +355,9 @@
<data name="FoundExternalDurableSdkInSession" xml:space="preserve">
<value>Found external Durable Functions SDK in session: Name='{0}', Version='{1}', Path='{2}'.</value>
</data>
<data name="FoundOpenTelemetrySdkInSession" xml:space="preserve">
<value>Found Open Telemetry SDK in session: Name='{0}', Version='{1}', Path='{2}'.</value>
</data>
<data name="UnableToInitializeOrchestrator" xml:space="preserve">
<value>Unable to initialize orchestrator function due to presence of other bindings. Total number of bindings found is '{0}'. Orchestrator Functions should never use any input or output bindings other than the orchestration trigger itself. See: aka.ms/df-bindings</value>
</data>
@ -379,4 +382,10 @@
<data name="ManagedDependenciesIsNotSupportedOnLegion" xml:space="preserve">
<value>Managed Dependencies is not supported in Linux Consumption on Legion. Please remove all module references from requirements.psd1 and include the function app dependencies with the function app content. For more information, please see https://aka.ms/functions-powershell-include-modules.</value>
</data>
<data name="FoundExternalModuleInSession" xml:space="preserve">
<value>Found external module in session: Name='{0}', Version='{1}', Path='{2}'.</value>
</data>
<data name="InvalidOpenTelemetryContext" xml:space="preserve">
<value>The app is configured to use OpenTelemetry but the TraceContext passed from host was null. </value>
</data>
</root>

Просмотреть файл

@ -7,6 +7,7 @@ using System;
using System.Collections;
using System.Collections.Generic;
using Microsoft.Azure.Functions.PowerShellWorker.Utility;
using Microsoft.Extensions.Logging.Abstractions;
using LogLevel = Microsoft.Azure.WebJobs.Script.Grpc.Messages.RpcLog.Types.Level;
namespace Microsoft.Azure.Functions.PowerShellWorker.Test

Просмотреть файл

@ -0,0 +1,170 @@
using Moq;
using System;
using Xunit;
using Microsoft.Azure.Functions.PowerShellWorker.OpenTelemetry;
using System.Linq;
using Microsoft.Azure.Functions.PowerShellWorker.Utility;
namespace Microsoft.Azure.Functions.PowerShellWorker.Test.OpenTelemetry
{
using PowerShell = System.Management.Automation.PowerShell;
public class OpenTelemetryControllerTests
{
// These constant values will work because they are not actually passed to the module
// The module would fail with these inputs, it needs real invocation id and trace information
private const string FakeInvocationID = "Fake InvocationID";
private const string FakeTraceParent = "Fake TraceParent";
private readonly Mock<ILogger> _mockLogger = new Mock<ILogger>(MockBehavior.Strict);
private readonly Mock<IPowerShellServicesForOpenTelemetry> _mockOtelServices;
public OpenTelemetryControllerTests()
{
_mockOtelServices = new Mock<IPowerShellServicesForOpenTelemetry>(MockBehavior.Strict);
}
[Theory]
[InlineData("true", true)]
[InlineData("false", false)]
[InlineData("True", true)]
[InlineData("False", false)]
[InlineData(null, false)]
internal void OpenTelemetryEnvironmentVariableCheckWorks(string? environmentVariableValue, bool desiredResult)
{
try
{
Environment.SetEnvironmentVariable("OTEL_FUNCTIONS_WORKER_ENABLED", environmentVariableValue);
Assert.Equal(desiredResult, OpenTelemetryController.IsOpenTelemetryEnvironmentEnabled());
}
finally
{
Environment.SetEnvironmentVariable("OTEL_FUNCTIONS_WORKER_ENABLED", null);
OpenTelemetryController.ResetOpenTelemetryModuleStatus();
}
}
[Fact]
internal void AddStartOpenTelemetryInvocationCommand_AddsCommands()
{
try
{
PowerShell _pwsh = PowerShell.Create();
var _realOTelServices = new PowerShellServicesForOpenTelemetry(_mockLogger.Object, _pwsh);
OpenTelemetryController controller = CreateMockOpenTelemetryController();
OpenTelemetryInvocationContext context = new OpenTelemetryInvocationContext(
FakeInvocationID,
FakeTraceParent,
string.Empty
);
Environment.SetEnvironmentVariable("OTEL_FUNCTIONS_WORKER_ENABLED", "true");
_mockOtelServices.Setup(_ => _.IsModuleLoaded()).Returns(true);
_mockOtelServices.Setup(_ => _.AddStartOpenTelemetryInvocationCommand(context))
.Callback(() => _realOTelServices.AddStartOpenTelemetryInvocationCommand(context));
controller.AddStartOpenTelemetryInvocationCommand(context);
Assert.Single(_pwsh.Commands.Commands);
Assert.Equal("Start-OpenTelemetryInvocationInternal", _pwsh.Commands.Commands.First().CommandText);
var parameters = _pwsh.Commands.Commands.First().Parameters;
Assert.Equal(3, parameters.Count);
Assert.Equal("InvocationId", parameters.ElementAt(0).Name);
Assert.Equal(context.InvocationId, parameters.ElementAt(0).Value);
Assert.Equal("TraceParent", parameters.ElementAt(1).Name);
Assert.Equal(context.TraceParent, parameters.ElementAt(1).Value);
Assert.Equal("TraceState", parameters.ElementAt(2).Name);
Assert.Equal(context.TraceState, parameters.ElementAt(2).Value);
_mockOtelServices.Verify(_ => _.AddStartOpenTelemetryInvocationCommand(context), Times.Once);
}
finally
{
Environment.SetEnvironmentVariable("OTEL_FUNCTIONS_WORKER_ENABLED", null);
OpenTelemetryController.ResetOpenTelemetryModuleStatus();
}
}
[Fact]
internal void StopOpenTelemetryInvocationCommand_AddsCommands()
{
try
{
PowerShell _pwsh = PowerShell.Create();
var _realOTelServices = new PowerShellServicesForOpenTelemetry(_mockLogger.Object, _pwsh);
OpenTelemetryController controller = CreateMockOpenTelemetryController();
OpenTelemetryInvocationContext context = new OpenTelemetryInvocationContext(
FakeInvocationID,
FakeTraceParent,
string.Empty
);
Environment.SetEnvironmentVariable("OTEL_FUNCTIONS_WORKER_ENABLED", "true");
_mockOtelServices.Setup(_ => _.IsModuleLoaded()).Returns(true);
_mockOtelServices.Setup(_ => _.StopOpenTelemetryInvocation(context, false))
.Callback(() => _realOTelServices.StopOpenTelemetryInvocation(context, false));
controller.StopOpenTelemetryInvocation(context, false);
Assert.Single(_pwsh.Commands.Commands);
Assert.Equal("Stop-OpenTelemetryInvocationInternal", _pwsh.Commands.Commands.First().CommandText);
var parameters = _pwsh.Commands.Commands.First().Parameters;
Assert.Single(parameters);
Assert.Equal("InvocationId", parameters.ElementAt(0).Name);
Assert.Equal(context.InvocationId, parameters.ElementAt(0).Value);
_mockOtelServices.Verify(_ => _.StopOpenTelemetryInvocation(context, false), Times.Once);
}
finally
{
Environment.SetEnvironmentVariable("OTEL_FUNCTIONS_WORKER_ENABLED", null);
OpenTelemetryController.ResetOpenTelemetryModuleStatus();
}
}
[Fact]
internal void StartFunctionsLoggingListener_CorrectCommands()
{
try
{
PowerShell _pwsh = PowerShell.Create();
var _realOTelServices = new PowerShellServicesForOpenTelemetry(_mockLogger.Object, _pwsh);
OpenTelemetryController controller = CreateMockOpenTelemetryController();
Environment.SetEnvironmentVariable("OTEL_FUNCTIONS_WORKER_ENABLED", "true");
_mockOtelServices.Setup(_ => _.IsModuleLoaded()).Returns(true);
_mockOtelServices.Setup(_ => _.StartFunctionsLoggingListener(false))
.Callback(() => _realOTelServices.StartFunctionsLoggingListener(false));
controller.StartFunctionsLoggingListener(false);
Assert.Single(_pwsh.Commands.Commands);
Assert.Equal("Get-FunctionsLogHandlerInternal", _pwsh.Commands.Commands.First().CommandText);
var parameters = _pwsh.Commands.Commands.First().Parameters;
Assert.Empty(parameters);
_mockOtelServices.Verify(_ => _.StartFunctionsLoggingListener(false), Times.Once);
}
finally
{
Environment.SetEnvironmentVariable("OTEL_FUNCTIONS_WORKER_ENABLED", null);
OpenTelemetryController.ResetOpenTelemetryModuleStatus();
}
}
private OpenTelemetryController CreateMockOpenTelemetryController()
{
return new OpenTelemetryController(_mockOtelServices.Object);
}
}
}

Просмотреть файл

@ -19,6 +19,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.Test
using System.Management.Automation;
using Microsoft.Azure.Functions.PowerShellWorker.Durable;
using Microsoft.Azure.Functions.PowerShellWorker.DurableWorker;
using Microsoft.Extensions.Logging.Abstractions;
using Newtonsoft.Json;
internal class TestUtils
@ -403,7 +404,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.Test
{
FunctionMetadata.RegisterFunctionMetadata(testManager.InstanceId, functionInfo.OutputBindings);
var result = testManager.InvokeFunction(functionInfo, null, null, null, CreateOrchestratorInputData(), new FunctionInvocationPerformanceStopwatch());
var result = testManager.InvokeFunction(functionInfo, null, null, null, CreateOrchestratorInputData(), new FunctionInvocationPerformanceStopwatch(), null);
var relevantLogs = s_testLogger.FullLog.Where(message => message.StartsWith("Information: OUTPUT:")).ToList();
var expected = shouldSuppressPipelineTraces ? new string[0] : new[] { "Information: OUTPUT: Hello" };
@ -439,7 +440,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.Test
Hashtable triggerMetadata = null,
RetryContext retryContext = null)
{
return powerShellManager.InvokeFunction(functionInfo, triggerMetadata, null, retryContext, s_testInputData, new FunctionInvocationPerformanceStopwatch());
return powerShellManager.InvokeFunction(functionInfo, triggerMetadata, null, retryContext, s_testInputData, new FunctionInvocationPerformanceStopwatch(), null);
}
private class ContextValidatingLogger : ILogger