diff --git a/src/RequestProcessor.cs b/src/RequestProcessor.cs index c9c10d2f..b2f177a0 100644 --- a/src/RequestProcessor.cs +++ b/src/RequestProcessor.cs @@ -20,6 +20,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker { using System.Diagnostics; using LogLevel = Microsoft.Azure.WebJobs.Script.Grpc.Messages.RpcLog.Types.Level; + using System.Runtime.InteropServices; internal class RequestProcessor { @@ -27,6 +28,7 @@ internal class RequestProcessor private readonly System.Management.Automation.PowerShell _firstPwshInstance; private readonly PowerShellManagerPool _powershellPool; private DependencyManager _dependencyManager; + private string _pwshVersion; // Holds the exception if an issue is encountered while processing the function app dependencies. private Exception _initTerminatingError; @@ -37,11 +39,12 @@ internal class RequestProcessor private Dictionary> _requestHandlers = new Dictionary>(); - internal RequestProcessor(MessagingStream msgStream, System.Management.Automation.PowerShell firstPwshInstance) + internal RequestProcessor(MessagingStream msgStream, System.Management.Automation.PowerShell firstPwshInstance, string pwshVersion) { _msgStream = msgStream; _firstPwshInstance = firstPwshInstance; _powershellPool = new PowerShellManagerPool(() => new RpcLogger(msgStream)); + _pwshVersion = pwshVersion; // Host sends capabilities/init data to worker _requestHandlers.Add(StreamingMessage.ContentOneofCase.WorkerInitRequest, ProcessWorkerInitRequest); @@ -95,6 +98,9 @@ internal async Task ProcessRequestLoop() internal StreamingMessage ProcessWorkerInitRequest(StreamingMessage request) { + var stopwatch = new Stopwatch(); + stopwatch.Start(); + var workerInitRequest = request.WorkerInitRequest; Environment.SetEnvironmentVariable("AZUREPS_HOST_ENVIRONMENT", $"AzureFunctions/{workerInitRequest.HostVersion}"); Environment.SetEnvironmentVariable("POWERSHELL_DISTRIBUTION_CHANNEL", $"Azure-Functions:{workerInitRequest.HostVersion}"); @@ -117,6 +123,22 @@ internal StreamingMessage ProcessWorkerInitRequest(StreamingMessage request) RemoteSessionNamedPipeServer.CreateCustomNamedPipeServer(pipeName); } + try + { + var rpcLogger = new RpcLogger(_msgStream); + rpcLogger.SetContext(request.RequestId, null); + + response.WorkerInitResponse.WorkerMetadata = GetWorkerMetadata(_pwshVersion); + + rpcLogger.Log(isUserOnlyLog: false, LogLevel.Trace, string.Format(PowerShellWorkerStrings.WorkerInitCompleted, stopwatch.ElapsedMilliseconds)); + } + catch (Exception e) + { + status.Status = StatusResult.Types.Status.Failure; + status.Exception = e.ToRpcException(); + return response; + } + return response; } @@ -180,11 +202,10 @@ internal StreamingMessage ProcessFunctionLoadRequest(StreamingMessage request) return response; } - // Ideally, the initialization should happen when processing 'WorkerInitRequest', however, the 'WorkerInitRequest' - // message doesn't provide information about the FunctionApp. That information is not available until the first - // 'FunctionLoadRequest' comes in. Therefore, we run initialization here. - // Also, we receive a FunctionLoadRequest when a proxy is configured. Proxies don't have the Metadata.Directory set - // which would cause initialization issues with the PSModulePath. Since they don't have that set, we skip over them. + // Ideally, the initialization should happen when processing 'WorkerInitRequest'. However, we defer the initialization + // until the first 'FunctionLoadRequest' which contains the information about whether Managed Dependencies is enabled for the function app, + // and if it is, we add the Managed Dependencies path to the PSModulePath. + // Also, we receive a FunctionLoadRequest when a proxy is configured. This is just a no-op on the worker size, so we skip over them. if (!_isFunctionAppInitialized && !functionLoadRequest.Metadata.IsProxy) { try @@ -519,6 +540,17 @@ private void SetupAppRootPathAndModulePath(FunctionLoadRequest functionLoadReque .InvokeAndClearCommands(); } + private WorkerMetadata GetWorkerMetadata(string pwshVersion) + { + var data = new WorkerMetadata(); + data.WorkerBitness = RuntimeInformation.OSArchitecture.ToString(); + data.WorkerVersion = typeof(Worker).Assembly.GetName().Version.ToString(); + data.RuntimeVersion = pwshVersion; + data.RuntimeName = "powershell"; + + return data; + } + #endregion } } diff --git a/src/Worker.cs b/src/Worker.cs index 8987086c..d580e79a 100644 --- a/src/Worker.cs +++ b/src/Worker.cs @@ -40,11 +40,12 @@ public async static Task Main(string[] args) // This PowerShell instance is shared by the first PowerShellManager instance created in the pool, // and the dependency manager (used to download dependent modules if needed). var firstPowerShellInstance = Utils.NewPwshInstance(); - LogPowerShellVersion(firstPowerShellInstance); + var pwshVersion = Utils.GetPowerShellVersion(firstPowerShellInstance); + LogPowerShellVersion(pwshVersion); WarmUpPowerShell(firstPowerShellInstance); var msgStream = new MessagingStream(arguments.Host, arguments.Port); - var requestProcessor = new RequestProcessor(msgStream, firstPowerShellInstance); + var requestProcessor = new RequestProcessor(msgStream, firstPowerShellInstance, pwshVersion); // Send StartStream message var startedMessage = new StreamingMessage() @@ -75,9 +76,9 @@ private static void WarmUpPowerShell(System.Management.Automation.PowerShell fir .InvokeAndClearCommands(); } - private static void LogPowerShellVersion(System.Management.Automation.PowerShell pwsh) + private static void LogPowerShellVersion(string pwshVersion) { - var message = string.Format(PowerShellWorkerStrings.PowerShellVersion, Utils.GetPowerShellVersion(pwsh)); + var message = string.Format(PowerShellWorkerStrings.PowerShellVersion, pwshVersion); RpcLogger.WriteSystemLog(LogLevel.Information, message); } } diff --git a/src/resources/PowerShellWorkerStrings.resx b/src/resources/PowerShellWorkerStrings.resx index 2d0228d7..07d6e78d 100644 --- a/src/resources/PowerShellWorkerStrings.resx +++ b/src/resources/PowerShellWorkerStrings.resx @@ -352,4 +352,7 @@ Dependency snapshot '{0}' does not contain acceptable module versions. + + Worker init request completed in {0} ms. + \ No newline at end of file