diff --git a/src/SourceBuild/content/eng/pipelines/vmr-license-scan.yml b/src/SourceBuild/content/eng/pipelines/vmr-license-scan.yml index 2b1604fec65e..d1e80d232b30 100644 --- a/src/SourceBuild/content/eng/pipelines/vmr-license-scan.yml +++ b/src/SourceBuild/content/eng/pipelines/vmr-license-scan.yml @@ -51,7 +51,6 @@ extends: containers: licenseScanContainer: image: mcr.microsoft.com/dotnet-buildtools/prereqs:azurelinux-3.0-net9.0-source-build-test-amd64 - options: '--memory=20g' pool: name: NetCore1ESPool-Svc-Internal image: build.azurelinux.3.amd64 @@ -79,20 +78,37 @@ extends: local name="$1" local repoPath="$2" local scanIgnorePatterns="${3:-}" + local scanProcessCount="${4:-}" if [ ! -z "$matrix" ]; then matrix="$matrix," fi - matrix="$matrix \"$name\": { \"repoPath\": \"$repoPath\", \"scanIgnorePatterns\": \"$scanIgnorePatterns\" }" + matrix="$matrix \"$name\": { \"repoPath\": \"$repoPath\", \"scanIgnorePatterns\": \"$scanIgnorePatterns\", \"scanProcessCount\": \"$scanProcessCount\" }" } # Repos whose src/ subdirectories should be scanned as separate jobs. # The repo root is also scanned with --ignore to skip subdirectories covered by sub-scans. splitRepos="source-build-assets" + # Repos that should scan with a reduced number of scancode processes. This is + # independent of splitRepos. Their large, text-heavy content deadlocks scancode's + # multiprocessing pool at the end of a scan, so they are scanned serially (0 disables + # multiprocessing). Other repos use the test's default. Flows through the matrix. + serialScanRepos="source-build-assets" + serialScanProcessCount=0 + + # Returns the scancode --processes value for a repo, or empty to use the test's default. + getScanProcessCount() { + local repoName="$1" + if echo "$serialScanRepos" | grep -qw "$repoName"; then + echo "$serialScanProcessCount" + fi + } + # If the repo name is provided, only scan that repo. if [ ! -z "$specificRepoName" ]; then repoName="$specificRepoName" dir="$vmrSrcDir/$specificRepoName" + scanProcessCount=$(getScanProcessCount "$repoName") if echo "$splitRepos" | grep -qw "$repoName"; then ignorePatterns="" @@ -104,17 +120,18 @@ extends: ignorePatterns="$ignorePatterns " fi ignorePatterns="$ignorePatterns$subdirName" - addMatrixEntry "${repoName}_${subdirName}" "$subdir" + addMatrixEntry "${repoName}_${subdirName}" "$subdir" "" "$scanProcessCount" fi done - addMatrixEntry "$repoName" "$dir" "$ignorePatterns" + addMatrixEntry "$repoName" "$dir" "$ignorePatterns" "$scanProcessCount" else - addMatrixEntry "$repoName" "$dir" + addMatrixEntry "$repoName" "$dir" "" "$scanProcessCount" fi else for dir in "$vmrSrcDir"/*/ do repoName=$(basename "$dir") + scanProcessCount=$(getScanProcessCount "$repoName") if echo "$splitRepos" | grep -qw "$repoName"; then # Root scan: skip subdirectories that are covered by sub-scans @@ -129,12 +146,12 @@ extends: ignorePatterns="$ignorePatterns " fi ignorePatterns="$ignorePatterns$subdirName" - addMatrixEntry "${repoName}_${subdirName}" "$subdir" + addMatrixEntry "${repoName}_${subdirName}" "$subdir" "" "$scanProcessCount" fi done - addMatrixEntry "$repoName" "$dir" "$ignorePatterns" + addMatrixEntry "$repoName" "$dir" "$ignorePatterns" "$scanProcessCount" else - addMatrixEntry "$repoName" "$dir" + addMatrixEntry "$repoName" "$dir" "" "$scanProcessCount" fi done fi @@ -176,6 +193,7 @@ extends: -clp:v=m /p:SmokeTestsLicenseScanPath=$(repoPath) "/p:SourceBuildTestsLicenseScanIgnorePatterns=$(scanIgnorePatterns)" + /p:SourceBuildTestsLicenseScanProcessCount=$(scanProcessCount) /p:SmokeTestsWarnOnLicenseScanDiffs=false /p:TargetRid=linux-x64 /p:PortableRid=linux-x64 diff --git a/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/Config.cs b/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/Config.cs index d1bb01f70783..827533fbba80 100644 --- a/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/Config.cs +++ b/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/Config.cs @@ -23,6 +23,8 @@ internal static class Config public static bool ExcludeOmniSharpTests => bool.TryParse((string)AppContext.GetData(ConfigSwitchPrefix + nameof(ExcludeOmniSharpTests))!, out bool excludeOmniSharpTests) && excludeOmniSharpTests; public static string? LicenseScanPath => (string)AppContext.GetData(ConfigSwitchPrefix + nameof(LicenseScanPath))!; public static string? LicenseScanIgnorePatterns => (string)AppContext.GetData(ConfigSwitchPrefix + nameof(LicenseScanIgnorePatterns))!; + public static int? LicenseScanProcessCount => + int.TryParse((string?)AppContext.GetData(ConfigSwitchPrefix + nameof(LicenseScanProcessCount)), out int processCount) ? processCount : null; public static string? MsftSdkTarballPath => (string)AppContext.GetData(ConfigSwitchPrefix + nameof(MsftSdkTarballPath))!; public static string? PoisonReportPath => (string)AppContext.GetData(ConfigSwitchPrefix + nameof(PoisonReportPath))!; public static string? PrereqsPath => (string)AppContext.GetData(ConfigSwitchPrefix + nameof(PrereqsPath))!; diff --git a/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/LicenseScanTests.cs b/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/LicenseScanTests.cs index 509194f23fce..0a7e65883d62 100644 --- a/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/LicenseScanTests.cs +++ b/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/LicenseScanTests.cs @@ -152,6 +152,12 @@ public void ScanForLicenses() // Indicates how long until a timeout occurs for scanning a given file const int FileScanTimeoutSeconds = 1800; + // Number of parallel processes scancode should use. Large, text-heavy repos can + // deadlock scancode's multiprocessing pool at the end of a scan, so the pipeline + // scans them serially by passing 0. Default to 4 when not specified by the pipeline. + const int DefaultProcessCount = 4; + int processCount = Config.LicenseScanProcessCount ?? DefaultProcessCount; + string scancodeResultsPath = Path.Combine(Config.LogsDirectory, "scancode-results.json"); // Combine default and additional ignore patterns @@ -167,7 +173,7 @@ public void ScanForLicenses() string ignoreOptions = string.Join(" ", allIgnorePatterns.Select(pattern => $"--ignore {pattern}")); ExecuteHelper.ExecuteProcessValidateExitCode( "scancode", - $"--license --processes 4 --timeout {FileScanTimeoutSeconds} --strip-root --only-findings {ignoreOptions} --json-pp {scancodeResultsPath} {Config.LicenseScanPath}", + $"--license --processes {processCount} --timeout {FileScanTimeoutSeconds} --strip-root --only-findings {ignoreOptions} --json-pp {scancodeResultsPath} {Config.LicenseScanPath}", OutputHelper); JsonDocument doc = JsonDocument.Parse(File.ReadAllText(scancodeResultsPath)); diff --git a/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/Microsoft.DotNet.SourceBuild.SmokeTests.csproj b/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/Microsoft.DotNet.SourceBuild.SmokeTests.csproj index 41d7e5dde177..feea579afae5 100644 --- a/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/Microsoft.DotNet.SourceBuild.SmokeTests.csproj +++ b/src/SourceBuild/content/test/Microsoft.DotNet.SourceBuild.SmokeTests/Microsoft.DotNet.SourceBuild.SmokeTests.csproj @@ -75,6 +75,10 @@ Condition="'$(SourceBuildTestsLicenseScanIgnorePatterns)' != ''"> $(SourceBuildTestsLicenseScanIgnorePatterns) + + $(SourceBuildTestsLicenseScanProcessCount) + $(MsftSdkTarballPath) diff --git a/test/Microsoft.NET.TestFramework/Commands/TestCommand.cs b/test/Microsoft.NET.TestFramework/Commands/TestCommand.cs index ebbdcadba8e2..ca0c4cabe7b3 100644 --- a/test/Microsoft.NET.TestFramework/Commands/TestCommand.cs +++ b/test/Microsoft.NET.TestFramework/Commands/TestCommand.cs @@ -1,4 +1,4 @@ -// Licensed to the .NET Foundation under one or more agreements. +// Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. using System.Diagnostics; @@ -20,6 +20,15 @@ public abstract class TestCommand public List EnvironmentToRemove { get; } = new List(); + /// + /// When true, the full command output is echoed to instead of being capped by a + /// . Leave false (the default) so a single very verbose + /// command (e.g. dotnet test -v diag) can't flood xUnit's IPC channel and trigger a + /// spurious hang-dump timeout. Set it (or call ) for + /// tests that need the complete output in the test log. + /// + public bool DisableTruncatedOutputLogging { get; set; } + // These only work via Execute(), not when using GetProcessStartInfo() public Action CommandOutputHandler { get; set; } public Action ProcessStartedHandler { get; set; } @@ -61,6 +70,16 @@ public TestCommand WithTraceOutput() return this; } + /// + /// Opts this command out of bounded output logging so the complete command output is echoed to + /// . See . + /// + public TestCommand WithoutTruncatedOutputLogging() + { + DisableTruncatedOutputLogging = true; + return this; + } + private SdkCommandSpec CreateCommandSpec(IEnumerable args) { var commandSpec = CreateCommand(args); @@ -120,29 +139,32 @@ private static bool SuccessOrNotTransientRestoreError(CommandResult result) public virtual CommandResult Execute(IEnumerable args) { - var spec = CreateCommandSpec(args); - - var command = spec + var command = CreateCommandSpec(args) .ToCommand(_doNotEscapeArguments) .CaptureStdOut() .CaptureStdErr(); - command.OnOutputLine(line => + if (CommandOutputHandler != null) { - Log.WriteLine($"》{line}"); - CommandOutputHandler?.Invoke(line); - }); - - command.OnErrorLine(line => - { - Log.WriteLine($"❌{line}"); - }); - - var display = $"dotnet {string.Join(" ", spec.Arguments)}"; + command.OnOutputLine(CommandOutputHandler); + } - Log.WriteLine($"Executing '{display}':"); var result = ((Command)command).Execute(ProcessStartedHandler); - Log.WriteLine($"Command '{display}' exited with exit code {result.ExitCode}."); + + // By default, cap how much of the (potentially enormous) command output is echoed to the test + // log so a single very verbose command (e.g. `dotnet test -v diag`) can't flush hundreds of + // megabytes over the test host's IPC channel and trigger a spurious hang-dump timeout. The full + // StdOut/StdErr remain on the returned CommandResult; only the log echo is bounded. Tests that + // need the complete output in the log can opt out with WithoutTruncatedOutputLogging(). + if (DisableTruncatedOutputLogging) + { + LogCommandResult(Log, result); + } + else + { + using var truncatingLog = new TruncatingTestOutputHelper(Log); + LogCommandResult(truncatingLog, result); + } return result; } diff --git a/test/Microsoft.NET.TestFramework/TruncatingTestOutputHelper.cs b/test/Microsoft.NET.TestFramework/TruncatingTestOutputHelper.cs new file mode 100644 index 000000000000..9745ab0de9d1 --- /dev/null +++ b/test/Microsoft.NET.TestFramework/TruncatingTestOutputHelper.cs @@ -0,0 +1,179 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +namespace Microsoft.NET.TestFramework +{ + /// + /// An wrapper that forwards only a bounded amount of output to an + /// inner helper. The first maxHeadCharacters characters are forwarded as they are written, + /// the most recent maxTailCharacters characters are buffered and emitted by + /// , and everything in between is dropped (replaced with a short note + /// describing how much was omitted). A character budget is used rather than a line count because + /// individual lines can be arbitrarily long. + /// + /// + /// + /// This is useful for commands that intentionally produce an enormous amount of output (for example + /// dotnet test -v diag). Echoing every line to xUnit's output buffer can flush hundreds of + /// megabytes over the test host's single IPC channel when the test completes, which is enough to + /// starve the blame hang-dump collector's inactivity timer and trigger a spurious timeout. + /// + /// + /// Tail eviction is line-oriented: whole buffered lines (oldest first) are dropped to stay within + /// maxTailCharacters, so the retained tail is rounded to line boundaries rather than an exact + /// character count. To avoid the degenerate case where a short final line would otherwise evict a + /// much larger immediately-preceding line (collapsing the tail to almost nothing), the single oldest + /// line that straddles the budget boundary is trimmed from its front instead of dropped — its + /// trailing (most recent) portion is kept. A single larger than the + /// tail budget likewise keeps only its final maxTailCharacters characters. The net effect is + /// that the tail always retains close to maxTailCharacters of the most recent output. + /// + /// + public sealed class TruncatingTestOutputHelper : ITestOutputHelper, IDisposable + { + private const int DefaultHeadCharacters = 50_000; + private const int DefaultTailCharacters = 50_000; + + private readonly ITestOutputHelper _inner; + private readonly int _maxHeadCharacters; + private readonly int _maxTailCharacters; + private readonly object _lock = new(); + private readonly LinkedList _tail = new(); + + private int _headCharactersWritten; + private bool _headFull; + private int _tailCharacters; + private long _omittedCharacters; + private int _omittedLines; + private bool _flushed; + + public TruncatingTestOutputHelper(ITestOutputHelper inner, int maxHeadCharacters = DefaultHeadCharacters, int maxTailCharacters = DefaultTailCharacters) + { + _inner = inner; + _maxHeadCharacters = maxHeadCharacters; + _maxTailCharacters = maxTailCharacters; + } + + public void WriteLine(string message) + { + message ??= string.Empty; + + lock (_lock) + { + if (!_headFull) + { + int remainingHead = _maxHeadCharacters - _headCharactersWritten; + if (message.Length <= remainingHead) + { + // Still within the head budget: forward immediately so the start of the output + // is preserved even if the test later throws before the tail is flushed. + _inner.WriteLine(message); + _headCharactersWritten += message.Length; + if (_headCharactersWritten >= _maxHeadCharacters) + { + _headFull = true; + } + + return; + } + + // This single message crosses the head budget. Forward only the part that fits in + // the head so one very large WriteLine (e.g. an entire captured StdOut written at + // once) cannot push the whole payload through immediately, then buffer the rest as + // tail below. + if (remainingHead > 0) + { + _inner.WriteLine(message.Substring(0, remainingHead)); + message = message.Substring(remainingHead); + } + + _headFull = true; + } + + // Past the head budget: keep only the most recent characters within the tail budget. + EnqueueTail(message); + } + } + + private void EnqueueTail(string message) + { + // If a single message is on its own larger than the entire tail budget, keep only its + // final portion so the buffered tail can never exceed the bound. + if (_maxTailCharacters > 0 && message.Length > _maxTailCharacters) + { + _omittedCharacters += message.Length - _maxTailCharacters; + message = message.Substring(message.Length - _maxTailCharacters); + } + + _tail.AddLast(message); + _tailCharacters += message.Length; + + // Evict the oldest content to stay within the tail budget. Whole lines are dropped while a + // whole line can be removed without going under budget. The single oldest line that straddles + // the boundary is trimmed from its front (keeping its most recent, trailing portion) rather + // than dropped, so a short final line can never discard a much larger recent line and leave + // the tail nearly empty. + while (_tailCharacters > _maxTailCharacters && _tail.Count > 0) + { + string oldest = _tail.First!.Value; + int overBy = _tailCharacters - _maxTailCharacters; + + if (oldest.Length <= overBy) + { + _tail.RemoveFirst(); + _tailCharacters -= oldest.Length; + _omittedCharacters += oldest.Length; + _omittedLines++; + } + else + { + // Dropping this whole line would remove more than necessary, discarding recent + // output. Trim just its leading (oldest) characters instead. + _tail.First.Value = oldest.Substring(overBy); + _tailCharacters -= overBy; + _omittedCharacters += overBy; + break; + } + } + } + + public void WriteLine(string format, params object[] args) => WriteLine(string.Format(format, args)); + + /// + /// Emits the buffered tail (see ). Disposing in a using + /// block guarantees the tail is flushed even if the logged command (or a later assertion) + /// throws, without needing an explicit try/finally. + /// + public void Dispose() => WriteBufferedTail(); + + /// + /// Emits the buffered tail (preceded by a note describing any omitted output) to the inner + /// helper. Call this once the command being logged has finished. Safe to call more than once. + /// + public void WriteBufferedTail() + { + lock (_lock) + { + if (_flushed) + { + return; + } + + _flushed = true; + + if (_omittedCharacters > 0) + { + _inner.WriteLine($"... [{_omittedLines} lines / {_omittedCharacters} characters of output omitted by {nameof(TruncatingTestOutputHelper)}] ..."); + } + + foreach (string line in _tail) + { + _inner.WriteLine(line); + } + + _tail.Clear(); + _tailCharacters = 0; + } + } + } +} diff --git a/test/dotnet-test.Tests/TruncatingTestOutputHelperTests.cs b/test/dotnet-test.Tests/TruncatingTestOutputHelperTests.cs new file mode 100644 index 000000000000..53963895a331 --- /dev/null +++ b/test/dotnet-test.Tests/TruncatingTestOutputHelperTests.cs @@ -0,0 +1,100 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System.Collections.Generic; +using System.Linq; + +namespace Microsoft.DotNet.Cli.Test.Tests +{ + public class TruncatingTestOutputHelperTests + { + private sealed class RecordingOutputHelper : ITestOutputHelper + { + public List Lines { get; } = new(); + + public void WriteLine(string message) => Lines.Add(message); + + public void WriteLine(string format, params object[] args) => Lines.Add(string.Format(format, args)); + } + + private static bool IsOmissionNote(string line) => line.Contains(nameof(TruncatingTestOutputHelper)); + + [Fact] + public void OutputWithinBudgetIsForwardedUnchanged() + { + var inner = new RecordingOutputHelper(); + using (var helper = new TruncatingTestOutputHelper(inner)) + { + helper.WriteLine("first"); + helper.WriteLine("second"); + } + + inner.Lines.Should().Equal("first", "second"); + } + + [Fact] + public void MiddleIsDroppedButHeadAndTailArePreserved() + { + var inner = new RecordingOutputHelper(); + using (var helper = new TruncatingTestOutputHelper(inner, maxHeadCharacters: 5, maxTailCharacters: 5)) + { + helper.WriteLine("aaaaa"); // fills the head + helper.WriteLine("bbbbb"); // middle, should be dropped + helper.WriteLine("ccccc"); // most recent, should be kept as tail + } + + inner.Lines.First().Should().Be("aaaaa"); + inner.Lines.Last().Should().Be("ccccc"); + inner.Lines.Should().ContainSingle(l => IsOmissionNote(l)); + inner.Lines.Should().NotContain("bbbbb"); + } + + [Fact] + public void TailKeepsRecentContentWhenFinalLineIsTiny() + { + // Michael Simons' review edge case: a short final line must not evict a much larger + // immediately-preceding line and leave the tail with essentially nothing. + var inner = new RecordingOutputHelper(); + using (var helper = new TruncatingTestOutputHelper(inner, maxHeadCharacters: 0, maxTailCharacters: 10)) + { + helper.WriteLine(new string('A', 9)); + helper.WriteLine("BBB"); + } + + string tail = string.Concat(inner.Lines.Where(l => !IsOmissionNote(l))); + // The retained tail holds the most recent ~10 characters (the trailing 'A's plus "BBB"), + // not just the tiny final "BBB" (which is what whole-line eviction would have left). + tail.Should().Be(new string('A', 7) + "BBB"); + tail.Length.Should().Be(10); + } + + [Fact] + public void SingleMessageLargerThanBudgetForwardsOnlyHeadAndTailPortions() + { + var inner = new RecordingOutputHelper(); + using (var helper = new TruncatingTestOutputHelper(inner, maxHeadCharacters: 5, maxTailCharacters: 5)) + { + helper.WriteLine(new string('x', 100)); + } + + int forwardedCharacters = inner.Lines.Where(l => !IsOmissionNote(l)).Sum(l => l.Length); + forwardedCharacters.Should().Be(10); // 5 head + 5 tail, not the whole 100 + inner.Lines.Should().ContainSingle(l => IsOmissionNote(l)); + } + + [Fact] + public void WriteBufferedTailIsIdempotent() + { + var inner = new RecordingOutputHelper(); + var helper = new TruncatingTestOutputHelper(inner, maxHeadCharacters: 0, maxTailCharacters: 5); + helper.WriteLine("abcdef"); // 6 chars, trimmed to last 5 + + helper.WriteBufferedTail(); + int countAfterFirstFlush = inner.Lines.Count; + helper.WriteBufferedTail(); + + inner.Lines.Count.Should().Be(countAfterFirstFlush); + inner.Lines.Last().Should().Be("bcdef"); + } + } +}