Fix race between SendMessage and server-initiated key re-exchange

src/Renci.SshNet/SshMessageFactory.cs

@@ -66,6 +66,12 @@ internal sealed class SshMessageFactory
         /// </summary>
         internal const byte HighestMessageNumber = 100;
 
+        /// <summary>
+        /// Defines the lowest message number of the connection protocol (RFC 4254), which is
+        /// SSH_MSG_GLOBAL_REQUEST. The connection protocol messages run up to <see cref="HighestMessageNumber"/>.
+        /// </summary>
+        internal const byte FirstConnectionProtocolMessageNumber = 80;
+
         /// <summary>
         /// Initializes a new instance of the <see cref="SshMessageFactory"/> class.
         /// </summary>
@@ -126,7 +132,18 @@ public Message Create(byte messageNumber)
         /// <para>  The relevant KEX Reply MSG will be allowed from a sub class of KeyExchange class.</para>
         /// <para>  For example, it calls <c>Session.RegisterMessage("SSH_MSG_KEX_ECDH_REPLY");</c> if the curve25519-sha256 KEX algorithm is selected per negotiation.</para>
         /// </param>
-        public void DisableNonKeyExchangeMessages(bool strict)
+        /// <param name="allowConnectionProtocolMessages">
+        /// <see langword="true"/> to leave the connection protocol messages (80 - 100, e.g. SSH_MSG_CHANNEL_DATA) enabled;
+        /// otherwise <see langword="false"/>. Ignored in strict key exchange mode.
+        /// <para>
+        /// This is meant for a key re-exchange in an established session. The sender of a message is not
+        /// supposed to send connection protocol messages between its SSH_MSG_KEXINIT and its SSH_MSG_NEWKEYS,
+        /// but the messages the peer had already queued when it decided to re-exchange keys, or that a
+        /// less strict peer sends anyway, are still protected by the old keys and are safe to accept.
+        /// The caller is responsible for not processing them until the key exchange has completed.
+        /// </para>
+        /// </param>
+        public void DisableNonKeyExchangeMessages(bool strict, bool allowConnectionProtocolMessages = false)
         {
             for (var i = 0; i < AllMessages.Length; i++)
             {
@@ -142,7 +159,10 @@ public void DisableNonKeyExchangeMessages(bool strict)
                 }
                 else
                 {
-                    if (messageNumber is (> 2 and < 20) or > 30)
+                    var isNonKeyExchangeMessage = messageNumber is (> 2 and < 20) or > 30;
+                    var isRetained = allowConnectionProtocolMessages && messageNumber >= FirstConnectionProtocolMessageNumber;
+
+                    if (isNonKeyExchangeMessage && !isRetained)
                     {
                         _enabledMessagesByNumber[messageNumber] = null;
                     }

test/Renci.SshNet.IntegrationTests/.dockerignore

@@ -1,3 +1,4 @@
 *
 !server/*
 !user/*
+!proftpd/*

test/Renci.SshNet.IntegrationTests/Logging/TextWriterLogger.cs

@@ -0,0 +1,45 @@
+#nullable enable
+
+using Microsoft.Extensions.Logging;
+
+namespace Renci.SshNet.IntegrationTests.Logging
+{
+    internal class TextWriterLogger(TextWriter writer, string categoryName) : ILogger
+    {
+        public IDisposable? BeginScope<TState>(TState state)
+            where TState : notnull
+        {
+            return null;
+        }
+
+        public bool IsEnabled(LogLevel logLevel)
+        {
+            return true;
+        }
+
+        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
+        {
+            StringBuilder sb = new StringBuilder();
+            sb.Append(logLevel);
+            sb.Append(": ");
+            sb.Append(categoryName);
+            sb.Append(": ");
+
+            string message = formatter(state, exception);
+            sb.Append(message);
+
+            if (exception != null)
+            {
+                sb.Append(": ");
+                sb.Append(exception);
+            }
+
+            string line = sb.ToString();
+
+            lock (writer)
+            {
+                writer.WriteLine(line);
+            }
+        }
+    }
+}

test/Renci.SshNet.IntegrationTests/Logging/TextWriterLoggerProvider.cs

@@ -0,0 +1,18 @@
+#nullable enable
+
+using Microsoft.Extensions.Logging;
+
+namespace Renci.SshNet.IntegrationTests.Logging
+{
+    internal class TextWriterLoggerProvider(TextWriter writer) : ILoggerProvider
+    {
+        public ILogger CreateLogger(string categoryName)
+        {
+            return new TextWriterLogger(writer, categoryName);
+        }
+
+        public void Dispose()
+        {
+        }
+    }
+}

test/Renci.SshNet.IntegrationTests/ProFtpdRekeyTests.cs

@@ -0,0 +1,164 @@
+#if NET // The test uses Parallel.ForEachAsync, which is not available on .NET Framework.
+
+using DotNet.Testcontainers.Builders;
+using DotNet.Testcontainers.Containers;
+using DotNet.Testcontainers.Images;
+
+using Microsoft.Extensions.Logging;
+
+using Renci.SshNet.IntegrationTests.Logging;
+
+namespace Renci.SshNet.IntegrationTests
+{
+    /// <summary>
+    /// Reproduces https://github.com/sshnet/SSH.NET/issues/1764: connection failures during
+    /// SFTP transfers when the server initiates a key re-exchange.
+    /// <para>
+    /// Unlike OpenSSH, which queues non key exchange output while a re-exchange is in progress,
+    /// ProFTPD mod_sftp keeps sending channel messages (SSH_MSG_CHANNEL_WINDOW_ADJUST,
+    /// SSH_MSG_CHANNEL_DATA) after it has sent its SSH_MSG_KEXINIT. The same load which passes
+    /// against the OpenSSH test server therefore fails against ProFTPD with either
+    /// "Message type 93 is not valid in the current context." or a connection drop
+    /// ("Key exchange failed"). These tests run against a ProFTPD container configured to
+    /// re-key every 1 MB (see proftpd/proftpd.conf) to give the race many trials per upload.
+    /// </para>
+    /// <para>
+    /// Trace-level logging to a file is enabled for the duration of these tests: the small
+    /// per-message overhead on the message listener thread widens the window between the
+    /// arrival of the server's SSH_MSG_KEXINIT and its processing, during which concurrent
+    /// uploaders keep sending data. This mirrors real-world conditions (applications with
+    /// trace logging enabled, or slower links) and makes the race fail reliably on loopback.
+    /// </para>
+    /// </summary>
+    [TestClass]
+    public sealed class ProFtpdRekeyTests : TestBase
+    {
+        private static IFutureDockerImage _proFtpdImage;
+        private static IContainer _proFtpdServer;
+        private static string _proFtpdHostName;
+        private static ushort _proFtpdPort;
+        private static StreamWriter _traceLogWriter;
+        private static ILoggerFactory _traceLoggerFactory;
+
+        [ClassInitialize]
+        [System.Diagnostics.CodeAnalysis.SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "MSTests requires context parameter")]
+        public static async Task ClassInitialize(TestContext context)
+        {
+            // The Windows Tests in CI cannot run the ProFTPD container: Docker on the Windows
+            // runners is in Windows containers mode ("no matching manifest for windows/amd64"),
+            // which is why the OpenSSH server for the other integration tests is set up in
+            // WSL2 with Podman instead (see InfrastructureFixture).
+            if (OperatingSystem.IsWindows() && Environment.GetEnvironmentVariable("CI") == "true")
+            {
+                Assert.Inconclusive("Requires a container runtime able to run Linux containers.");
+            }
+
+            _traceLogWriter = new StreamWriter(Path.GetTempFileName()) { AutoFlush = true };
+            _traceLoggerFactory = LoggerFactory.Create(builder =>
+            {
+                builder.SetMinimumLevel(LogLevel.Trace);
+                builder.AddProvider(new TextWriterLoggerProvider(_traceLogWriter));
+            });
+
+            SshNetLoggingConfiguration.InitializeLogging(_traceLoggerFactory);
+
+            _proFtpdImage = new ImageFromDockerfileBuilder()
+                .WithName("renci-ssh-tests-proftpd-image")
+                .WithDockerfileDirectory(CommonDirectoryPath.GetSolutionDirectory(), Path.Combine("test", "Renci.SshNet.IntegrationTests"))
+                .WithDockerfile("proftpd/Dockerfile")
+                .WithDeleteIfExists(true)
+                .Build();
+
+            await _proFtpdImage.CreateAsync(context.CancellationToken);
+
+            _proFtpdServer = new ContainerBuilder(_proFtpdImage)
+                .WithHostname("renci-ssh-tests-proftpd")
+                .WithPortBinding(22, true)
+                .WithWaitStrategy(Wait.ForUnixContainer().UntilInternalTcpPortIsAvailable(22))
+                .Build();
+
+            await _proFtpdServer.StartAsync(context.CancellationToken);
+
+            _proFtpdPort = _proFtpdServer.GetMappedPublicPort(22);
+            _proFtpdHostName = _proFtpdServer.Hostname;
+        }
+
+        [ClassCleanup]
+        public static async Task ClassCleanup()
+        {
+            if (_proFtpdServer != null)
+            {
+                await _proFtpdServer.DisposeAsync();
+            }
+
+            if (_proFtpdImage != null)
+            {
+                await _proFtpdImage.DisposeAsync();
+            }
+
+            // Restore the assembly-wide logging configuration set up by InfrastructureFixture.
+            var defaultLoggerFactory = LoggerFactory.Create(builder =>
+            {
+                builder.SetMinimumLevel(LogLevel.Debug);
+                builder.AddTestConsoleLogger();
+            });
+
+            SshNetLoggingConfiguration.InitializeLogging(defaultLoggerFactory);
+
+            _traceLoggerFactory?.Dispose();
+            _traceLogWriter?.Dispose();
+        }
+
+        [TestMethod]
+        public async Task Sftp_ConcurrentUploads_WithServerRekey()
+        {
+            const int fileSize = 128 * 1024 * 1024;
+            const int concurrentUploads = 4;
+            const int attempts = 3;
+
+            using (var sftp = new SftpClient(_proFtpdHostName, _proFtpdPort, "sshnet", "ssh4ever"))
+            {
+                await sftp.ConnectAsync(CancellationToken.None);
+
+                for (var attempt = 0; attempt < attempts; attempt++)
+                {
+                    await Parallel.ForEachAsync(Enumerable.Range(0, concurrentUploads), async (i, ct) =>
+                    {
+                        var localFile = CreateZeroFilledTempFile(fileSize);
+
+                        try
+                        {
+                            var remoteFile = $"rekey-test-{i}";
+
+                            using (var fileStream = File.OpenRead(localFile))
+                            {
+                                await sftp.UploadFileAsync(fileStream, remoteFile, ct);
+                            }
+
+                            var remoteLength = (await sftp.GetAsync(remoteFile, ct)).Attributes.Size;
+
+                            Assert.AreEqual(fileSize, remoteLength);
+                        }
+                        finally
+                        {
+                            File.Delete(localFile);
+                        }
+                    });
+                }
+            }
+        }
+
+        private static string CreateZeroFilledTempFile(long size)
+        {
+            var file = Path.GetTempFileName();
+
+            using (var fs = File.OpenWrite(file))
+            {
+                fs.SetLength(size);
+            }
+
+            return file;
+        }
+    }
+}
+#endif

test/Renci.SshNet.IntegrationTests/proftpd/Dockerfile

@@ -0,0 +1,11 @@
+# ProFTPD with mod_sftp, used by ProFtpdRekeyTests to reproduce
+# https://github.com/sshnet/SSH.NET/issues/1764 (alpine:3.24 ships ProFTPD 1.3.9c).
+FROM alpine:3.24
+RUN apk add --no-cache proftpd proftpd-mod_sftp openssh-keygen
+RUN ssh-keygen -t rsa -b 3072 -N "" -m PEM -f /etc/proftpd/host_rsa
+RUN chmod 400 /etc/proftpd/host_rsa
+RUN adduser -D sshnet
+RUN echo 'sshnet:ssh4ever' | chpasswd
+COPY proftpd/proftpd.conf /etc/proftpd/proftpd.conf
+EXPOSE 22
+CMD ["proftpd", "--nodaemon", "--config", "/etc/proftpd/proftpd.conf"]

test/Renci.SshNet.IntegrationTests/proftpd/proftpd.conf

@@ -0,0 +1,26 @@
+ServerName "renci-ssh-tests-proftpd"
+ServerType standalone
+DefaultServer on
+# SFTPEngine converts this server to SSH/SFTP entirely; no plain FTP is served.
+Port 22
+User nobody
+Group nobody
+DefaultRoot ~
+AllowOverwrite on
+PidFile /var/run/proftpd.pid
+ScoreboardFile /var/run/proftpd.scoreboard
+
+LoadModule mod_sftp.c
+
+<IfModule mod_sftp.c>
+  SFTPEngine on
+  SFTPHostKey /etc/proftpd/host_rsa
+  SFTPAuthMethods password
+  SFTPLog /var/log/sftp.log
+  # Re-key every 1 MB so that the key re-exchange races of
+  # https://github.com/sshnet/SSH.NET/issues/1764 get many trials per upload.
+  # Unlike OpenSSH, ProFTPD mod_sftp keeps sending channel messages
+  # (SSH_MSG_CHANNEL_WINDOW_ADJUST / SSH_MSG_CHANNEL_DATA) after it has
+  # initiated a re-exchange, which is what triggers the client-side failures.
+  SFTPRekey required 3600 1
+</IfModule>

test/Renci.SshNet.Tests/Classes/SessionTest_ConnectedBase.cs

@@ -38,6 +38,14 @@ public abstract class SessionTest_ConnectedBase
 
         protected Random Random { get; private set; }
         protected byte[] SessionId { get; private set; }
+
+        /// <summary>
+        /// The name of the (mocked) key exchange algorithm that the "server" offers in its KEXINIT.
+        /// </summary>
+        protected string KeyExchangeAlgorithm
+        {
+            get { return _keyExchangeAlgorithm; }
+        }
         protected ConnectionInfo ConnectionInfo { get; private set; }
         protected IList<EventArgs> DisconnectedRegister { get; private set; }
         protected IList<MessageEventArgs<DisconnectMessage>> DisconnectReceivedRegister { get; private set; }
@@ -208,6 +216,9 @@ private void SetupMocks()
             _ = _keyExchangeMock.Setup(p => p.Name)
                                 .Returns(_keyExchangeAlgorithm);
             _ = _keyExchangeMock.Setup(p => p.Start(Session, It.IsAny<KeyExchangeInitMessage>(), false));
+
+            // a key re-exchange initiated by the server: the client is expected to send its own KEXINIT
+            _ = _keyExchangeMock.Setup(p => p.Start(Session, It.IsAny<KeyExchangeInitMessage>(), true));
             _ = _keyExchangeMock.Setup(p => p.ExchangeHash)
                                 .Returns(SessionId);
             _ = _keyExchangeMock.Setup(p => p.CreateServerCipher(out It.Ref<bool>.IsAny))