search

sshnet / SSH.NET

SSH.NET is a Secure Shell (SSH) library for .NET, optimized for parallelism.
http://sshnet.github.io/SSH.NET/
MIT License
3.88k stars 917 forks source link

Remove enormous array allocations in tests causing instability in CI #1367

Closed Rob-Hague closed 2 months ago

Rob-Hague commented 2 months ago

I have opened a ticket for lack of ideas https://help.appveyor.com/discussions/problems/35588-net-tests-silently-exiting-on-ubuntu2204

Rob-Hague commented 2 months ago 
string token = ""; // https://ci.appveyor.com/api-keys
var client = new HttpClient();

client.DefaultRequestHeaders.Accept.Add(new MediaTypeWithQualityHeaderValue("application/json"));
client.DefaultRequestHeaders.Authorization = new AuthenticationHeaderValue("Bearer", token);

JsonDocument x = JsonDocument.Parse(await client.GetStringAsync("https://ci.appveyor.com/api/projects/drieseng/ssh-net/history?recordsNumber=200"));

int buildCount = 0;
int badCount = 0;
foreach (JsonElement build in x.RootElement.GetProperty("builds").EnumerateArray())
{
    buildCount++;
    long buildId = build.GetProperty("buildId").GetInt64();
    string status = build.GetProperty("status").GetString();

    if (status != "success")
    {
        continue;
    }

    foreach (var job in JsonDocument.Parse(
        await client.GetStringAsync($"https://ci.appveyor.com/api/projects/drieseng/ssh-net/builds/{buildId}"))
        .RootElement.GetProperty("build").GetProperty("jobs").EnumerateArray())
    {
        string jobId = job.GetProperty("jobId").GetString();
        int testsCount = job.GetProperty("testsCount").GetInt32();

        if (testsCount < 1000)
        {
            badCount++;
            Console.WriteLine($"Bad: {testsCount} tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/{buildId}");

            Console.WriteLine(string.Join(Environment.NewLine,
                ReadLines(await client.GetStreamAsync($"https://ci.appveyor.com/api/buildjobs/{jobId}/log"))
                .TakeLast(5)));

            Console.WriteLine();
            Console.WriteLine();
        }
    }
}

 Console.WriteLine($"{badCount} bad of {buildCount}");

