Log module installation time (#814) (#818)

* Log the module installation time

* Update tests

Author: Francisco-Gamino

src/DependencyManagement/DependencySnapshotInstaller.cs

@@ -9,6 +9,7 @@ namespace Microsoft.Azure.Functions.PowerShellWorker.DependencyManagement
     using System.Collections.Generic;
     using System.Management.Automation;
     using System.Threading;
+    using System.Diagnostics;
 
     using Microsoft.Azure.Functions.PowerShellWorker.Utility;
 
@@ -129,9 +130,12 @@ private void InstallModule(DependencyInfo module, string installingPath, PowerSh
             {
                 try
                 {
+                    var stopwatch = new Stopwatch();
+                    stopwatch.Start();
+
                     _moduleProvider.SaveModule(pwsh, module.Name, module.ExactVersion, installingPath);
 
-                    var message = string.Format(PowerShellWorkerStrings.ModuleHasBeenInstalled, module.Name, module.ExactVersion);
+                    var message = string.Format(PowerShellWorkerStrings.ModuleHasBeenInstalled, module.Name, module.ExactVersion, stopwatch.ElapsedMilliseconds);
                     logger.Log(isUserOnlyLog: false, LogLevel.Trace, message);
 
                     break;

src/resources/PowerShellWorkerStrings.resx

@@ -179,7 +179,7 @@
     <value>Started installing module '{0}' version '{1}'.</value>
   </data>
   <data name="ModuleHasBeenInstalled" xml:space="preserve">
-    <value>Module name '{0}' version '{1}' has been installed.</value>
+    <value>Module name '{0}' version '{1}' has been installed. Module installation completed in {2} ms.</value>
   </data>
   <data name="AcceptableFunctionAppDependenciesAlreadyInstalled" xml:space="preserve">
     <value>The function app has existing dependencies installed. Updating the dependencies to the latest versions will be performed in the background. New function app instances will pick up any new dependencies.</value>

test/Unit/DependencyManagement/DependencyManagementTests.cs

@@ -11,8 +11,10 @@
 
 namespace Microsoft.Azure.Functions.PowerShellWorker.Test
 {
+    using System.Diagnostics;
     using System.Linq;
     using System.Management.Automation;
+    using System.Threading;
 
     public class DependencyManagementTests : IDisposable
     {
@@ -481,8 +483,12 @@ public void SaveModule(PowerShell pwsh, string moduleName, string version, strin
         {
             if (SuccessfulDownload || (SaveModuleCount >= ShouldNotThrowAfterCount))
             {
+                var stopwatch = new Stopwatch();
+                stopwatch.Start();
+                Thread.Sleep(10); // wait for 10 milliseconds
+
                 // Save the module name and version for a successful download.
-                DownloadedModuleInfo = string.Format(PowerShellWorkerStrings.ModuleHasBeenInstalled, moduleName, version);
+                DownloadedModuleInfo = string.Format(PowerShellWorkerStrings.ModuleHasBeenInstalled, moduleName, version, stopwatch.ElapsedMilliseconds);
                 return;
             }