diff --git a/Directory.Packages.props b/Directory.Packages.props index 2ed0dc3e9..e5fc9884d 100644 --- a/Directory.Packages.props +++ b/Directory.Packages.props @@ -20,6 +20,7 @@ + diff --git a/src/Renci.SshNet/BaseClient.cs b/src/Renci.SshNet/BaseClient.cs index 243d83dab..074fe24dc 100644 --- a/src/Renci.SshNet/BaseClient.cs +++ b/src/Renci.SshNet/BaseClient.cs @@ -48,6 +48,14 @@ internal IServiceFactory ServiceFactory get { return _serviceFactory; } } + /// + /// Gets the protocol name used in telemetry for this client. + /// + private protected virtual string TelemetryProtocolName + { + get { return "ssh"; } + } + /// /// Gets the connection info. /// @@ -209,6 +217,20 @@ public void Connect() { CheckDisposed(); + using var operation = SshNetTelemetry.StartOperation(TelemetryProtocolName, "Connect", _connectionInfo); + try + { + ConnectCore(); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } + } + + private void ConnectCore() + { // TODO (see issue #1758): // we're not stopping the keep-alive timer and disposing the session here // @@ -278,6 +300,20 @@ public async Task ConnectAsync(CancellationToken cancellationToken) CheckDisposed(); cancellationToken.ThrowIfCancellationRequested(); + using var operation = SshNetTelemetry.StartOperation(TelemetryProtocolName, "Connect", _connectionInfo); + try + { + await ConnectCoreAsync(cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } + } + + private async Task ConnectCoreAsync(CancellationToken cancellationToken) + { // TODO (see issue #1758): // we're not stopping the keep-alive timer and disposing the session here // diff --git a/src/Renci.SshNet/NetConfClient.cs b/src/Renci.SshNet/NetConfClient.cs index f2e2299c3..76e58e7ce 100644 --- a/src/Renci.SshNet/NetConfClient.cs +++ b/src/Renci.SshNet/NetConfClient.cs @@ -202,6 +202,12 @@ public XmlDocument ClientCapabilities /// public bool AutomaticMessageIdHandling { get; set; } + /// + private protected override string TelemetryProtocolName + { + get { return "netconf"; } + } + /// /// Sends the receive RPC. /// diff --git a/src/Renci.SshNet/Renci.SshNet.csproj b/src/Renci.SshNet/Renci.SshNet.csproj index 9b7af1590..8e0bc1e94 100644 --- a/src/Renci.SshNet/Renci.SshNet.csproj +++ b/src/Renci.SshNet/Renci.SshNet.csproj @@ -53,6 +53,10 @@ + + + + diff --git a/src/Renci.SshNet/SftpClient.cs b/src/Renci.SshNet/SftpClient.cs index 947139f84..58cf76078 100644 --- a/src/Renci.SshNet/SftpClient.cs +++ b/src/Renci.SshNet/SftpClient.cs @@ -169,6 +169,12 @@ public int ProtocolVersion } } + /// + private protected override string TelemetryProtocolName + { + get { return "sftp"; } + } + /// /// Gets the current SFTP session. /// @@ -304,7 +310,16 @@ public void ChangeDirectory(string path) throw new SshConnectionException("Client not connected."); } - _sftpSession.ChangeDirectory(path); + using var operation = StartOperation("ChangeDirectory", path); + try + { + _sftpSession.ChangeDirectory(path); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -331,7 +346,7 @@ public Task ChangeDirectoryAsync(string path, CancellationToken cancellationToke cancellationToken.ThrowIfCancellationRequested(); - return _sftpSession.ChangeDirectoryAsync(path, cancellationToken); + return ChangeDirectoryCoreAsync(_sftpSession, path, cancellationToken); } /// @@ -347,8 +362,17 @@ public Task ChangeDirectoryAsync(string path, CancellationToken cancellationToke /// The method was called after the client was disposed. public void ChangePermissions(string path, short mode) { - var file = Get(path); - file.SetPermissions(mode); + using var operation = StartOperation("ChangePermissions", path); + try + { + var file = Get(path); + file.SetPermissions(mode); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -370,9 +394,18 @@ public void CreateDirectory(string path) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); + using var operation = StartOperation("CreateDirectory", path); + try + { + var fullPath = _sftpSession.GetCanonicalPath(path); - _sftpSession.RequestMkDir(fullPath); + _sftpSession.RequestMkDir(fullPath); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -396,9 +429,18 @@ public async Task CreateDirectoryAsync(string path, CancellationToken cancellati throw new SshConnectionException("Client not connected."); } - var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + using var operation = StartOperation("CreateDirectory", path); + try + { + var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); - await _sftpSession.RequestMkDirAsync(fullPath, cancellationToken).ConfigureAwait(false); + await _sftpSession.RequestMkDirAsync(fullPath, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -421,9 +463,18 @@ public void DeleteDirectory(string path) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); + using var operation = StartOperation("DeleteDirectory", path); + try + { + var fullPath = _sftpSession.GetCanonicalPath(path); - _sftpSession.RequestRmDir(fullPath); + _sftpSession.RequestRmDir(fullPath); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -439,9 +490,18 @@ public async Task DeleteDirectoryAsync(string path, CancellationToken cancellati cancellationToken.ThrowIfCancellationRequested(); - var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + using var operation = StartOperation("DeleteDirectory", path); + try + { + var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); - await _sftpSession.RequestRmDirAsync(fullPath, cancellationToken).ConfigureAwait(false); + await _sftpSession.RequestRmDirAsync(fullPath, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -464,9 +524,18 @@ public void DeleteFile(string path) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); + using var operation = StartOperation("DeleteFile", path); + try + { + var fullPath = _sftpSession.GetCanonicalPath(path); - _sftpSession.RequestRemove(fullPath); + _sftpSession.RequestRemove(fullPath); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -482,8 +551,17 @@ public async Task DeleteFileAsync(string path, CancellationToken cancellationTok cancellationToken.ThrowIfCancellationRequested(); - var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); - await _sftpSession.RequestRemoveAsync(fullPath, cancellationToken).ConfigureAwait(false); + using var operation = StartOperation("DeleteFile", path); + try + { + var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + await _sftpSession.RequestRemoveAsync(fullPath, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -523,17 +601,26 @@ public void RenameFile(string oldPath, string newPath, bool isPosix) throw new SshConnectionException("Client not connected."); } - var oldFullPath = _sftpSession.GetCanonicalPath(oldPath); + using var operation = StartOperation("RenameFile", oldPath); + try + { + var oldFullPath = _sftpSession.GetCanonicalPath(oldPath); - var newFullPath = _sftpSession.GetCanonicalPath(newPath); + var newFullPath = _sftpSession.GetCanonicalPath(newPath); - if (isPosix) - { - _sftpSession.RequestPosixRename(oldFullPath, newFullPath); + if (isPosix) + { + _sftpSession.RequestPosixRename(oldFullPath, newFullPath); + } + else + { + _sftpSession.RequestRename(oldFullPath, newFullPath); + } } - else + catch (Exception ex) { - _sftpSession.RequestRename(oldFullPath, newFullPath); + operation?.SetError(ex); + throw; } } @@ -562,9 +649,18 @@ public async Task RenameFileAsync(string oldPath, string newPath, CancellationTo cancellationToken.ThrowIfCancellationRequested(); - var oldFullPath = await _sftpSession.GetCanonicalPathAsync(oldPath, cancellationToken).ConfigureAwait(false); - var newFullPath = await _sftpSession.GetCanonicalPathAsync(newPath, cancellationToken).ConfigureAwait(false); - await _sftpSession.RequestRenameAsync(oldFullPath, newFullPath, cancellationToken).ConfigureAwait(false); + using var operation = StartOperation("RenameFile", oldPath); + try + { + var oldFullPath = await _sftpSession.GetCanonicalPathAsync(oldPath, cancellationToken).ConfigureAwait(false); + var newFullPath = await _sftpSession.GetCanonicalPathAsync(newPath, cancellationToken).ConfigureAwait(false); + await _sftpSession.RequestRenameAsync(oldFullPath, newFullPath, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -588,11 +684,20 @@ public void SymbolicLink(string path, string linkPath) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); + using var operation = StartOperation("SymbolicLink", path); + try + { + var fullPath = _sftpSession.GetCanonicalPath(path); - var linkFullPath = _sftpSession.GetCanonicalPath(linkPath); + var linkFullPath = _sftpSession.GetCanonicalPath(linkPath); - _sftpSession.RequestSymLink(fullPath, linkFullPath); + _sftpSession.RequestSymLink(fullPath, linkFullPath); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -643,9 +748,23 @@ public async IAsyncEnumerable ListDirectoryAsync(string path, [Enumer cancellationToken.ThrowIfCancellationRequested(); - var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + // The operation spans the whole enumeration. C# does not allow yield + // inside try/catch, so errors are recorded around each request instead. + using var operation = StartOperation("ListDirectory", path); + + string fullPath; + byte[] handle; + try + { + fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + handle = await _sftpSession.RequestOpenDirAsync(fullPath, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } - var handle = await _sftpSession.RequestOpenDirAsync(fullPath, cancellationToken).ConfigureAwait(false); try { var basePath = (fullPath[fullPath.Length - 1] == '/') ? @@ -654,7 +773,17 @@ public async IAsyncEnumerable ListDirectoryAsync(string path, [Enumer while (true) { - var files = await _sftpSession.RequestReadDirAsync(handle, cancellationToken).ConfigureAwait(false); + KeyValuePair[]? files; + try + { + files = await _sftpSession.RequestReadDirAsync(handle, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } + if (files is null) { break; @@ -746,11 +875,20 @@ public ISftpFile Get(string path) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); + using var operation = StartOperation("Get", path); + try + { + var fullPath = _sftpSession.GetCanonicalPath(path); - var attributes = _sftpSession.RequestLStat(fullPath); + var attributes = _sftpSession.RequestLStat(fullPath); - return new SftpFile(_sftpSession, fullPath, attributes); + return new SftpFile(_sftpSession, fullPath, attributes); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -778,11 +916,20 @@ public async Task GetAsync(string path, CancellationToken cancellatio cancellationToken.ThrowIfCancellationRequested(); - var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + using var operation = StartOperation("Get", path); + try + { + var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); - var attributes = await _sftpSession.RequestLStatAsync(fullPath, cancellationToken).ConfigureAwait(false); + var attributes = await _sftpSession.RequestLStatAsync(fullPath, cancellationToken).ConfigureAwait(false); - return new SftpFile(_sftpSession, fullPath, attributes); + return new SftpFile(_sftpSession, fullPath, attributes); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -807,35 +954,44 @@ public bool Exists(string path) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); - - /* - * Using SSH_FXP_REALPATH is not an alternative as the SFTP specification has not always - * been clear on how the server should respond when the specified path is not present on - * the server: - * - * SSH 1 to 4: - * No mention of how the server should respond if the path is not present on the server. - * - * SSH 5: - * The server SHOULD fail the request if the path is not present on the server. - * - * SSH 6: - * Draft 06: The server SHOULD fail the request if the path is not present on the server. - * Draft 07 to 13: The server MUST NOT fail the request if the path does not exist. - * - * Note that SSH 6 (draft 06 and forward) allows for more control options, but we - * currently only support up to v3. - */ - + using var operation = StartOperation("Exists", path); try { - _ = _sftpSession.RequestLStat(fullPath); - return true; + var fullPath = _sftpSession.GetCanonicalPath(path); + + /* + * Using SSH_FXP_REALPATH is not an alternative as the SFTP specification has not always + * been clear on how the server should respond when the specified path is not present on + * the server: + * + * SSH 1 to 4: + * No mention of how the server should respond if the path is not present on the server. + * + * SSH 5: + * The server SHOULD fail the request if the path is not present on the server. + * + * SSH 6: + * Draft 06: The server SHOULD fail the request if the path is not present on the server. + * Draft 07 to 13: The server MUST NOT fail the request if the path does not exist. + * + * Note that SSH 6 (draft 06 and forward) allows for more control options, but we + * currently only support up to v3. + */ + + try + { + _ = _sftpSession.RequestLStat(fullPath); + return true; + } + catch (SftpPathNotFoundException) + { + return false; + } } - catch (SftpPathNotFoundException) + catch (Exception ex) { - return false; + operation?.SetError(ex); + throw; } } @@ -865,35 +1021,44 @@ public async Task ExistsAsync(string path, CancellationToken cancellationT cancellationToken.ThrowIfCancellationRequested(); - var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); - - /* - * Using SSH_FXP_REALPATH is not an alternative as the SFTP specification has not always - * been clear on how the server should respond when the specified path is not present on - * the server: - * - * SSH 1 to 4: - * No mention of how the server should respond if the path is not present on the server. - * - * SSH 5: - * The server SHOULD fail the request if the path is not present on the server. - * - * SSH 6: - * Draft 06: The server SHOULD fail the request if the path is not present on the server. - * Draft 07 to 13: The server MUST NOT fail the request if the path does not exist. - * - * Note that SSH 6 (draft 06 and forward) allows for more control options, but we - * currently only support up to v3. - */ - + using var operation = StartOperation("Exists", path); try { - _ = await _sftpSession.RequestLStatAsync(fullPath, cancellationToken).ConfigureAwait(false); - return true; + var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + + /* + * Using SSH_FXP_REALPATH is not an alternative as the SFTP specification has not always + * been clear on how the server should respond when the specified path is not present on + * the server: + * + * SSH 1 to 4: + * No mention of how the server should respond if the path is not present on the server. + * + * SSH 5: + * The server SHOULD fail the request if the path is not present on the server. + * + * SSH 6: + * Draft 06: The server SHOULD fail the request if the path is not present on the server. + * Draft 07 to 13: The server MUST NOT fail the request if the path does not exist. + * + * Note that SSH 6 (draft 06 and forward) allows for more control options, but we + * currently only support up to v3. + */ + + try + { + _ = await _sftpSession.RequestLStatAsync(fullPath, cancellationToken).ConfigureAwait(false); + return true; + } + catch (SftpPathNotFoundException) + { + return false; + } } - catch (SftpPathNotFoundException) + catch (Exception ex) { - return false; + operation?.SetError(ex); + throw; } } @@ -1355,9 +1520,18 @@ public SftpFileSystemInformation GetStatus(string path) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); + using var operation = StartOperation("GetStatus", path); + try + { + var fullPath = _sftpSession.GetCanonicalPath(path); - return _sftpSession.RequestStatVfs(fullPath); + return _sftpSession.RequestStatVfs(fullPath); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -1384,8 +1558,17 @@ public async Task GetStatusAsync(string path, Cancell cancellationToken.ThrowIfCancellationRequested(); - var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); - return await _sftpSession.RequestStatVfsAsync(fullPath, cancellationToken).ConfigureAwait(false); + using var operation = StartOperation("GetStatus", path); + try + { + var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + return await _sftpSession.RequestStatVfsAsync(fullPath, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } #region File Methods @@ -1582,15 +1765,33 @@ public StreamWriter CreateText(string path, Encoding encoding) /// The method was called after the client was disposed. public void Delete(string path) { - var file = Get(path); - file.Delete(); + using var operation = StartOperation("Delete", path); + try + { + var file = Get(path); + file.Delete(); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// public async Task DeleteAsync(string path, CancellationToken cancellationToken = default) { - var file = await GetAsync(path, cancellationToken).ConfigureAwait(false); - await file.DeleteAsync(cancellationToken).ConfigureAwait(false); + using var operation = StartOperation("Delete", path); + try + { + var file = await GetAsync(path, cancellationToken).ConfigureAwait(false); + await file.DeleteAsync(cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -2043,9 +2244,18 @@ public SftpFileAttributes GetAttributes(string path) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); + using var operation = StartOperation("GetAttributes", path); + try + { + var fullPath = _sftpSession.GetCanonicalPath(path); - return _sftpSession.RequestLStat(fullPath); + return _sftpSession.RequestLStat(fullPath); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -2070,9 +2280,18 @@ public async Task GetAttributesAsync(string path, Cancellati throw new SshConnectionException("Client not connected."); } - var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); + using var operation = StartOperation("GetAttributes", path); + try + { + var fullPath = await _sftpSession.GetCanonicalPathAsync(path, cancellationToken).ConfigureAwait(false); - return await _sftpSession.RequestLStatAsync(fullPath, cancellationToken).ConfigureAwait(false); + return await _sftpSession.RequestLStatAsync(fullPath, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } /// @@ -2092,9 +2311,18 @@ public void SetAttributes(string path, SftpFileAttributes fileAttributes) throw new SshConnectionException("Client not connected."); } - var fullPath = _sftpSession.GetCanonicalPath(path); + using var operation = StartOperation("SetAttributes", path); + try + { + var fullPath = _sftpSession.GetCanonicalPath(path); - _sftpSession.RequestSetStat(fullPath, fileAttributes); + _sftpSession.RequestSetStat(fullPath, fileAttributes); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } } #endregion // File Methods @@ -2284,6 +2512,20 @@ private List InternalSynchronizeDirectories(string sourcePath, string /// is . /// Client not connected. private List InternalListDirectory(string path, SftpListDirectoryAsyncResult? asyncResult, Action? listCallback) + { + using var operation = StartOperation("ListDirectory", path); + try + { + return InternalListDirectoryCore(path, asyncResult, listCallback); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } + } + + private List InternalListDirectoryCore(string path, SftpListDirectoryAsyncResult? asyncResult, Action? listCallback) { ArgumentNullException.ThrowIfNull(path); @@ -2337,6 +2579,25 @@ private List InternalListDirectory(string path, SftpListDirectoryAsyn return result; } + private SshNetTelemetry.Operation? StartOperation(string operation, string? path) + { + return SshNetTelemetry.StartOperation(TelemetryProtocolName, operation, ConnectionInfo, path); + } + + private async Task ChangeDirectoryCoreAsync(ISftpSession sftpSession, string path, CancellationToken cancellationToken) + { + using var operation = StartOperation("ChangeDirectory", path); + try + { + await sftpSession.ChangeDirectoryAsync(path, cancellationToken).ConfigureAwait(false); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } + } + #pragma warning disable CA1849 // Call async methods when in an async method private async Task InternalDownloadFile( string path, @@ -2345,6 +2606,27 @@ private async Task InternalDownloadFile( IProgress? downloadProgress, bool isAsync, CancellationToken cancellationToken) + { + using var operation = StartOperation("DownloadFile", path); + try + { + var bytesDownloaded = await InternalDownloadFileCore(path, output, asyncResult, downloadProgress, isAsync, cancellationToken).ConfigureAwait(false); + operation?.SetTag("sftp.transfer.bytes", (long)bytesDownloaded); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } + } + + private async Task InternalDownloadFileCore( + string path, + Stream output, + SftpDownloadAsyncResult? asyncResult, + IProgress? downloadProgress, + bool isAsync, + CancellationToken cancellationToken) { Debug.Assert(!string.IsNullOrWhiteSpace(path)); Debug.Assert(output is not null); @@ -2386,10 +2668,10 @@ private async Task InternalDownloadFile( // The below is effectively sftpStream.CopyTo{Async}(output) with consideration // for downloadCallback/asyncResult. + ulong totalBytesRead = 0; var buffer = ArrayPool.Shared.Rent(81920); try { - ulong totalBytesRead = 0; while (true) { // Cancel download @@ -2447,6 +2729,8 @@ private async Task InternalDownloadFile( sftpStream.Dispose(); } } + + return totalBytesRead; } private async Task InternalUploadFile( @@ -2457,6 +2741,28 @@ private async Task InternalUploadFile( IProgress? uploadProgress, bool isAsync, CancellationToken cancellationToken) + { + using var operation = StartOperation("UploadFile", path); + try + { + var bytesUploaded = await InternalUploadFileCore(input, path, flags, asyncResult, uploadProgress, isAsync, cancellationToken).ConfigureAwait(false); + operation?.SetTag("sftp.transfer.bytes", (long)bytesUploaded); + } + catch (Exception ex) + { + operation?.SetError(ex); + throw; + } + } + + private async Task InternalUploadFileCore( + Stream input, + string path, + Flags flags, + SftpUploadAsyncResult? asyncResult, + IProgress? uploadProgress, + bool isAsync, + CancellationToken cancellationToken) { Debug.Assert(isAsync || cancellationToken == default); @@ -2593,6 +2899,8 @@ private async Task InternalUploadFile( { _sftpSession.RequestClose(handle); } + + return offset; } #pragma warning restore CA1849 // Call async methods when in an async method diff --git a/src/Renci.SshNet/SshCommand.cs b/src/Renci.SshNet/SshCommand.cs index ce1042244..6ed64f74d 100644 --- a/src/Renci.SshNet/SshCommand.cs +++ b/src/Renci.SshNet/SshCommand.cs @@ -46,6 +46,8 @@ public sealed class SshCommand : IDisposable private int _exitStatus; private volatile bool _haveExitStatus; // volatile to prevent re-ordering of reads/writes of _exitStatus. + private SshNetTelemetry.Operation? _operation; + /// /// Gets the command text. /// @@ -290,9 +292,29 @@ public Task ExecuteAsync(CancellationToken cancellationToken = default) _channel.ExtendedDataReceived += Channel_ExtendedDataReceived; _channel.RequestReceived += Channel_RequestReceived; _channel.Closed += Channel_Closed; - _channel.Open(); - _ = _channel.SendExecRequest(CommandText); + // This method is not async, so restore Activity.Current to keep the + // caller's subsequent work from being parented to the command. + if (SshNetTelemetry.IsEnabled) + { + var previousActivity = Activity.Current; + _operation = SshNetTelemetry.StartOperation("ssh", "Execute", _session.ConnectionInfo); + Activity.Current = previousActivity; + } + + try + { + _channel.Open(); + + _ = _channel.SendExecRequest(CommandText); + } + catch (Exception ex) + { + var operation = Interlocked.Exchange(ref _operation, value: null); + operation?.SetError(ex); + operation?.Dispose(); + throw; + } if (CommandTimeout != Timeout.InfiniteTimeSpan) { @@ -507,13 +529,17 @@ public string Execute(string commandText) private void Session_Disconnected(object? sender, EventArgs e) { - _ = _tcs?.TrySetException(new SshConnectionException("An established connection was aborted by the software in your host machine.", DisconnectReason.ConnectionLost)); + var exception = new SshConnectionException("An established connection was aborted by the software in your host machine.", DisconnectReason.ConnectionLost); + + CompleteOperation(exception); + _ = _tcs?.TrySetException(exception); SetAsyncComplete(setResult: false); } private void Session_ErrorOccurred(object? sender, ExceptionEventArgs e) { + CompleteOperation(e.Exception); _ = _tcs?.TrySetException(e.Exception); SetAsyncComplete(setResult: false); @@ -529,18 +555,24 @@ private void SetAsyncComplete(bool setResult = true) if (_userToken.IsCancellationRequested) { + CompleteOperation(isCanceled: true); _ = _tcs.TrySetCanceled(_userToken); } else if (_cts?.Token.IsCancellationRequested == true) { - _ = _tcs.TrySetException(new SshOperationTimeoutException($"Command '{CommandText}' timed out. ({nameof(CommandTimeout)}: {CommandTimeout}).")); + var exception = new SshOperationTimeoutException($"Command '{CommandText}' timed out. ({nameof(CommandTimeout)}: {CommandTimeout})."); + + CompleteOperation(exception); + _ = _tcs.TrySetException(exception); } else if (_cancellationRequested) { + CompleteOperation(isCanceled: true); _ = _tcs.TrySetCanceled(); } else { + CompleteOperation(); _ = _tcs.TrySetResult(null!); } } @@ -554,6 +586,35 @@ private void SetAsyncComplete(bool setResult = true) ExtendedOutputStream.Dispose(); } + /// + /// Ends the telemetry operation, if any. Called before completing + /// so that the operation has ended by the time awaiters resume. + /// + private void CompleteOperation(Exception? exception = null, bool isCanceled = false) + { + var operation = Interlocked.Exchange(ref _operation, value: null); + if (operation is null) + { + return; + } + + if (ExitStatus is int exitStatus) + { + operation.SetTag("ssh.command.exit_code", exitStatus); + } + + if (exception is not null) + { + operation.SetError(exception); + } + else if (isCanceled) + { + operation.SetError(typeof(OperationCanceledException).FullName!, "The command was cancelled."); + } + + operation.Dispose(); + } + private void Channel_Closed(object? sender, ChannelEventArgs e) { SetAsyncComplete(); @@ -662,7 +723,10 @@ private void Dispose(bool disposing) if (_tcs is { Task.IsCompleted: false } tcs) { // In case an operation is still running, try to complete it with an ObjectDisposedException. - _ = tcs.TrySetException(new ObjectDisposedException(GetType().FullName)); + var exception = new ObjectDisposedException(GetType().FullName); + + CompleteOperation(exception); + _ = tcs.TrySetException(exception); } _isDisposed = true; diff --git a/src/Renci.SshNet/SshNetTelemetry.cs b/src/Renci.SshNet/SshNetTelemetry.cs new file mode 100644 index 000000000..e7472c05c --- /dev/null +++ b/src/Renci.SshNet/SshNetTelemetry.cs @@ -0,0 +1,125 @@ +#nullable enable +using System; +using System.Diagnostics; +using System.Diagnostics.Metrics; + +namespace Renci.SshNet +{ + /// + /// The and used for SSH.NET's + /// traces and metrics. Both are named Renci.SshNet. + /// + internal static class SshNetTelemetry + { + internal const string Name = "Renci.SshNet"; + + internal static readonly ActivitySource ActivitySource = new(Name, ThisAssembly.NuGetPackageVersion); + + internal static readonly Meter Meter = new(Name, ThisAssembly.NuGetPackageVersion); + + private static readonly Histogram OperationDuration = Meter.CreateHistogram( + "ssh.client.operation.duration", + unit: "s", + description: "Duration of SSH client operations."); + + /// + /// Gets a value indicating whether anybody is listening to the traces or metrics. + /// + internal static bool IsEnabled + { + get { return OperationDuration.Enabled || ActivitySource.HasListeners(); } + } + + /// + /// Starts tracking an operation, or returns if nobody is listening. + /// + internal static Operation? StartOperation(string protocol, string operation, IConnectionInfo? connectionInfo, string? path = null) + { + if (!IsEnabled) + { + return null; + } + + return new Operation(protocol, operation, connectionInfo, path); + } + + internal sealed class Operation : IDisposable + { + private readonly Activity? _activity; + private readonly long _startTimestamp; + private TagList _metricTags; + private bool _isDisposed; + + internal Operation(string protocol, string operation, IConnectionInfo? connectionInfo, string? path) + { + _startTimestamp = Stopwatch.GetTimestamp(); + + _metricTags = new TagList + { + { "network.protocol.name", protocol }, + { "ssh.operation.name", operation }, + }; + + if (connectionInfo is not null) + { + _metricTags.Add("server.address", connectionInfo.Host); + _metricTags.Add("server.port", connectionInfo.Port); + } + + _activity = ActivitySource.StartActivity(protocol + " " + operation, ActivityKind.Client); + + if (_activity is { IsAllDataRequested: true }) + { + foreach (var tag in _metricTags) + { + _ = _activity.SetTag(tag.Key, tag.Value); + } + + if (path is not null) + { + _ = _activity.SetTag("file.path", path); + } + } + } + + public void SetTag(string key, object? value) + { + if (_activity is { IsAllDataRequested: true }) + { + _ = _activity.SetTag(key, value); + } + } + + public void SetError(Exception exception) + { + SetError(exception.GetType().FullName!, exception.Message); + } + + public void SetError(string errorType, string? description) + { + _metricTags.Add("error.type", errorType); + + if (_activity is not null) + { + _ = _activity.SetTag("error.type", errorType); + _ = _activity.SetStatus(ActivityStatusCode.Error, description); + } + } + + public void Dispose() + { + if (_isDisposed) + { + return; + } + + _isDisposed = true; + + var elapsedSeconds = (Stopwatch.GetTimestamp() - _startTimestamp) / (double)Stopwatch.Frequency; + OperationDuration.Record(elapsedSeconds, _metricTags); + + _activity?.Dispose(); + } + } + } +} diff --git a/test/Renci.SshNet.IntegrationTests/TelemetryTests.cs b/test/Renci.SshNet.IntegrationTests/TelemetryTests.cs new file mode 100644 index 000000000..75313e5e7 --- /dev/null +++ b/test/Renci.SshNet.IntegrationTests/TelemetryTests.cs @@ -0,0 +1,260 @@ +using System.Collections.Concurrent; +using System.Diagnostics; +using System.Diagnostics.Metrics; + +using Renci.SshNet.Common; + +namespace Renci.SshNet.IntegrationTests +{ + [TestClass] + public class TelemetryTests : TestBase, IDisposable + { + private readonly ActivitySource _testSource = new ActivitySource("Renci.SshNet.IntegrationTests"); + private readonly ConcurrentQueue _activities = new ConcurrentQueue(); + private readonly ConcurrentQueue<(double Value, Dictionary Tags)> _durations = new ConcurrentQueue<(double, Dictionary)>(); + private readonly ActivityListener _activityListener; + private readonly MeterListener _meterListener; + + public TelemetryTests() + { + // .NET Framework defaults to hierarchical IDs; OpenTelemetry forces W3C, so do the same. + Activity.DefaultIdFormat = ActivityIdFormat.W3C; + Activity.ForceDefaultIdFormat = true; + + _activityListener = new ActivityListener + { + ShouldListenTo = source => string.Equals(source.Name, "Renci.SshNet", StringComparison.Ordinal) || string.Equals(source.Name, _testSource.Name, StringComparison.Ordinal), + Sample = (ref _) => ActivitySamplingResult.AllDataAndRecorded, + ActivityStopped = activity => + { + if (activity.Source.Name == "Renci.SshNet") + { + _activities.Enqueue(activity); + } + }, + }; + ActivitySource.AddActivityListener(_activityListener); + + _meterListener = new MeterListener + { + InstrumentPublished = (instrument, listener) => + { + if (instrument.Meter.Name == "Renci.SshNet") + { + listener.EnableMeasurementEvents(instrument); + } + }, + }; + _meterListener.SetMeasurementEventCallback((instrument, value, tags, state) => + { + var tagDictionary = new Dictionary(); + foreach (var tag in tags) + { + tagDictionary[tag.Key] = tag.Value; + } + + _durations.Enqueue((value, tagDictionary)); + }); + _meterListener.Start(); + } + + public void Dispose() + { + _activityListener.Dispose(); + _meterListener.Dispose(); + _testSource.Dispose(); + } + + [TestMethod] + public async Task Sftp_Operations_ProduceSpansAndDurations() + { + var directory = $"/tmp/telemetry-{Guid.NewGuid():N}"; + var path = $"{directory}/file.bin"; + + using (var parent = _testSource.StartActivity("parent")) + using (var client = new SftpClient(SshServerHostName, SshServerPort, User.UserName, User.Password)) + { + await client.ConnectAsync(CancellationToken.None); + client.CreateDirectory(directory); + + using (var input = CreateMemoryStream(10_000)) + { + input.Position = 0; + await client.UploadFileAsync(input, path); + } + + _ = client.ListDirectory(directory); + + await foreach (var file in client.ListDirectoryAsync(directory, CancellationToken.None)) + { + Assert.IsNotNull(file); + } + + using (var output = new MemoryStream()) + { + client.DownloadFile(path, output); + } + + client.DeleteFile(path); + client.DeleteDirectory(directory); + + var spans = _activities.ToList(); + + CollectionAssert.AreEqual( + new[] + { + "sftp Connect", + "sftp CreateDirectory", + "sftp UploadFile", + "sftp ListDirectory", + "sftp ListDirectory", + "sftp DownloadFile", + "sftp DeleteFile", + "sftp DeleteDirectory", + }, + spans.Select(s => s.DisplayName).ToArray()); + + foreach (var span in spans) + { + Assert.AreEqual(ActivityKind.Client, span.Kind); + Assert.AreEqual(parent.TraceId, span.TraceId); + Assert.AreEqual(parent.SpanId, span.ParentSpanId); + Assert.AreEqual(ActivityStatusCode.Unset, span.Status); + Assert.AreEqual("sftp", span.GetTagItem("network.protocol.name")); + Assert.AreEqual(SshServerHostName, span.GetTagItem("server.address")); + Assert.AreEqual((int)SshServerPort, span.GetTagItem("server.port")); + } + + var upload = spans.Single(s => s.DisplayName == "sftp UploadFile"); + Assert.AreEqual(path, upload.GetTagItem("file.path")); + Assert.AreEqual(10_000L, upload.GetTagItem("sftp.transfer.bytes")); + + var download = spans.Single(s => s.DisplayName == "sftp DownloadFile"); + Assert.AreEqual(10_000L, download.GetTagItem("sftp.transfer.bytes")); + + Assert.AreEqual(spans.Count, _durations.Count); + Assert.IsTrue(_durations.All(d => d.Value > 0 && !d.Tags.ContainsKey("file.path"))); + } + } + + [TestMethod] + public async Task Sftp_MetadataOperations_ProduceSpans() + { + var directory = $"/tmp/telemetry-{Guid.NewGuid():N}"; + + using var client = new SftpClient(SshServerHostName, SshServerPort, User.UserName, User.Password); + client.Connect(); + + await client.CreateDirectoryAsync(directory); + client.WriteAllText($"{directory}/a.txt", "a"); + + Assert.IsTrue(client.Exists($"{directory}/a.txt")); + Assert.IsFalse(await client.ExistsAsync($"{directory}/missing.txt")); + client.RenameFile($"{directory}/a.txt", $"{directory}/b.txt"); + _ = await client.GetAttributesAsync($"{directory}/b.txt", CancellationToken.None); + client.ChangeDirectory(directory); + await client.ChangeDirectoryAsync("/tmp"); + client.Delete($"{directory}/b.txt"); + await client.DeleteDirectoryAsync(directory); + + var spans = _activities.ToList(); + + CollectionAssert.AreEqual( + new[] + { + "sftp Connect", + "sftp CreateDirectory", + "sftp Exists", + "sftp Exists", + "sftp RenameFile", + "sftp GetAttributes", + "sftp ChangeDirectory", + "sftp ChangeDirectory", + "sftp Get", + "sftp Delete", + "sftp DeleteDirectory", + }, + spans.Select(s => s.DisplayName).ToArray()); + + // A path that does not exist is a normal result of Exists, not an error. + Assert.IsTrue(spans.TrueForAll(s => s.Status == ActivityStatusCode.Unset)); + + var rename = spans.Single(s => s.DisplayName == "sftp RenameFile"); + Assert.AreEqual($"{directory}/a.txt", rename.GetTagItem("file.path")); + + // Delete looks the file up first, so Get is its child. + var delete = spans.Single(s => s.DisplayName == "sftp Delete"); + var get = spans.Single(s => s.DisplayName == "sftp Get"); + Assert.AreEqual(delete.SpanId, get.ParentSpanId); + } + + [TestMethod] + public void Sftp_DownloadMissingFile_RecordsError() + { + using var client = new SftpClient(SshServerHostName, SshServerPort, User.UserName, User.Password); + client.Connect(); + + using var output = new MemoryStream(); + _ = Assert.ThrowsExactly(() => client.DownloadFile($"/tmp/missing-{Guid.NewGuid():N}", output)); + + var span = _activities.Single(s => s.DisplayName == "sftp DownloadFile"); + Assert.AreEqual(ActivityStatusCode.Error, span.Status); + Assert.AreEqual(typeof(SftpPathNotFoundException).FullName, span.GetTagItem("error.type")); + + var duration = _durations.Single(d => (string)d.Tags["ssh.operation.name"] == "DownloadFile"); + Assert.AreEqual(typeof(SftpPathNotFoundException).FullName, duration.Tags["error.type"]); + } + + [TestMethod] + public void Connect_WrongPassword_RecordsError() + { + using var client = new SshClient(SshServerHostName, SshServerPort, User.UserName, "wrong-password"); + + _ = Assert.ThrowsExactly(client.Connect); + + var span = _activities.Single(); + Assert.AreEqual("ssh Connect", span.DisplayName); + Assert.AreEqual(ActivityStatusCode.Error, span.Status); + Assert.AreEqual(typeof(SshAuthenticationException).FullName, span.GetTagItem("error.type")); + } + + [TestMethod] + public async Task SshCommand_ExecuteAsync_EndsSpanBeforeAwaitResumes() + { + using var client = new SshClient(SshServerHostName, SshServerPort, User.UserName, User.Password); + client.Connect(); + + using var parent = _testSource.StartActivity("parent"); + using var command = client.CreateCommand("echo hello; exit 3"); + + var task = command.ExecuteAsync(); + + // ExecuteAsync is not async, so it must not leave its span as Activity.Current. + Assert.AreSame(parent, Activity.Current); + + await task; + + var span = _activities.Single(s => s.DisplayName == "ssh Execute"); + Assert.AreEqual(parent.SpanId, span.ParentSpanId); + Assert.AreEqual(3, span.GetTagItem("ssh.command.exit_code")); + Assert.AreEqual(ActivityStatusCode.Unset, span.Status); + Assert.IsNull(span.GetTagItem("ssh.command.text")); + } + + [TestMethod] + public void SshCommand_Timeout_RecordsError() + { + using var client = new SshClient(SshServerHostName, SshServerPort, User.UserName, User.Password); + client.Connect(); + + using var command = client.CreateCommand("sleep 10"); + command.CommandTimeout = TimeSpan.FromMilliseconds(200); + + _ = Assert.ThrowsExactly(command.Execute); + + var span = _activities.Single(s => s.DisplayName == "ssh Execute"); + Assert.AreEqual(ActivityStatusCode.Error, span.Status); + Assert.AreEqual(typeof(SshOperationTimeoutException).FullName, span.GetTagItem("error.type")); + } + } +}