static IEnumerable<string> ReadLines(Stream s)
{
    using StreamReader sr = new(s);
    string line;
    while ((line = sr.ReadLine()) != null)
    {
        yield return line;
    }
}
``` Bad: 837 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49547340 [00:04:05] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [25 ms] [00:04:07] Passed CreateShellStreamShouldThrowSshException [1 s] [00:04:11] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [4 s] [00:04:12] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [523 ms] [00:04:14] Build exited with code 0 Bad: 840 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49547208 [00:04:05] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [491 ms] [00:04:05] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [162 ms] [00:04:05] Passed CreateShellStreamShouldNotReturnNull [18 ms] [00:04:08] Passed SendPseudoTerminalRequestShouldHaveBeenInvokedOnce [4 s] [00:04:09] Build exited with code 0 Bad: 838 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49546786 [00:03:57] Passed CreateShellStreamShouldThrowSshException [39 ms] [00:03:57] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [5 ms] [00:04:03] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [2 s] [00:04:07] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [8 s] [00:04:08] Build exited with code 0 Bad: 831 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49544633 [00:04:12] Passed CreateSftpFileReaderShouldReturnCreatedInstance [6 ms] [00:04:12] Passed CreateShellStreamShouldRethrowExceptionThrownByOpenOnChannelSession [26 ms] [00:04:12] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [19 ms] [00:04:12] Passed CreateShellStreamShouldThrowSshException [1 s] [00:04:17] Build exited with code 0 Bad: 834 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49521023 [00:03:58] Passed CreateShellStreamShouldThrowSshException [32 ms] [00:03:58] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [533 ms] [00:03:58] Passed CreateShellStreamShouldRethrowExceptionThrownBySendPseudoTerminalRequestOnChannelSession [714 ms] [00:03:58] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [16 ms] [00:04:03] Build exited with code 0 Bad: 836 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49520209 [00:04:32] Passed CreateShellStreamShouldRethrowExceptionThrownBySendPseudoTerminalRequestOnChannelSession [360 ms] [00:04:32] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [489 ms] [00:04:33] Passed CreateShellStreamShouldThrowSshException [966 ms] [00:04:36] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [3 s] [00:04:39] Build exited with code 0 Bad: 838 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49517420 [00:03:44] Passed CreateShellStreamShouldThrowSshException [765 ms] [00:03:44] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [5 ms] [00:03:44] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [416 ms] [00:03:46] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [2 s] [00:03:48] Build exited with code 0 Bad: 838 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49517250 [00:04:01] Passed CreateShellStreamShouldThrowSshException [119 ms] [00:04:03] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [625 ms] [00:04:03] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [1 s] [00:04:03] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [7 ms] [00:04:06] Build exited with code 0 Bad: 840 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49513131 [00:04:11] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [17 ms] [00:04:11] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [5 ms] [00:04:13] Passed CreateShellStreamShouldNotReturnNull [1 s] [00:04:13] Passed SendPseudoTerminalRequestShouldHaveBeenInvokedOnce [14 ms] [00:04:14] Build exited with code 0 Bad: 836 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49495999 [00:04:06] Passed CreateShellStreamShouldRethrowExceptionThrownBySendPseudoTerminalRequestOnChannelSession [29 ms] [00:04:06] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [185 ms] [00:04:08] Passed CreateShellStreamShouldThrowSshException [319 ms] [00:04:13] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [6 s] [00:04:19] Build exited with code 0 Bad: 840 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49470368 [00:03:21] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [6 ms] [00:03:21] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [333 ms] [00:03:21] Passed CreateShellStreamShouldNotReturnNull [86 ms] [00:03:24] Passed SendPseudoTerminalRequestShouldHaveBeenInvokedOnce [2 s] [00:03:26] Build exited with code 0 Bad: 834 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49453523 [00:04:00] Passed CreateShellStreamShouldThrowSshException [19 ms] [00:04:00] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [1 s] [00:04:00] Passed CreateShellStreamShouldRethrowExceptionThrownBySendPseudoTerminalRequestOnChannelSession [6 ms] [00:04:00] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [196 ms] [00:04:05] Build exited with code 0 Bad: 833 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49449893 [00:04:00] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [2 ms] [00:04:00] Passed CreateShellStreamShouldThrowSshException [41 ms] [00:04:01] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [3 s] [00:04:03] Passed CreateShellStreamShouldRethrowExceptionThrownBySendPseudoTerminalRequestOnChannelSession [25 ms] [00:04:05] Build exited with code 0 Bad: 836 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49419110 [00:04:07] Passed CreateShellStreamShouldThrowSshException [3 s] [00:04:09] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [886 ms] [00:04:09] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [26 ms] [00:04:09] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [6 ms] [00:04:14] Build exited with code 0 Bad: 836 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49404033 [00:03:55] Passed CreateShellStreamShouldRethrowExceptionThrownBySendPseudoTerminalRequestOnChannelSession [20 ms] [00:03:55] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [354 ms] [00:03:57] Passed CreateShellStreamShouldThrowSshException [2 s] [00:04:05] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [8 s] [00:04:08] Build exited with code 0 Bad: 840 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49402372 [00:04:08] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [1 s] [00:04:10] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [827 ms] [00:04:10] Passed CreateShellStreamShouldNotReturnNull [11 ms] [00:04:10] Passed SendPseudoTerminalRequestShouldHaveBeenInvokedOnce [416 ms] [00:04:13] Build exited with code 0 Bad: 840 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49378759 [00:04:07] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [21 ms] [00:04:07] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [5 ms] [00:04:07] Passed CreateShellStreamShouldNotReturnNull [577 ms] [00:04:10] Passed SendPseudoTerminalRequestShouldHaveBeenInvokedOnce [3 s] [00:04:12] Build exited with code 0 Bad: 838 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49368767 [00:04:03] Passed CreateShellStreamShouldThrowSshException [57 ms] [00:04:03] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [19 ms] [00:04:03] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [80 ms] [00:04:03] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [357 ms] [00:04:07] Build exited with code 0 Bad: 839 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49340690 [00:05:24] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [443 ms] [00:05:24] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [247 ms] [00:05:24] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [353 ms] [00:05:24] Passed CreateShellStreamShouldNotReturnNull [37 ms] [00:05:34] Build exited with code 0 Bad: 836 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49340612 [00:05:13] Passed CreateShellStreamShouldRethrowExceptionThrownBySendPseudoTerminalRequestOnChannelSession [32 ms] [00:05:13] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [28 ms] [00:05:13] Passed CreateShellStreamShouldThrowSshException [22 ms] [00:05:17] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [6 s] [00:05:41] Build exited with code 0 Bad: 840 tests in https://ci.appveyor.com/project/drieseng/ssh-net/builds/49334632 [00:05:18] Passed CreateShellStreamShouldRethrowExceptionThrownBySendShellRequestOnChannelSession [1 s] [00:05:18] Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [259 ms] [00:05:18] Passed CreateShellStreamShouldNotReturnNull [19 ms] [00:05:21] Passed SendPseudoTerminalRequestShouldHaveBeenInvokedOnce [3 s] [00:05:51] Build exited with code 0 21 bad of 100 ```
Rob-Hague commented 2 months ago

