diff --git a/poc/TestOfTestFramework/nano.runsettings b/poc/TestOfTestFramework/nano.runsettings index 62f0a00..521afd3 100644 --- a/poc/TestOfTestFramework/nano.runsettings +++ b/poc/TestOfTestFramework/nano.runsettings @@ -9,5 +9,7 @@ None + True + \ No newline at end of file diff --git a/source/TestAdapter/DeploymentAssembly.cs b/source/TestAdapter/DeploymentAssembly.cs new file mode 100644 index 0000000..7ba32ad --- /dev/null +++ b/source/TestAdapter/DeploymentAssembly.cs @@ -0,0 +1,35 @@ +// +// Copyright (c) .NET Foundation and Contributors +// See LICENSE file in the project root for full license information. +// + +using System.Collections.Generic; + +namespace nanoFramework.TestPlatform.TestAdapter +{ + public class DeploymentAssembly + { + /// + /// Path to the EXE or DLL file. + /// + public string Path { get; set; } + + /// + /// Assembly version of the EXE or DLL. + /// + public string Version { get; set; } + + /// + /// Required version of the native implementation of the class library. + /// Only used in class libraries. Can be empty on the core library and user EXE and DLLs. + /// + public string NativeVersion { get; set; } + + public DeploymentAssembly(string path, string version, string nativeVersion) + { + Path = path; + Version = version; + NativeVersion = nativeVersion; + } + } +} \ No newline at end of file diff --git a/source/TestAdapter/Executor.cs b/source/TestAdapter/Executor.cs index 3316b7e..9892446 100644 --- a/source/TestAdapter/Executor.cs +++ b/source/TestAdapter/Executor.cs @@ -4,9 +4,14 @@ // See LICENSE file in the project root for full license information. // +using ICSharpCode.Decompiler; +using ICSharpCode.Decompiler.CSharp; using Microsoft.VisualStudio.TestPlatform.ObjectModel; using Microsoft.VisualStudio.TestPlatform.ObjectModel.Adapter; using nanoFramework.TestAdapter; +using nanoFramework.Tools.Debugger; +using nanoFramework.Tools.Debugger.Extensions; +using nanoFramework.Tools.Debugger.WireProtocol; using System; using System.Collections.Generic; using System.Diagnostics; @@ -15,6 +20,7 @@ using System.Text; using System.Text.RegularExpressions; using System.Threading; +using System.Threading.Tasks; namespace nanoFramework.TestPlatform.TestAdapter { @@ -32,6 +38,12 @@ class Executor : ITestExecutor private LogMessenger _logger; private Process _nanoClr; + // number of retries when performing a deploy operation + private const int _numberOfRetries = 5; + + // timeout when performing a deploy operation + private const int _timeoutMiliseconds = 1000; + private IFrameworkHandle _frameworkHandle = null; /// @@ -95,7 +107,19 @@ public void RunTests(IEnumerable tests, IRunContext runContext, IFrame $"Test group is '{source}'", Settings.LoggingLevel.Detailed); - var results = RunTest(groups.ToList()); + // + List results; + + if (_settings.IsRealHardware) + { + // we are connecting to a real device + results = RunTestOnHardwareAsync(groups.ToList()).GetAwaiter().GetResult(); + } + else + { + // we are connecting to WIN32 nanoCLR + results = RunTest(groups.ToList()); + } foreach (var result in results) { @@ -104,6 +128,305 @@ public void RunTests(IEnumerable tests, IRunContext runContext, IFrame } } + private async Task> RunTestOnHardwareAsync(List tests) + { + List results = PrepareListResult(tests); + List assemblies = new List(); + string port = _settings.RealHardwarePort == string.Empty ? "COM4" : _settings.RealHardwarePort; + //var serialDebugClient = PortBase.CreateInstanceForSerial("", null, true, new List() { port }); + var serialDebugClient = PortBase.CreateInstanceForSerial("", null, true, null); + + _logger.LogMessage($"Checking device on port {port}.", Settings.LoggingLevel.Verbose); + while (!serialDebugClient.IsDevicesEnumerationComplete) + { + Thread.Sleep(1); + } + + _logger.LogMessage($"Found: {serialDebugClient.NanoFrameworkDevices.Count} devices", Settings.LoggingLevel.Verbose); + + if(serialDebugClient.NanoFrameworkDevices.Count == 0) + { + results.First().Outcome = TestOutcome.Failed; + results.First().ErrorMessage = $"Couldn't find any device, please try to disable the device scanning in the Visual Studio Extension! If the situation persists reboot the device as well."; + return results; + } + + var device = serialDebugClient.NanoFrameworkDevices[0]; + + // check if debugger engine exists + if (device.DebugEngine == null) + { + device.CreateDebugEngine(); + _logger.LogMessage($"Debug engine created.", Settings.LoggingLevel.Verbose); + } + + bool deviceIsInInitializeState = false; + int retryCount = 0; + + bool connectResult = await device.DebugEngine.ConnectAsync(5000, true); + _logger.LogMessage($"Device connect result is {connectResult}.", Settings.LoggingLevel.Verbose); + + if (connectResult) + { + // erase the device + var eraseResult = await Task.Run(async delegate + { + _logger.LogMessage($"Erase deployment block storage.", Settings.LoggingLevel.Error); + return await device.EraseAsync( + EraseOptions.Deployment, + CancellationToken.None, + null, + null); + }); + + _logger.LogMessage($"Erase result is {eraseResult}.", Settings.LoggingLevel.Verbose); + if (eraseResult) + { + + // initial check + if (device.DebugEngine.IsDeviceInInitializeState()) + { + _logger.LogMessage($"Device status verified as being in initialized state. Requesting to resume execution.", Settings.LoggingLevel.Error); + // set flag + deviceIsInInitializeState = true; + + // device is still in initialization state, try resume execution + device.DebugEngine.ResumeExecution(); + } + + // handle the workflow required to try resuming the execution on the device + // only required if device is not already there + // retry 5 times with a 500ms interval between retries + while (retryCount++ < _numberOfRetries && deviceIsInInitializeState) + { + if (!device.DebugEngine.IsDeviceInInitializeState()) + { + _logger.LogMessage($"Device has completed initialization.", Settings.LoggingLevel.Verbose); + // done here + deviceIsInInitializeState = false; + break; + } + + _logger.LogMessage($"Waiting for device to report initialization completed ({retryCount}/{_numberOfRetries}).", Settings.LoggingLevel.Verbose); + // provide feedback to user on the 1st pass + if (retryCount == 0) + { + _logger.LogMessage($"Waiting for device to initialize.", Settings.LoggingLevel.Verbose); + } + + if (device.DebugEngine.IsConnectedTonanoBooter) + { + _logger.LogMessage($"Device reported running nanoBooter. Requesting to load nanoCLR.", Settings.LoggingLevel.Verbose); + // request nanoBooter to load CLR + device.DebugEngine.ExecuteMemory(0); + } + else if (device.DebugEngine.IsConnectedTonanoCLR) + { + _logger.LogMessage($"Device reported running nanoCLR. Requesting to reboot nanoCLR.", Settings.LoggingLevel.Error); + await Task.Run(delegate + { + // already running nanoCLR try rebooting the CLR + device.DebugEngine.RebootDevice(RebootOptions.ClrOnly); + }); + } + + // wait before next pass + // use a back-off strategy of increasing the wait time to accommodate slower or less responsive targets (such as networked ones) + await Task.Delay(TimeSpan.FromMilliseconds(_timeoutMiliseconds * (retryCount + 1))); + + await Task.Yield(); + } + + // check if device is still in initialized state + if (!deviceIsInInitializeState) + { + // device has left initialization state + _logger.LogMessage($"Device is initialized and ready!", Settings.LoggingLevel.Verbose); + await Task.Yield(); + + + ////////////////////////////////////////////////////////// + // sanity check for devices without native assemblies ?!?! + if (device.DeviceInfo.NativeAssemblies.Count == 0) + { + _logger.LogMessage($"Device reporting no assemblies loaded. This can not happen. Sanity check failed.", Settings.LoggingLevel.Error); + // there are no assemblies deployed?! + results.First().Outcome = TestOutcome.Failed; + results.First().ErrorMessage = $"Couldn't find any native assemblies deployed in {device.Description}, {device.TargetName} on {device.SerialNumber}! If the situation persists reboot the device."; + return results; + } + + _logger.LogMessage($"Computing deployment blob.", Settings.LoggingLevel.Verbose); + // build a list with the full path for each DLL, referenced DLL and EXE + List assemblyList = new List(); + + var source = tests.First().Source; + var workingDirectory = Path.GetDirectoryName(source); + var allPeFiles = Directory.GetFiles(workingDirectory, "*.pe"); + + // load tests in case we don't need to check the version: + //foreach (var pe in allPeFiles) + //{ + // assemblyList.Add( + // new DeploymentAssembly(Path.Combine(workingDirectory, pe), "", "")); + //} + + // TODO do we need to check versions? + var decompilerSettings = new DecompilerSettings + { + LoadInMemory = false, + ThrowOnAssemblyResolveErrors = false + }; + + foreach (string assemblyPath in allPeFiles) + { + // load assembly in order to get the versions + var file = Path.Combine(workingDirectory, assemblyPath.Replace(".pe", ".dll")); + if (!File.Exists(file)) + { + // Check with an exe + file = Path.Combine(workingDirectory, assemblyPath.Replace(".pe", ".exe")); + } + + var decompiler = new CSharpDecompiler(file, decompilerSettings); ; + var assemblyProperties = decompiler.DecompileModuleAndAssemblyAttributesToString(); + + // read attributes using a Regex + + // AssemblyVersion + string pattern = @"(?<=AssemblyVersion\("")(.*)(?=\""\)])"; + var match = Regex.Matches(assemblyProperties, pattern, RegexOptions.IgnoreCase); + string assemblyVersion = match[0].Value; + + // AssemblyNativeVersion + pattern = @"(?<=AssemblyNativeVersion\("")(.*)(?=\""\)])"; + match = Regex.Matches(assemblyProperties, pattern, RegexOptions.IgnoreCase); + + // only class libs have this attribute, therefore sanity check is required + string nativeVersion = ""; + if (match.Count == 1) + { + nativeVersion = match[0].Value; + } + + assemblyList.Add(new DeploymentAssembly(Path.Combine(workingDirectory, assemblyPath), assemblyVersion, nativeVersion)); + } + + _logger.LogMessage($"Added {assemblyList.Count} assemblies to deploy.", Settings.LoggingLevel.Verbose); + await Task.Yield(); + + // Keep track of total assembly size + long totalSizeOfAssemblies = 0; + + // TODO use this code to load the PE files + + // now we will re-deploy all system assemblies + foreach (DeploymentAssembly peItem in assemblyList) + { + // append to the deploy blob the assembly + using (FileStream fs = File.Open(peItem.Path, FileMode.Open, FileAccess.Read)) + { + long length = (fs.Length + 3) / 4 * 4; + _logger.LogMessage($"Adding {Path.GetFileNameWithoutExtension(peItem.Path)} v{peItem.Version} ({length} bytes) to deployment bundle", Settings.LoggingLevel.Verbose); + byte[] buffer = new byte[length]; + + await Task.Yield(); + + await fs.ReadAsync(buffer, 0, (int)fs.Length); + assemblies.Add(buffer); + + // Increment totalizer + totalSizeOfAssemblies += length; + } + } + + _logger.LogMessage($"Deploying {assemblyList.Count:N0} assemblies to device... Total size in bytes is {totalSizeOfAssemblies}.", Settings.LoggingLevel.Verbose); + // need to keep a copy of the deployment blob for the second attempt (if needed) + var assemblyCopy = new List(assemblies); + + await Task.Yield(); + + await Task.Run(async delegate + { + // OK to skip erase as we just did that + // no need to reboot device + if (!device.DebugEngine.DeploymentExecute( + assemblyCopy, + false, + true, + null, + null)) + { + // if the first attempt fails, give it another try + + // wait before next pass + await Task.Delay(TimeSpan.FromSeconds(1)); + + await Task.Yield(); + + _logger.LogMessage("Deploying assemblies. Second attempt.", Settings.LoggingLevel.Verbose); + + // !! need to use the deployment blob copy + assemblyCopy = new List(assemblies); + + // can't skip erase as we just did that + // no need to reboot device + if (!device.DebugEngine.DeploymentExecute( + assemblyCopy, + false, + false, + null, + null)) + { + _logger.LogMessage("Deployment failed.", Settings.LoggingLevel.Error); + + // throw exception to signal deployment failure + results.First().Outcome = TestOutcome.Failed; + results.First().ErrorMessage = $"Deployment failed in {device.Description}, {device.TargetName} on {device.SerialNumber}! If the situation persists reboot the device."; + } + } + }); + + await Task.Yield(); + // If there has been an issue before, the first test is marked as failed + if (results.First().Outcome == TestOutcome.Failed) + { + return results; + } + + StringBuilder output = new StringBuilder(); + bool isFinished = false; + // attach listner for messages + device.DebugEngine.OnMessage += (message, text) => + { + _logger.LogMessage(text, Settings.LoggingLevel.Verbose); + output.AppendLine(text); + if (text.Contains(Done)) + { + isFinished = true; + } + }; + + device.DebugEngine.RebootDevice(RebootOptions.ClrOnly); + + while (!isFinished) + { + Thread.Sleep(1); + } + + _logger.LogMessage($"Tests finished.", Settings.LoggingLevel.Verbose); + CheckAllTests(output.ToString(), results); + } + else + { + _logger.LogMessage("Failed to initialize device.", Settings.LoggingLevel.Error); + } + } + } + + return results; + } + /// public void RunTests(IEnumerable sources, IRunContext runContext, IFrameworkHandle frameworkHandle) { @@ -119,6 +442,19 @@ public void RunTests(IEnumerable sources, IRunContext runContext, IFrame } } + private List PrepareListResult(List tests) + { + List results = new List(); + + foreach (var test in tests) + { + TestResult result = new TestResult(test) { Outcome = TestOutcome.None }; + results.Add(result); + } + + return results; + } + private List RunTest(List tests) { _logger.LogMessage( @@ -135,13 +471,7 @@ private List RunTest(List tests) $"Timeout set to {runTimeout}ms", Settings.LoggingLevel.Verbose); - List results = new List(); - - foreach (var test in tests) - { - TestResult result = new TestResult(test) { Outcome = TestOutcome.None }; - results.Add(result); - } + List results = PrepareListResult(tests); _logger.LogMessage( "Processing assemblies to load into test runner...", @@ -149,7 +479,7 @@ private List RunTest(List tests) var source = tests.First().Source; var workingDirectory = Path.GetDirectoryName(source); - var allPeFiles = Directory.GetFiles(workingDirectory, "*.pe"); + var allPeFiles = Directory.GetFiles(workingDirectory, "*.pe"); // prepare the process start of the WIN32 nanoCLR _nanoClr = new Process(); @@ -167,7 +497,7 @@ private List RunTest(List tests) // 3. test framework // 4. test application StringBuilder str = new StringBuilder(); - foreach(var pe in allPeFiles) + foreach (var pe in allPeFiles) { str.Append($" -load {Path.Combine(workingDirectory, pe)}"); } @@ -233,54 +563,7 @@ private List RunTest(List tests) // wait for exit, no worries about the outcome _nanoClr.WaitForExit(runTimeout); - var outputStrings = Regex.Split(output.ToString(), @"((\r)+)?(\n)+((\r)+)?").Where(m => !string.IsNullOrEmpty(m)); - - _logger.LogMessage( - "Parsing test results...", - Settings.LoggingLevel.Verbose); - - foreach (var line in outputStrings) - { - if (line.Contains(TestPassed)) - { - // Format is "Test passed: MethodName, ticks"; - // We do get split with space if the coma is missing, happens time to time - string method = line.Substring(line.IndexOf(TestPassed) + TestPassed.Length).Split(',')[0].Split(' ')[0]; - string ticks = line.Substring(line.IndexOf(TestPassed) + TestPassed.Length + method.Length + 2); - long ticksNum = 0; - - try - { - ticksNum = Convert.ToInt64(ticks); - } - catch (Exception) - { - // We won't do anything - } - - // Find the test - var res = results.Where(m => m.TestCase.DisplayName == method); - if (res.Any()) - { - res.First().Duration = TimeSpan.FromTicks(ticksNum); - res.First().Outcome = TestOutcome.Passed; - } - } - else if (line.Contains(TestFailed)) - { - // Format is "Test passed: MethodName, Exception message"; - string method = line.Substring(line.IndexOf(TestFailed) + TestFailed.Length).Split(',')[0].Split(' ')[0]; - string exception = line.Substring(line.IndexOf(TestFailed) + TestPassed.Length + method.Length + 2); - - // Find the test - var res = results.Where(m => m.TestCase.DisplayName == method); - if (res.Any()) - { - res.First().ErrorMessage = exception; - res.First().Outcome = TestOutcome.Failed; - } - } - } + CheckAllTests(output.ToString(), results); if (!output.ToString().Contains(Done)) { @@ -319,5 +602,57 @@ private List RunTest(List tests) return results; } + + private void CheckAllTests(string toCheck, List results) + { + var outputStrings = Regex.Split(toCheck, @"((\r)+)?(\n)+((\r)+)?").Where(m => !string.IsNullOrEmpty(m)); + + _logger.LogMessage( + "Parsing test results...", + Settings.LoggingLevel.Verbose); + + foreach (var line in outputStrings) + { + if (line.Contains(TestPassed)) + { + // Format is "Test passed: MethodName, ticks"; + // We do get split with space if the coma is missing, happens time to time + string method = line.Substring(line.IndexOf(TestPassed) + TestPassed.Length).Split(',')[0].Split(' ')[0]; + string ticks = line.Substring(line.IndexOf(TestPassed) + TestPassed.Length + method.Length + 2); + long ticksNum = 0; + + try + { + ticksNum = Convert.ToInt64(ticks); + } + catch (Exception) + { + // We won't do anything + } + + // Find the test + var res = results.Where(m => m.TestCase.DisplayName == method); + if (res.Any()) + { + res.First().Duration = TimeSpan.FromTicks(ticksNum); + res.First().Outcome = TestOutcome.Passed; + } + } + else if (line.Contains(TestFailed)) + { + // Format is "Test passed: MethodName, Exception message"; + string method = line.Substring(line.IndexOf(TestFailed) + TestFailed.Length).Split(',')[0].Split(' ')[0]; + string exception = line.Substring(line.IndexOf(TestFailed) + TestPassed.Length + method.Length + 2); + + // Find the test + var res = results.Where(m => m.TestCase.DisplayName == method); + if (res.Any()) + { + res.First().ErrorMessage = exception; + res.First().Outcome = TestOutcome.Failed; + } + } + } + } } } diff --git a/source/TestAdapter/Settings.cs b/source/TestAdapter/Settings.cs index af46540..8c5bace 100644 --- a/source/TestAdapter/Settings.cs +++ b/source/TestAdapter/Settings.cs @@ -10,7 +10,7 @@ namespace nanoFramework.TestPlatform.TestAdapter { /// - /// Settings for the nanoFramweork tests + /// Settings for the nanoFramework tests /// public class Settings { @@ -23,12 +23,12 @@ public class Settings /// /// True to run the tests on real hardware /// - public bool IsRealHarware { get; set; } = false; + public bool IsRealHardware { get; set; } = false; /// /// The serial port number to run the tests on a real hardware /// - public string RealHarwarePort { get; set; } = string.Empty; + public string RealHardwarePort { get; set; } = string.Empty; /// /// Level of logging for test execution. @@ -55,16 +55,16 @@ public static Settings Extract(XmlNode node) } } - var isrealhard = node.SelectSingleNode(nameof(IsRealHarware))?.FirstChild; + var isrealhard = node.SelectSingleNode(nameof(IsRealHardware))?.FirstChild; if (isrealhard != null && isrealhard.NodeType == XmlNodeType.Text) { - settings.IsRealHarware = isrealhard.Value.ToLower() == "true" ? true : false; + settings.IsRealHardware = isrealhard.Value.ToLower() == "true" ? true : false; } - var realhardport = node.SelectSingleNode(nameof(RealHarwarePort))?.FirstChild; + var realhardport = node.SelectSingleNode(nameof(RealHardwarePort))?.FirstChild; if (realhardport != null && realhardport.NodeType == XmlNodeType.Text) { - settings.RealHarwarePort = realhardport.Value; + settings.RealHardwarePort = realhardport.Value; } var loggingLevel = node.SelectSingleNode(nameof(Logging))?.FirstChild; diff --git a/source/TestAdapter/nanoFramework.TestAdapter.csproj b/source/TestAdapter/nanoFramework.TestAdapter.csproj index 50841dd..e21e3ab 100644 --- a/source/TestAdapter/nanoFramework.TestAdapter.csproj +++ b/source/TestAdapter/nanoFramework.TestAdapter.csproj @@ -1,18 +1,20 @@  - net4.6 + net4.8 true key.snk + 1.6.1-preview.223 runtime; build; native; contentfiles; analyzers; buildtransitive all + 3.3.37 runtime; build; native; contentfiles; analyzers; buildtransitive diff --git a/source/package.nuspec b/source/package.nuspec index dae81c8..e9df111 100644 --- a/source/package.nuspec +++ b/source/package.nuspec @@ -22,8 +22,8 @@ - - + + diff --git a/source/runsettings/nano.runsettings b/source/runsettings/nano.runsettings index 62f0a00..fa881e3 100644 --- a/source/runsettings/nano.runsettings +++ b/source/runsettings/nano.runsettings @@ -8,6 +8,7 @@ Framework40 - None + None + False \ No newline at end of file