diff --git a/README.md b/README.md index 4a251ca..563abc6 100644 --- a/README.md +++ b/README.md @@ -86,7 +86,7 @@ This option alters the testcase name attribute. By default, this contains only t #### FailureBodyFormat -When set to default, the body will contain only the exception which is captured by vstest. Verbose will prepend the body with 'Expected X, Actual Y' similar to how it is displayed in the standard test output. 'Expected X, Actual Y' are normally only contained in the failure message. See [here](/docs/gitlab-recommendation.md) for an example of why this might be useful. +When set to default, the body will contain only the exception which is captured by vstest. Verbose will prepend the body with 'Expected X, Actual Y' similar to how it is displayed in the standard test output. 'Expected X, Actual Y' are normally only contained in the failure message. Additionally, Verbose will include standard output from the test in the failure message. See [here](/docs/gitlab-recommendation.md) for an example of why this might be useful. ##### Allowed Values diff --git a/docs/assets/TestResults.xml b/docs/assets/TestResults.xml index 79cb8b2..638adb0 100644 --- a/docs/assets/TestResults.xml +++ b/docs/assets/TestResults.xml @@ -1,102 +1,130 @@  - + - - + + --TearDown - at JUnit.Xml.TestLogger.NetFull.Tests.FailingTearDown.TearDown() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 175 + at JUnit.Xml.TestLogger.NetFull.Tests.FailingTearDown.TearDown() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 182 - - at JUnit.Xml.TestLogger.NetFull.Tests.FailingTestSetup.SetUp() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 160 + + at JUnit.Xml.TestLogger.NetFull.Tests.FailingTestSetup.SetUp() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 167 - + - - at JUnit.Xml.TestLogger.NetFull.Tests.ParametrizedTestCases.TestData(Int32 x, String s) in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 225 + + at JUnit.Xml.TestLogger.NetFull.Tests.ParametrizedTestCases.TestData(Int32 x, String s) in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 232 - at JUnit.Xml.TestLogger.NetFull.Tests.ParametrizedTestCases.TestData(Int32 x, String s) in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 225 + at JUnit.Xml.TestLogger.NetFull.Tests.ParametrizedTestCases.TestData(Int32 x, String s) in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 232 - - at JUnit.Xml.TestLogger.NetFull.Tests.UnitTest1.FailTest11() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 20 + + at JUnit.Xml.TestLogger.NetFull.Tests.UnitTest1.FailTest11() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 27 - + - - + + - + - - at JUnit.Xml.TestLogger.NetFull.Tests.UnitTest2.FailTest22() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 87 + + at JUnit.Xml.TestLogger.NetFull.Tests.UnitTest2.FailTest22() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 94 - - - + + + - + --TearDown at JUnit.Xml.TestLogger.Tests2.FailingTearDown.TearDown() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest2.cs:line 137 - + at JUnit.Xml.TestLogger.Tests2.FailingTestSetup.SetUp() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest2.cs:line 122 - + - + at JUnit.Xml.TestLogger.Tests2.ParametrizedTestCases.TestData(Int32 x, String s) in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest2.cs:line 187 - + at JUnit.Xml.TestLogger.Tests2.ParametrizedTestCases.TestData(Int32 x, String s) in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest2.cs:line 187 - + - - + + at JUnit.Xml.TestLogger.Tests2.UnitTest1.FailTest11() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest2.cs:line 20 - - + + - + at JUnit.Xml.TestLogger.Tests2.UnitTest2.FailTest22() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest2.cs:line 49 - - - + + + - Junit Logger does not log standard output - Junit Logger does not log error output + NUnit Adapter 3.10.0.21: Test execution started +Running all tests in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\bin\Debug\netcoreapp2.0\JUnit.Xml.TestLogger.NetCore.Tests.dll +NUnit3TestExecutor converted 52 of 52 NUnit test cases + +JUnit.Xml.TestLogger.NetFull.Tests.UnitTest1.FailTest11 + {EEEE1DA6-6296-4486-BDA5-A50A19672F0F} + {C33FF4B5-75E1-4882-B968-DF9608BFE7C2} + +JUnit.Xml.TestLogger.NetFull.Tests.UnitTest1.PassTest11 + {2010CAE3-7BC0-4841-A5A3-7D5F947BB9FB} + {998AC9EC-7429-42CD-AD55-72037E7AF3D8} +NUnit Adapter 3.10.0.21: Test execution complete + + SetUp failed for test fixture JUnit.Xml.TestLogger.NetFull.Tests.FailingOneTimeSetUp +System.InvalidOperationException : Operation is not valid due to the current state of the object. + at JUnit.Xml.TestLogger.NetFull.Tests.FailingOneTimeSetUp.OneTimeSetUp() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 152 +TearDown failed for test fixture JUnit.Xml.TestLogger.NetFull.Tests.FailingOneTimeTearDown +TearDown : System.InvalidOperationException : Operation is not valid due to the current state of the object. +--TearDown + at JUnit.Xml.TestLogger.NetFull.Tests.FailingOneTimeTearDown.OneTimeTearDown() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest1.cs:line 197 +{D46DFA10-EEDD-49E5-804D-FE43051331A7} +{33F5FD22-6F40-499D-98E4-481D87FAEAA1} +SetUp failed for test fixture JUnit.Xml.TestLogger.Tests2.FailingOneTimeSetUp +System.InvalidOperationException : Operation is not valid due to the current state of the object. + at JUnit.Xml.TestLogger.Tests2.FailingOneTimeSetUp.OneTimeSetUp() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest2.cs:line 107 +TearDown failed for test fixture JUnit.Xml.TestLogger.Tests2.FailingOneTimeTearDown +TearDown : System.InvalidOperationException : Operation is not valid due to the current state of the object. +--TearDown + at JUnit.Xml.TestLogger.Tests2.FailingOneTimeTearDown.OneTimeTearDown() in C:\Users\mjc82\Documents\GitHub\junit.testlogger\test\assets\JUnit.Xml.TestLogger.NetCore.Tests\UnitTest2.cs:line 152 + \ No newline at end of file diff --git a/docs/assets/gitlab-test-popup-with-verbose-failure.png b/docs/assets/gitlab-test-popup-with-verbose-failure.png index eb9d722..096e34e 100644 Binary files a/docs/assets/gitlab-test-popup-with-verbose-failure.png and b/docs/assets/gitlab-test-popup-with-verbose-failure.png differ diff --git a/docs/gitlab-recommendation.md b/docs/gitlab-recommendation.md index f3224cb..80bbdd7 100644 --- a/docs/gitlab-recommendation.md +++ b/docs/gitlab-recommendation.md @@ -42,4 +42,4 @@ Test: ## Notes -Screen shots and behavior are current as of GitLab Community Edition 11.11.8. +Screen shots and behavior are current as of GitLab Enterprise Edition 13.0.0-pre. diff --git a/src/JUnit.Xml.TestLogger/JUnitXmlTestLogger.cs b/src/JUnit.Xml.TestLogger/JUnitXmlTestLogger.cs index e8158c7..e429eeb 100644 --- a/src/JUnit.Xml.TestLogger/JUnitXmlTestLogger.cs +++ b/src/JUnit.Xml.TestLogger/JUnitXmlTestLogger.cs @@ -9,7 +9,6 @@ namespace Microsoft.VisualStudio.TestPlatform.Extension.JUnit.Xml.TestLogger using System.IO; using System.Linq; using System.Text; - using System.Text.RegularExpressions; using System.Xml; using System.Xml.Linq; using Microsoft.VisualStudio.TestPlatform.ObjectModel; @@ -48,6 +47,16 @@ public class JUnitXmlTestLogger : ITestLoggerWithParameters private readonly object resultsGuard = new object(); private string outputFilePath; + /// + /// Recieves information messages, along with StdOut from test methods. + /// + private StringBuilder stdOut = new StringBuilder(); + + /// + /// Recieves both warning and error messages. + /// + private StringBuilder stdErr = new StringBuilder(); + private List results; private DateTime utcStartTime; @@ -130,7 +139,9 @@ public static IEnumerable GroupTestSuites(IEnumerable suit /// Initialized called by dotnet test. /// /// Test logger event. - /// A single string is assumed to be the test result directory argument. + /// + /// A single string is assumed to be the test result directory argument. + /// public void Initialize(TestLoggerEvents events, string testResultsDirPath) { if (events == null) @@ -151,7 +162,9 @@ public void Initialize(TestLoggerEvents events, string testResultsDirPath) /// Initialized called by dotnet test. /// /// Test logger event. - /// Dictionary of key value pairs provided by the user, semicolon delimited (i.e. 'key1=val1;key2=val2'). + /// + /// Dictionary of key value pairs provided by the user, semicolon delimited (i.e. 'key1=val1;key2=val2'). + /// public void Initialize(TestLoggerEvents events, Dictionary parameters) { if (events == null) @@ -241,10 +254,19 @@ public void Initialize(TestLoggerEvents events, Dictionary param } /// - /// Called when a test message is received. + /// Called when a test message is received. These messages are coming from the test + /// framework, and don't contain standard output produced by test code. /// internal void TestMessageHandler(object sender, TestRunMessageEventArgs e) { + if (e.Level == TestMessageLevel.Informational) + { + this.stdOut.AppendLine(e.Message); + } + else + { + this.stdErr.AppendLine(e.Message); + } } /// @@ -277,8 +299,14 @@ internal void TestResultHandler(object sender, TestResultEventArgs e) { TestResult result = e.Result; - var parsedName = TestCaseNameParser.Parse(result.TestCase.FullyQualifiedName); + if (e.Result.Messages.Count > 0) + { + this.stdOut.AppendLine(); + this.stdOut.AppendLine(result.TestCase.FullyQualifiedName); + this.stdOut.AppendLine(Indent(result.Messages)); + } + var parsedName = TestCaseNameParser.Parse(result.TestCase.FullyQualifiedName); lock (this.resultsGuard) { this.results.Add(new TestResultInfo( @@ -395,6 +423,27 @@ private static TestSuite AggregateTestSuites( }; } + /// + /// Produces a consistently indented output, taking into account that incoming messages + /// often have new lines within a message. + /// + private static string Indent(IReadOnlyCollection messages) + { + var indent = " "; + + // Splitting on any line feed or carrage return because a message may include new lines + // that are inconsistent with the Environment.NewLine. We then remove all blank lines so + // it shouldn't cause an issue that this generates extra line breaks. + return + indent + + string.Join( + $"{Environment.NewLine}{indent}", + messages.SelectMany(m => + m.Text.Split(new string[] { "\r", "\n" }, StringSplitOptions.None) + .Where(x => !string.IsNullOrWhiteSpace(x)) + .Select(x => x.Trim()))); + } + private void InitializeImpl(TestLoggerEvents events, string outputPath) { events.TestRunMessage += this.TestMessageHandler; @@ -428,13 +477,14 @@ private XElement CreateTestSuiteElement(List results) var testCaseElements = results.Select(a => this.CreateTestCaseElement(a)); // Adding required properties, system-out, and system-err elements in the correct - // positions as required by the xsd. + // positions as required by the xsd. In system-out collapse consequtive newlines to a + // single newline. var element = new XElement( "testsuite", new XElement("properties"), testCaseElements, - new XElement("system-out", "Junit Logger does not log standard output"), - new XElement("system-err", "Junit Logger does not log error output")); + new XElement("system-out", this.stdOut.ToString()), + new XElement("system-err", this.stdErr.ToString())); element.SetAttributeValue("name", Path.GetFileName(results.First().AssemblyPath)); @@ -472,9 +522,8 @@ private XElement CreateTestCaseElement(TestResultInfo result) testcaseElement.SetAttributeValue("name", result.Name); } - // Ensure time value is never zero because gitlab treats 0 like its null. - // 0.1 micro seconds should be low enough it won't interfere with anyone - // monitoring test duration. + // Ensure time value is never zero because gitlab treats 0 like its null. 0.1 micro + // seconds should be low enough it won't interfere with anyone monitoring test duration. testcaseElement.SetAttributeValue( "time", Math.Max(0.0000001f, result.Duration.TotalSeconds).ToString("0.0000000")); @@ -487,12 +536,20 @@ private XElement CreateTestCaseElement(TestResultInfo result) { failureBodySB.AppendLine(result.ErrorMessage); - // Stack trace included to mimic the normal test output + // Stack trace label included to mimic the normal test output failureBodySB.AppendLine("Stack Trace:"); } failureBodySB.AppendLine(result.ErrorStackTrace); + if (this.FailureBodyFormatOption == FailureBodyFormat.Verbose && + result.Messages.Count > 0) + { + failureBodySB.AppendLine("Standard Output:"); + + failureBodySB.AppendLine(Indent(result.Messages)); + } + var failureElement = new XElement("failure", failureBodySB.ToString().Trim()); failureElement.SetAttributeValue("type", "failure"); // TODO are there failure types? diff --git a/test/JUnit.Xml.TestLogger.AcceptanceTests/JUnitTestLoggerAcceptanceTests.cs b/test/JUnit.Xml.TestLogger.AcceptanceTests/JUnitTestLoggerAcceptanceTests.cs index 58df0f8..4d7af25 100644 --- a/test/JUnit.Xml.TestLogger.AcceptanceTests/JUnitTestLoggerAcceptanceTests.cs +++ b/test/JUnit.Xml.TestLogger.AcceptanceTests/JUnitTestLoggerAcceptanceTests.cs @@ -95,6 +95,26 @@ public void TestResultFileShouldContainTestCases() Assert.AreEqual(6, skips.Count()); } + [TestMethod] + public void TestResultFileShouldContainStandardOut() + { + var node = this.resultsXml.XPathSelectElement("/testsuites/testsuite/system-out"); + + Assert.IsTrue(node.Value.Contains("{2010CAE3-7BC0-4841-A5A3-7D5F947BB9FB}")); + Assert.IsTrue(node.Value.Contains("{998AC9EC-7429-42CD-AD55-72037E7AF3D8}")); + Assert.IsTrue(node.Value.Contains("{EEEE1DA6-6296-4486-BDA5-A50A19672F0F}")); + Assert.IsTrue(node.Value.Contains("{C33FF4B5-75E1-4882-B968-DF9608BFE7C2}")); + } + + [TestMethod] + public void TestResultFileShouldContainErrordOut() + { + var node = this.resultsXml.XPathSelectElement("/testsuites/testsuite/system-err"); + + Assert.IsTrue(node.Value.Contains("{D46DFA10-EEDD-49E5-804D-FE43051331A7}")); + Assert.IsTrue(node.Value.Contains("{33F5FD22-6F40-499D-98E4-481D87FAEAA1}")); + } + [TestMethod] public void LoggedXmlValidatesAgainstXsdSchema() { diff --git a/test/JUnit.Xml.TestLogger.AcceptanceTests/JUnitTestLoggerFormatOptionsAcceptanceTests.cs b/test/JUnit.Xml.TestLogger.AcceptanceTests/JUnitTestLoggerFormatOptionsAcceptanceTests.cs index bdc9150..afb041e 100644 --- a/test/JUnit.Xml.TestLogger.AcceptanceTests/JUnitTestLoggerFormatOptionsAcceptanceTests.cs +++ b/test/JUnit.Xml.TestLogger.AcceptanceTests/JUnitTestLoggerFormatOptionsAcceptanceTests.cs @@ -15,8 +15,9 @@ namespace JUnit.Xml.TestLogger.AcceptanceTests /// Acceptance tests evaluate the most recent output of the build.ps1 script, NOT the most /// recent build performed by visual studio or dotnet.build /// - /// These acceptance tests look at the specific places output is expected to change because of the format option specified. - /// Accordingly, these tests cannot protect against other changes occurring due to the formatting option. + /// These acceptance tests look at the specific places output is expected to change because of + /// the format option specified. Accordingly, these tests cannot protect against other changes + /// occurring due to the formatting option. /// [TestClass] public class JUnitTestLoggerFormatOptionsAcceptanceTests @@ -35,7 +36,8 @@ public void FailureBodyFormat_Default_ShouldntStartWithMessage() foreach (var failure in failures) { - // Strip new line and carrige return. These may be inconsistent depending on environment settings + // Strip new line and carrige return. These may be inconsistent depending on + // environment settings var message = failure.Attribute("message").Value.Replace("\r", string.Empty).Replace("\n", string.Empty); var body = failure.Value.Replace("\r", string.Empty).Replace("\n", string.Empty); @@ -43,6 +45,22 @@ public void FailureBodyFormat_Default_ShouldntStartWithMessage() } } + [TestMethod] + public void FailureBodyFormat_Verbose_ShouldNotContainConsoleOut() + { + DotnetTestFixture.Execute("failure-verbose-test-results.xml;FailureBodyFormat=Default"); + string resultsFile = Path.Combine(DotnetTestFixture.RootDirectory, "failure-verbose-test-results.xml"); + XDocument resultsXml = XDocument.Load(resultsFile); + + var failures = resultsXml.XPathSelectElements("/testsuites/testsuite") + .Descendants() + .Where(x => x.Name.LocalName == "failure") + .ToList(); + + Assert.AreEqual(0, failures.Count(x => x.Value.Contains("{EEEE1DA6-6296-4486-BDA5-A50A19672F0F}"))); + Assert.AreEqual(0, failures.Count(x => x.Value.Contains("{C33FF4B5-75E1-4882-B968-DF9608BFE7C2}"))); + } + [TestMethod] public void FailureBodyFormat_Verbose_ShouldStartWithMessage() { @@ -57,7 +75,8 @@ public void FailureBodyFormat_Verbose_ShouldStartWithMessage() foreach (var failure in failures) { - // Strip new line and carrige return. These may be inconsistent depending on environment settings + // Strip new line and carrige return. These may be inconsistent depending on + // environment settings var message = failure.Attribute("message").Value.Replace("\r", string.Empty).Replace("\n", string.Empty); var body = failure.Value.Replace("\r", string.Empty).Replace("\n", string.Empty); @@ -65,6 +84,22 @@ public void FailureBodyFormat_Verbose_ShouldStartWithMessage() } } + [TestMethod] + public void FailureBodyFormat_Verbose_ShouldContainConsoleOut() + { + DotnetTestFixture.Execute("failure-verbose-test-results.xml;FailureBodyFormat=Verbose"); + string resultsFile = Path.Combine(DotnetTestFixture.RootDirectory, "failure-verbose-test-results.xml"); + XDocument resultsXml = XDocument.Load(resultsFile); + + var failures = resultsXml.XPathSelectElements("/testsuites/testsuite") + .Descendants() + .Where(x => x.Name.LocalName == "failure") + .ToList(); + + Assert.AreEqual(1, failures.Count(x => x.Value.Contains("{EEEE1DA6-6296-4486-BDA5-A50A19672F0F}"))); + Assert.AreEqual(1, failures.Count(x => x.Value.Contains("{C33FF4B5-75E1-4882-B968-DF9608BFE7C2}"))); + } + [TestMethod] public void MethodFormat_Default_ShouldBeOnlyTheMethod() { @@ -102,8 +137,8 @@ public void MethodFormat_Class_ShouldIncludeClass() { var parsedName = TestCaseNameParser.Parse(testcase.Attribute("name").Value); - // If the name is parsable into two pieces, then we have a two piece name - // and consider that to be a passing result. + // If the name is parsable into two pieces, then we have a two piece name and + // consider that to be a passing result. Assert.AreNotEqual(parsedName.TypeName, TestCaseNameParser.TestCaseParserUnknownType); } } diff --git a/test/assets/JUnit.Xml.TestLogger.NetCore.Tests/UnitTest1.cs b/test/assets/JUnit.Xml.TestLogger.NetCore.Tests/UnitTest1.cs index 2e038e2..c4813c4 100644 --- a/test/assets/JUnit.Xml.TestLogger.NetCore.Tests/UnitTest1.cs +++ b/test/assets/JUnit.Xml.TestLogger.NetCore.Tests/UnitTest1.cs @@ -11,12 +11,19 @@ public class UnitTest1 [Description("Passing test description")] public async Task PassTest11() { + Console.WriteLine("{2010CAE3-7BC0-4841-A5A3-7D5F947BB9FB}"); + Console.WriteLine("{998AC9EC-7429-42CD-AD55-72037E7AF3D8}"); await Task.Delay(TimeSpan.FromMilliseconds(400)); } [Test] public void FailTest11() { + Console.WriteLine("{EEEE1DA6-6296-4486-BDA5-A50A19672F0F}"); + Console.WriteLine("{C33FF4B5-75E1-4882-B968-DF9608BFE7C2}"); + Console.Error.WriteLine("{D46DFA10-EEDD-49E5-804D-FE43051331A7}"); + Console.Error.WriteLine("{33F5FD22-6F40-499D-98E4-481D87FAEAA1}"); + Assert.False(true); }