Skip to content

Commit 1362bca

Browse files
bradwilsonbradwilson
committed
Add a bunch of diagnostic messages, plus fix an issue with TestStarting that should've been TestCaseStarting
1 parent a02eeff commit 1362bca

File tree

10 files changed

+231
-133
lines changed

10 files changed

+231
-133
lines changed

‎common/WinRTFile.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,7 @@ internal static class File
66
{
77
public static bool Exists(string path)
88
{
9-
if (String.IsNullOrWhiteSpace(path))
9+
if (string.IsNullOrWhiteSpace(path))
1010
return false;
1111

1212
var folder = Package.Current.InstalledLocation;

‎xunit.runner.visualstudio.testadapter/Utility/AssemblyExtensions.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,7 @@ public static string GetLocalCodeBase(this Assembly assembly)
1111
return null;
1212

1313
if (!codeBase.StartsWith("file:///"))
14-
throw new ArgumentException(String.Format("Code base {0} in wrong format; must start with file:///", codeBase), "assembly");
14+
throw new ArgumentException(string.Format("Code base {0} in wrong format; must start with file:///", codeBase), "assembly");
1515

1616
codeBase = codeBase.Substring(8);
1717
if (Path.DirectorySeparatorChar == '/')

‎xunit.runner.visualstudio.testadapter/Utility/LoggerHelper.cs‎

Lines changed: 53 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,53 @@
1+
using System.Diagnostics;
2+
using System.IO;
3+
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Logging;
4+
using Xunit.Abstractions;
5+
6+
public class LoggerHelper
7+
{
8+
public LoggerHelper(IMessageLogger logger, Stopwatch stopwatch)
9+
{
10+
InnerLogger = logger;
11+
Stopwatch = stopwatch;
12+
}
13+
14+
public IMessageLogger InnerLogger { get; private set; }
15+
16+
public Stopwatch Stopwatch { get; private set; }
17+
18+
public void Log(string format, params object[] args)
19+
{
20+
SendMessage(TestMessageLevel.Informational, null, string.Format(format, args));
21+
}
22+
23+
public void Log(ITestCase testCase, string format, params object[] args)
24+
{
25+
SendMessage(TestMessageLevel.Informational, testCase.TestMethod.TestClass.TestCollection.TestAssembly.Assembly.AssemblyPath, string.Format(format, args));
26+
}
27+
28+
public void LogError(string format, params object[] args)
29+
{
30+
SendMessage(TestMessageLevel.Error, null, string.Format(format, args));
31+
}
32+
33+
public void LogError(ITestCase testCase, string format, params object[] args)
34+
{
35+
SendMessage(TestMessageLevel.Error, testCase.TestMethod.TestClass.TestCollection.TestAssembly.Assembly.AssemblyPath, string.Format(format, args));
36+
}
37+
38+
public void LogWarning(string format, params object[] args)
39+
{
40+
SendMessage(TestMessageLevel.Warning, null, string.Format(format, args));
41+
}
42+
43+
public void LogWarning(ITestCase testCase, string format, params object[] args)
44+
{
45+
SendMessage(TestMessageLevel.Warning, testCase.TestMethod.TestClass.TestCollection.TestAssembly.Assembly.AssemblyPath, string.Format(format, args));
46+
}
47+
48+
void SendMessage(TestMessageLevel level, string assemblyName, string message)
49+
{
50+
var assemblyText = assemblyName == null ? "" : string.Format("{0}: ", Path.GetFileNameWithoutExtension(assemblyName));
51+
InnerLogger.SendMessage(level, string.Format("[xUnit.net {0}] {1}{2}", Stopwatch.Elapsed, assemblyText, message));
52+
}
53+
}

‎xunit.runner.visualstudio.testadapter/Visitors/DiagnosticMessageVisitor.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,7 @@ public DiagnosticMessageVisitor(IMessageLogger logger, string assemblyDisplayNam
2323
protected override bool Visit(IDiagnosticMessage diagnosticMessage)
2424
{
2525
if (showDiagnostics)
26-
logger.SendMessage(TestMessageLevel.Warning, String.Format("[xUnit.net {0}] {1}: {2}", stopwatch.Elapsed, assemblyDisplayName, diagnosticMessage.Message));
26+
logger.SendMessage(TestMessageLevel.Warning, string.Format("[xUnit.net {0}] {1}: {2}", stopwatch.Elapsed, assemblyDisplayName, diagnosticMessage.Message));
2727

2828
return base.Visit(diagnosticMessage);
2929
}

‎xunit.runner.visualstudio.testadapter/Visitors/VsDiscoveryVisitor.cs‎

Lines changed: 18 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1,18 +1,16 @@
11
using System;
22
using System.Collections.Generic;
33
using System.Linq.Expressions;
4-
using System.Reflection;
54
using System.Text;
65
using Microsoft.VisualStudio.TestPlatform.ObjectModel;
76
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Adapter;
8-
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Logging;
97
using Xunit.Abstractions;
108

119
#if WINDOWS_PHONE_APP
12-
using Xunit.Serialization;
10+
using System.Reflection;
11+
using System.Runtime.InteropServices.WindowsRuntime;
1312
using Windows.Security.Cryptography;
1413
using Windows.Security.Cryptography.Core;
15-
using System.Runtime.InteropServices.WindowsRuntime;
1614
#else
1715
using System.Security.Cryptography;
1816
#endif
@@ -29,14 +27,14 @@ public class VsDiscoveryVisitor : TestMessageVisitor<IDiscoveryCompleteMessage>,
2927
readonly ITestFrameworkDiscoveryOptions discoveryOptions;
3028
readonly ITestCaseDiscoverySink discoverySink;
3129
readonly List<ITestCase> lastTestClassTestCases = new List<ITestCase>();
32-
readonly IMessageLogger logger;
30+
readonly LoggerHelper logger;
3331
readonly string source;
3432

3533
string lastTestClass;
3634

3735
public VsDiscoveryVisitor(string source,
3836
ITestFrameworkDiscoverer discoverer,
39-
IMessageLogger logger,
37+
LoggerHelper logger,
4038
ITestCaseDiscoverySink discoverySink,
4139
ITestFrameworkDiscoveryOptions discoveryOptions,
4240
Func<bool> cancelThunk)
@@ -51,13 +49,13 @@ public VsDiscoveryVisitor(string source,
5149

5250
public int TotalTests { get; private set; }
5351

54-
public static TestCase CreateVsTestCase(string source, ITestFrameworkDiscoverer discoverer, ITestCase xunitTestCase, bool forceUniqueNames, IMessageLogger logger, bool logDiscovery)
52+
public static TestCase CreateVsTestCase(string source, ITestFrameworkDiscoverer discoverer, ITestCase xunitTestCase, bool forceUniqueNames, LoggerHelper logger)
5553
{
5654
try
5755
{
5856
var serializedTestCase = discoverer.Serialize(xunitTestCase);
59-
var fqTestMethodName = String.Format("{0}.{1}", xunitTestCase.TestMethod.TestClass.Class.Name, xunitTestCase.TestMethod.Method.Name);
60-
var uniqueName = forceUniqueNames ? String.Format("{0} ({1})", fqTestMethodName, xunitTestCase.UniqueID) : fqTestMethodName;
57+
var fqTestMethodName = string.Format("{0}.{1}", xunitTestCase.TestMethod.TestClass.Class.Name, xunitTestCase.TestMethod.Method.Name);
58+
var uniqueName = forceUniqueNames ? string.Format("{0} ({1})", fqTestMethodName, xunitTestCase.UniqueID) : fqTestMethodName;
6159

6260
var result = new TestCase(uniqueName, uri, source) { DisplayName = Escape(xunitTestCase.DisplayName) };
6361
result.SetPropertyValue(VsTestRunner.SerializedTestCaseProperty, serializedTestCase);
@@ -75,15 +73,15 @@ public static TestCase CreateVsTestCase(string source, ITestFrameworkDiscoverer
7573
}
7674
catch (Exception ex)
7775
{
78-
logger.SendMessage(TestMessageLevel.Error, String.Format("Error creating Visual Studio test case for {0}: {1}", xunitTestCase.DisplayName, ex));
76+
logger.LogError(xunitTestCase, "Error creating Visual Studio test case for {0}: {1}", xunitTestCase.DisplayName, ex);
7977
return null;
8078
}
8179
}
8280

8381
static string Escape(string value)
8482
{
8583
if (value == null)
86-
return String.Empty;
84+
return string.Empty;
8785

8886
return value.Replace("\r", "\\r").Replace("\n", "\\n").Replace("\t", "\\t");
8987
}
@@ -134,7 +132,7 @@ static Action<TestCase, string, string> GetAddTraitThunk()
134132
protected override bool Visit(ITestCaseDiscoveryMessage discovery)
135133
{
136134
var testCase = discovery.TestCase;
137-
var testClass = String.Format("{0}.{1}", testCase.TestMethod.TestClass.Class.Name, testCase.TestMethod.Method.Name);
135+
var testClass = string.Format("{0}.{1}", testCase.TestMethod.TestClass.Class.Name, testCase.TestMethod.Method.Name);
138136
if (lastTestClass != testClass)
139137
SendExistingTestCases();
140138

@@ -158,9 +156,16 @@ private void SendExistingTestCases()
158156

159157
foreach (var testCase in lastTestClassTestCases)
160158
{
161-
var vsTestCase = CreateVsTestCase(source, discoverer, testCase, forceUniqueNames, logger, discoveryOptions.GetDiagnosticMessagesOrDefault());
159+
var vsTestCase = CreateVsTestCase(source, discoverer, testCase, forceUniqueNames, logger);
162160
if (vsTestCase != null)
161+
{
162+
if (discoveryOptions.GetDiagnosticMessagesOrDefault())
163+
logger.Log(testCase, "Discovered test case '{0}' (ID = '{1}', VS FQN = '{2}')", testCase.DisplayName, testCase.UniqueID, vsTestCase.FullyQualifiedName);
164+
163165
discoverySink.SendTestCase(vsTestCase);
166+
}
167+
else
168+
logger.LogWarning(testCase, "Could not create VS test case for '{0}' (ID = '{1}', VS FQN = '{2}')", testCase.DisplayName, testCase.UniqueID, vsTestCase.FullyQualifiedName);
164169
}
165170

166171
lastTestClassTestCases.Clear();

‎xunit.runner.visualstudio.testadapter/Visitors/VsExecutionVisitor.cs‎

Lines changed: 57 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,6 @@
33
using System.Linq;
44
using Microsoft.VisualStudio.TestPlatform.ObjectModel;
55
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Adapter;
6-
using Microsoft.VisualStudio.TestPlatform.ObjectModel.Logging;
76
using Xunit.Abstractions;
87
using VsTestResult = Microsoft.VisualStudio.TestPlatform.ObjectModel.TestResult;
98
using VsTestResultMessage = Microsoft.VisualStudio.TestPlatform.ObjectModel.TestResultMessage;
@@ -14,15 +13,18 @@ public class VsExecutionVisitor : TestMessageVisitor<ITestAssemblyFinished>
1413
{
1514
readonly Func<bool> cancelledThunk;
1615
readonly ITestFrameworkExecutionOptions executionOptions;
16+
readonly LoggerHelper logger;
1717
readonly ITestExecutionRecorder recorder;
1818
readonly Dictionary<ITestCase, TestCase> testCases;
1919

2020
public VsExecutionVisitor(ITestExecutionRecorder recorder,
21+
LoggerHelper logger,
2122
Dictionary<ITestCase, TestCase> testCases,
2223
ITestFrameworkExecutionOptions executionOptions,
2324
Func<bool> cancelledThunk)
2425
{
2526
this.recorder = recorder;
27+
this.logger = logger;
2628
this.testCases = testCases;
2729
this.executionOptions = executionOptions;
2830
this.cancelledThunk = cancelledThunk;
@@ -38,13 +40,28 @@ TestCase FindTestCase(ITestCase testCase)
3840
if (result != null)
3941
return result;
4042

41-
recorder.SendMessage(TestMessageLevel.Error, String.Format("Result reported for unknown test case: {0}", testCase.DisplayName));
43+
logger.LogError(testCase, "Result reported for unknown test case: {0}", testCase.DisplayName);
4244
return null;
4345
}
4446

47+
private void TryAndReport(string actionDescription, ITestCase testCase, Action action)
48+
{
49+
try
50+
{
51+
if (executionOptions.GetDiagnosticMessagesOrDefault())
52+
logger.Log(testCase, "Performing {0} for test case {1}", actionDescription, testCase.DisplayName);
53+
54+
action();
55+
}
56+
catch (Exception ex)
57+
{
58+
logger.LogError(testCase, "Error occured while {0} for test case {1}: {2}", actionDescription, testCase.DisplayName, ex);
59+
}
60+
}
61+
4562
protected override bool Visit(IErrorMessage error)
4663
{
47-
recorder.SendMessage(TestMessageLevel.Error, String.Format("Catastrophic failure: {0}", ExceptionUtility.CombineMessages(error)));
64+
logger.LogError("Catastrophic failure: {0}", ExceptionUtility.CombineMessages(error));
4865

4966
return !cancelledThunk();
5067
}
@@ -57,9 +74,10 @@ protected override bool Visit(ITestFailed testFailed)
5774
result.ErrorMessage = ExceptionUtility.CombineMessages(testFailed);
5875
result.ErrorStackTrace = ExceptionUtility.CombineStackTraces(testFailed);
5976

60-
recorder.RecordEnd(result.TestCase, result.Outcome);
61-
recorder.RecordResult(result);
77+
TryAndReport("RecordResult (Fail)", testFailed.TestCase, () => recorder.RecordResult(result));
6278
}
79+
else
80+
logger.LogWarning(testFailed.TestCase, "(Fail) Could not find VS test case for {0} (ID = {1})", testFailed.TestCase.DisplayName, testFailed.TestCase.UniqueID);
6381

6482
return !cancelledThunk();
6583
}
@@ -68,10 +86,9 @@ protected override bool Visit(ITestPassed testPassed)
6886
{
6987
var result = MakeVsTestResult(TestOutcome.Passed, testPassed);
7088
if (result != null)
71-
{
72-
recorder.RecordEnd(result.TestCase, result.Outcome);
73-
recorder.RecordResult(result);
74-
}
89+
TryAndReport("RecordResult (Pass)", testPassed.TestCase, () => recorder.RecordResult(result));
90+
else
91+
logger.LogWarning(testPassed.TestCase, "(Pass) Could not find VS test case for {0} (ID = {1})", testPassed.TestCase.DisplayName, testPassed.TestCase.UniqueID);
7592

7693
return !cancelledThunk();
7794
}
@@ -80,51 +97,63 @@ protected override bool Visit(ITestSkipped testSkipped)
8097
{
8198
var result = MakeVsTestResult(TestOutcome.Skipped, testSkipped);
8299
if (result != null)
83-
{
84-
recorder.RecordEnd(result.TestCase, result.Outcome);
85-
recorder.RecordResult(result);
86-
}
100+
TryAndReport("RecordResult (Skip)", testSkipped.TestCase, () => recorder.RecordResult(result));
101+
else
102+
logger.LogWarning(testSkipped.TestCase, "(Skip) Could not find VS test case for {0} (ID = {1})", testSkipped.TestCase.DisplayName, testSkipped.TestCase.UniqueID);
103+
104+
return !cancelledThunk();
105+
}
106+
107+
protected override bool Visit(ITestCaseStarting testCaseStarting)
108+
{
109+
var vsTestCase = FindTestCase(testCaseStarting.TestCase);
110+
if (vsTestCase != null)
111+
TryAndReport("RecordStart", testCaseStarting.TestCase, () => recorder.RecordStart(vsTestCase));
112+
else
113+
logger.LogWarning(testCaseStarting.TestCase, "(Starting) Could not find VS test case for {0} (ID = {1})", testCaseStarting.TestCase.DisplayName, testCaseStarting.TestCase.UniqueID);
87114

88115
return !cancelledThunk();
89116
}
90117

91-
protected override bool Visit(ITestStarting testStarting)
118+
protected override bool Visit(ITestCaseFinished testCaseFinished)
92119
{
93-
var vsTestCase = FindTestCase(testStarting.TestCase);
120+
var vsTestCase = FindTestCase(testCaseFinished.TestCase);
94121
if (vsTestCase != null)
95-
recorder.RecordStart(vsTestCase);
122+
TryAndReport("RecordEnd", testCaseFinished.TestCase, () => recorder.RecordEnd(vsTestCase, TestOutcome.Passed)); // TODO: Don't have an aggregate outcome here!
123+
else
124+
logger.LogWarning(testCaseFinished.TestCase, "(Finished) Could not find VS test case for {0} (ID = {1})", testCaseFinished.TestCase.DisplayName, testCaseFinished.TestCase.UniqueID);
96125

97126
return !cancelledThunk();
98127
}
99128

100129
protected override bool Visit(ITestAssemblyCleanupFailure cleanupFailure)
101130
{
102-
return WriteError(String.Format("Test Assembly Cleanup Failure ({0})", cleanupFailure.TestAssembly.Assembly.AssemblyPath), cleanupFailure, cleanupFailure.TestCases);
131+
return WriteError(string.Format("Test Assembly Cleanup Failure ({0})", cleanupFailure.TestAssembly.Assembly.AssemblyPath), cleanupFailure, cleanupFailure.TestCases);
103132
}
104133

105134
protected override bool Visit(ITestCaseCleanupFailure cleanupFailure)
106135
{
107-
return WriteError(String.Format("Test Case Cleanup Failure ({0})", cleanupFailure.TestCase.DisplayName), cleanupFailure, cleanupFailure.TestCases);
136+
return WriteError(string.Format("Test Case Cleanup Failure ({0})", cleanupFailure.TestCase.DisplayName), cleanupFailure, cleanupFailure.TestCases);
108137
}
109138

110139
protected override bool Visit(ITestClassCleanupFailure cleanupFailure)
111140
{
112-
return WriteError(String.Format("Test Class Cleanup Failure ({0})", cleanupFailure.TestClass.Class.Name), cleanupFailure, cleanupFailure.TestCases);
141+
return WriteError(string.Format("Test Class Cleanup Failure ({0})", cleanupFailure.TestClass.Class.Name), cleanupFailure, cleanupFailure.TestCases);
113142
}
114143

115144
protected override bool Visit(ITestCollectionCleanupFailure cleanupFailure)
116145
{
117-
return WriteError(String.Format("Test Collection Cleanup Failure ({0})", cleanupFailure.TestCollection.DisplayName), cleanupFailure, cleanupFailure.TestCases);
146+
return WriteError(string.Format("Test Collection Cleanup Failure ({0})", cleanupFailure.TestCollection.DisplayName), cleanupFailure, cleanupFailure.TestCases);
118147
}
119148

120149
protected override bool Visit(ITestCleanupFailure cleanupFailure)
121150
{
122-
return WriteError(String.Format("Test Cleanup Failure ({0})", cleanupFailure.Test.DisplayName), cleanupFailure, cleanupFailure.TestCases);
151+
return WriteError(string.Format("Test Cleanup Failure ({0})", cleanupFailure.Test.DisplayName), cleanupFailure, cleanupFailure.TestCases);
123152
}
124153

125154
protected override bool Visit(ITestMethodCleanupFailure cleanupFailure)
126155
{
127-
return WriteError(String.Format("Test Method Cleanup Failure ({0})", cleanupFailure.TestMethod.Method.Name), cleanupFailure, cleanupFailure.TestCases);
156+
return WriteError(string.Format("Test Method Cleanup Failure ({0})", cleanupFailure.TestMethod.Method.Name), cleanupFailure, cleanupFailure.TestCases);
128157
}
129158

130159
protected bool WriteError(string failureName, IFailureInformation failureInfo, IEnumerable<ITestCase> testCases)
@@ -134,12 +163,14 @@ protected bool WriteError(string failureName, IFailureInformation failureInfo, I
134163
var result = MakeVsTestResult(TestOutcome.Failed, testCase, testCase.DisplayName);
135164
if (result != null)
136165
{
137-
result.ErrorMessage = String.Format("[{0}]: {1}", failureName, ExceptionUtility.CombineMessages(failureInfo));
166+
result.ErrorMessage = string.Format("[{0}]: {1}", failureName, ExceptionUtility.CombineMessages(failureInfo));
138167
result.ErrorStackTrace = ExceptionUtility.CombineStackTraces(failureInfo);
139168

140-
recorder.RecordEnd(result.TestCase, result.Outcome);
141-
recorder.RecordResult(result);
169+
TryAndReport("RecordEnd (Failure)", testCase, () => recorder.RecordEnd(result.TestCase, result.Outcome));
170+
TryAndReport("RecordResult (Failure)", testCase, () => recorder.RecordResult(result));
142171
}
172+
else
173+
logger.LogWarning(testCase, "(Failure) Could not find VS test case for {0} (ID = {1})", testCase.DisplayName, testCase.UniqueID);
143174
}
144175

145176
return !cancelledThunk();
@@ -170,7 +201,7 @@ private VsTestResult MakeVsTestResult(TestOutcome outcome, ITestCase testCase, s
170201
if (result.Duration.TotalMilliseconds == 0)
171202
result.Duration = TimeSpan.FromMilliseconds(1);
172203

173-
if (!String.IsNullOrEmpty(output))
204+
if (!string.IsNullOrEmpty(output))
174205
result.Messages.Add(new VsTestResultMessage(VsTestResultMessage.StandardOutCategory, output));
175206

176207
return result;

0 commit comments

Comments
 (0)