Memory explodes:

[00:04:54]   Passed CreateShellStreamShouldRethrowExceptionThrownByOpenOnChannelSession [26 ms]
[00:04:54]   Standard Output Messages:
[00:04:54]  memout1 ServiceFactoryTest_CreateShellStream_ChannelOpenThrowsException: 29,558,432
[00:04:54]  memout2 ServiceFactoryTest_CreateShellStream_ChannelOpenThrowsException: 1,496,752,520
[00:04:54] 
[00:04:54] 
[00:04:54]   Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [2 ms]
[00:04:54]   Standard Output Messages:
[00:04:54]  memout1 ServiceFactoryTest_CreateShellStream_ChannelOpenThrowsException: 1,496,893,136
[00:04:54]  memout2 ServiceFactoryTest_CreateShellStream_ChannelOpenThrowsException: 4,440,210,096
[00:04:54] 
[00:04:54] 
[00:04:54]   Passed CreateShellStreamShouldThrowSshException [305 ms]
[00:04:54]   Passed DisposeOnChannelSessionShouldHaveBeenInvokedOnce [529 ms]
Rob-Hague commented 2 months ago

Found it 🙂

https://github.com/sshnet/SSH.NET/blob/70a0a08dae410df014fe33267087821026ccc27e/test/Renci.SshNet.Tests/Classes/ServiceFactoryTest_CreateShellStream_ChannelOpenThrowsException.cs#L38

https://github.com/sshnet/SSH.NET/blob/70a0a08dae410df014fe33267087821026ccc27e/test/Renci.SshNet.Tests/Classes/ServiceFactoryTest_CreateShellStream_Success.cs#L37

Rob-Hague commented 2 months ago

Found it 🙂

Since these changes, I have run the CI 13 times successfully without any silent crashes at the ~840 test mark (the latest build failed one of the usual integration tests afterwards).

At a 21 / 100 prior occurrence rate, the chance of 13 passes would be (1 - 0.21) ^ 13 ~= 4.66%. So I think we can say that this is the fix and that the process was crashing due to out-of-memory from these randomly-sized array allocations.

Still a bit of a mystery why the dotnet process was showing exit code 0 though