scadalink-design/src/ScadaLink.SiteRuntime/Scripts/AuditingDbCommand.cs

using System.Data;
using System.Data.Common;
using System.Diagnostics;
using Microsoft.Extensions.Logging;
using ScadaLink.Commons.Entities.Audit;
using ScadaLink.Commons.Interfaces.Services;
using ScadaLink.Commons.Types.Enums;

namespace ScadaLink.SiteRuntime.Scripts;

/// <summary>
/// Audit Log #23 — M4 Bundle A: <see cref="DbCommand"/> decorator that emits
/// exactly one <c>DbOutbound</c>/<c>DbWrite</c> audit event per execution.
/// </summary>
/// <remarks>
/// <para>
/// <b>Vocabulary lock (M4 plan):</b> both writes (Execute / ExecuteScalar) and
/// reads (ExecuteReader) emit <see cref="AuditKind.DbWrite"/> on the
/// <see cref="AuditChannel.DbOutbound"/> channel. The <c>Extra</c> JSON column
/// distinguishes them — <c>{"op":"write","rowsAffected":N}</c> for writes,
/// <c>{"op":"read","rowsReturned":N}</c> for reads.
/// </para>
/// <para>
/// <b>Best-effort emission (alog.md §7):</b> mirrors
/// <see cref="ScriptRuntimeContext.ExternalSystemHelper"/>'s 3-layer fail-safe.
/// The original ADO.NET result (or original exception) flows back to the
/// script untouched; audit-build, audit-write, and audit-continuation faults
/// are all logged + swallowed. A faulted <see cref="IAuditWriter"/> never
/// aborts the SQL call.
/// </para>
/// </remarks>
internal sealed class AuditingDbCommand : DbCommand
{
    private readonly DbCommand _inner;
    private readonly IAuditWriter _auditWriter;
    private readonly string _connectionName;
    private readonly string _siteId;
    private readonly string _instanceName;
    private readonly string? _sourceScript;
    private readonly ILogger _logger;
    private DbConnection? _wrappingConnection;

    public AuditingDbCommand(
        DbCommand inner,
        IAuditWriter auditWriter,
        string connectionName,
        string siteId,
        string instanceName,
        string? sourceScript,
        ILogger logger)
    {
        _inner = inner ?? throw new ArgumentNullException(nameof(inner));
        _auditWriter = auditWriter ?? throw new ArgumentNullException(nameof(auditWriter));
        _connectionName = connectionName ?? throw new ArgumentNullException(nameof(connectionName));
        _siteId = siteId ?? string.Empty;
        _instanceName = instanceName ?? string.Empty;
        _sourceScript = sourceScript;
        _logger = logger ?? throw new ArgumentNullException(nameof(logger));
    }

    // -- Forwarded surface ------------------------------------------------

#pragma warning disable CS8765 // ADO.NET base members carry pre-NRT signatures with permissive nullability
    public override string CommandText
    {
        get => _inner.CommandText;
        set => _inner.CommandText = value;
    }
#pragma warning restore CS8765

    public override int CommandTimeout
    {
        get => _inner.CommandTimeout;
        set => _inner.CommandTimeout = value;
    }

    public override CommandType CommandType
    {
        get => _inner.CommandType;
        set => _inner.CommandType = value;
    }

    public override bool DesignTimeVisible
    {
        get => _inner.DesignTimeVisible;
        set => _inner.DesignTimeVisible = value;
    }

    public override UpdateRowSource UpdatedRowSource
    {
        get => _inner.UpdatedRowSource;
        set => _inner.UpdatedRowSource = value;
    }

    protected override DbConnection? DbConnection
    {
        // When the script has wrapped the connection (the normal path through
        // ScriptRuntimeContext.DatabaseHelper.Connection) we keep returning
        // the wrapper, but writes from the user go through to the inner
        // command so the underlying provider keeps its wiring intact.
        get => _wrappingConnection ?? _inner.Connection;
        set
        {
            _wrappingConnection = value;
            _inner.Connection = value switch
            {
                AuditingDbConnection auditing => auditing.GetType()
                    .GetField("_inner", System.Reflection.BindingFlags.Instance | System.Reflection.BindingFlags.NonPublic)
                    !.GetValue(auditing) as DbConnection,
                _ => value
            };
        }
    }

    protected override DbParameterCollection DbParameterCollection => _inner.Parameters;

    protected override DbTransaction? DbTransaction
    {
        get => _inner.Transaction;
        set => _inner.Transaction = value;
    }

    public override void Cancel() => _inner.Cancel();

    public override void Prepare() => _inner.Prepare();

    protected override DbParameter CreateDbParameter() => _inner.CreateParameter();

    // -- Audited execution surface ---------------------------------------

    public override int ExecuteNonQuery()
    {
        var occurredAtUtc = DateTime.UtcNow;
        var startTicks = Stopwatch.GetTimestamp();
        int rows = 0;
        Exception? thrown = null;
        try
        {
            rows = _inner.ExecuteNonQuery();
            return rows;
        }
        catch (Exception ex)
        {
            thrown = ex;
            throw;
        }
        finally
        {
            EmitAudit(
                occurredAtUtc,
                ElapsedMs(startTicks),
                op: "write",
                rowsAffected: thrown == null ? rows : (int?)null,
                rowsReturned: null,
                thrown);
        }
    }

    public override object? ExecuteScalar()
    {
        var occurredAtUtc = DateTime.UtcNow;
        var startTicks = Stopwatch.GetTimestamp();
        object? scalar = null;
        Exception? thrown = null;
        try
        {
            scalar = _inner.ExecuteScalar();
            return scalar;
        }
        catch (Exception ex)
        {
            thrown = ex;
            throw;
        }
        finally
        {
            // ExecuteScalar is classified as "write" per the M4 vocabulary
            // lock — it's a single-value execution; rowsAffected mirrors the
            // inner command's value if exposed (DbCommand has no RecordsAffected
            // property, so we report -1 when the provider didn't surface it).
            EmitAudit(
                occurredAtUtc,
                ElapsedMs(startTicks),
                op: "write",
                rowsAffected: thrown == null ? -1 : (int?)null,
                rowsReturned: null,
                thrown);
        }
    }

    public override async Task<int> ExecuteNonQueryAsync(CancellationToken cancellationToken)
    {
        var occurredAtUtc = DateTime.UtcNow;
        var startTicks = Stopwatch.GetTimestamp();
        int rows = 0;
        Exception? thrown = null;
        try
        {
            rows = await _inner.ExecuteNonQueryAsync(cancellationToken).ConfigureAwait(false);
            return rows;
        }
        catch (Exception ex)
        {
            thrown = ex;
            throw;
        }
        finally
        {
            EmitAudit(
                occurredAtUtc,
                ElapsedMs(startTicks),
                op: "write",
                rowsAffected: thrown == null ? rows : (int?)null,
                rowsReturned: null,
                thrown);
        }
    }

    public override async Task<object?> ExecuteScalarAsync(CancellationToken cancellationToken)
    {
        var occurredAtUtc = DateTime.UtcNow;
        var startTicks = Stopwatch.GetTimestamp();
        object? scalar = null;
        Exception? thrown = null;
        try
        {
            scalar = await _inner.ExecuteScalarAsync(cancellationToken).ConfigureAwait(false);
            return scalar;
        }
        catch (Exception ex)
        {
            thrown = ex;
            throw;
        }
        finally
        {
            EmitAudit(
                occurredAtUtc,
                ElapsedMs(startTicks),
                op: "write",
                rowsAffected: thrown == null ? -1 : (int?)null,
                rowsReturned: null,
                thrown);
        }
    }

    protected override DbDataReader ExecuteDbDataReader(CommandBehavior behavior)
    {
        var occurredAtUtc = DateTime.UtcNow;
        var startTicks = Stopwatch.GetTimestamp();
        DbDataReader? reader = null;
        Exception? thrown = null;
        try
        {
            reader = _inner.ExecuteReader(behavior);
            return new AuditingDbDataReader(
                reader,
                onClose: rows => EmitAudit(
                    occurredAtUtc,
                    ElapsedMs(startTicks),
                    op: "read",
                    rowsAffected: null,
                    rowsReturned: rows,
                    thrown: null));
        }
        catch (Exception ex)
        {
            thrown = ex;
            // Emit the failure row immediately — no reader to wait on.
            EmitAudit(
                occurredAtUtc,
                ElapsedMs(startTicks),
                op: "read",
                rowsAffected: null,
                rowsReturned: null,
                thrown);
            throw;
        }
    }

    protected override async Task<DbDataReader> ExecuteDbDataReaderAsync(
        CommandBehavior behavior, CancellationToken cancellationToken)
    {
        var occurredAtUtc = DateTime.UtcNow;
        var startTicks = Stopwatch.GetTimestamp();
        DbDataReader? reader = null;
        Exception? thrown = null;
        try
        {
            reader = await _inner.ExecuteReaderAsync(behavior, cancellationToken).ConfigureAwait(false);
            return new AuditingDbDataReader(
                reader,
                onClose: rows => EmitAudit(
                    occurredAtUtc,
                    ElapsedMs(startTicks),
                    op: "read",
                    rowsAffected: null,
                    rowsReturned: rows,
                    thrown: null));
        }
        catch (Exception ex)
        {
            thrown = ex;
            EmitAudit(
                occurredAtUtc,
                ElapsedMs(startTicks),
                op: "read",
                rowsAffected: null,
                rowsReturned: null,
                thrown);
            throw;
        }
    }

    protected override void Dispose(bool disposing)
    {
        if (disposing)
        {
            _inner.Dispose();
        }
        base.Dispose(disposing);
    }

    // -- Emission ---------------------------------------------------------

    private static int ElapsedMs(long startTicks) =>
        (int)((Stopwatch.GetTimestamp() - startTicks) * 1000d / Stopwatch.Frequency);

    /// <summary>
    /// Best-effort emission of one <c>DbOutbound</c>/<c>DbWrite</c> audit row.
    /// Mirrors the M2 Bundle F <c>EmitCallAudit</c> 3-layer fail-safe pattern.
    /// </summary>
    private void EmitAudit(
        DateTime occurredAtUtc,
        int durationMs,
        string op,
        int? rowsAffected,
        int? rowsReturned,
        Exception? thrown)
    {
        AuditEvent evt;
        try
        {
            evt = BuildAuditEvent(occurredAtUtc, durationMs, op, rowsAffected, rowsReturned, thrown);
        }
        catch (Exception buildEx)
        {
            // Defensive: building the event from already-validated fields
            // shouldn't throw, but the alog.md §7 contract requires we never
            // propagate to the user-facing action regardless.
            _logger.LogWarning(buildEx,
                "Failed to build Audit Log #23 event for {Connection} (op={Op}) — skipping emission",
                _connectionName, op);
            return;
        }

        try
        {
            var writeTask = _auditWriter.WriteAsync(evt, CancellationToken.None);
            if (!writeTask.IsCompleted)
            {
                writeTask.ContinueWith(
                    t => _logger.LogWarning(t.Exception,
                        "Audit Log #23 write failed for EventId {EventId} ({Connection} op={Op})",
                        evt.EventId, _connectionName, op),
                    CancellationToken.None,
                    TaskContinuationOptions.OnlyOnFaulted | TaskContinuationOptions.ExecuteSynchronously,
                    TaskScheduler.Default);
            }
            else if (writeTask.IsFaulted)
            {
                _logger.LogWarning(writeTask.Exception,
                    "Audit Log #23 write failed for EventId {EventId} ({Connection} op={Op})",
                    evt.EventId, _connectionName, op);
            }
        }
        catch (Exception writeEx)
        {
            // Synchronous throw from WriteAsync before its own try/catch.
            // Swallow + log per alog.md §7.
            _logger.LogWarning(writeEx,
                "Audit Log #23 write threw synchronously for EventId {EventId} ({Connection} op={Op})",
                evt.EventId, _connectionName, op);
        }
    }

    private AuditEvent BuildAuditEvent(
        DateTime occurredAtUtc,
        int durationMs,
        string op,
        int? rowsAffected,
        int? rowsReturned,
        Exception? thrown)
    {
        var status = thrown == null ? AuditStatus.Delivered : AuditStatus.Failed;

        // Target = "<connectionName>.<first 60 chars of SQL>" so the audit
        // row carries a human-recognisable handle without dragging the full
        // (potentially huge) statement into the index column. The full
        // statement + parameter values live in RequestSummary.
        string target = _connectionName;
        var sqlSnippet = _inner.CommandText ?? string.Empty;
        if (sqlSnippet.Length > 0)
        {
            var snippet = sqlSnippet.Length > 60
                ? sqlSnippet[..60]
                : sqlSnippet;
            target = $"{_connectionName}.{snippet}";
        }

        // RequestSummary captures the SQL statement + parameter values by
        // default per the alog.md M4 acceptance criteria (M5 will add
        // per-connection redaction opt-in).
        string? requestSummary = BuildRequestSummary();

        // Extra carries the op discriminator + row count per the vocabulary
        // lock. Build as a small hand-rolled JSON object to avoid pulling
        // in System.Text.Json on the hot path.
        string extra = op == "write"
            ? $"{{\"op\":\"write\",\"rowsAffected\":{(rowsAffected ?? 0)}}}"
            : $"{{\"op\":\"read\",\"rowsReturned\":{(rowsReturned ?? 0)}}}";

        return new AuditEvent
        {
            EventId = Guid.NewGuid(),
            OccurredAtUtc = DateTime.SpecifyKind(occurredAtUtc, DateTimeKind.Utc),
            Channel = AuditChannel.DbOutbound,
            Kind = AuditKind.DbWrite,
            CorrelationId = null,
            SourceSiteId = string.IsNullOrEmpty(_siteId) ? null : _siteId,
            SourceInstanceId = _instanceName,
            SourceScript = _sourceScript,
            // Outbound channel: per the Audit Log Actor-column spec the actor is
            // the calling script. Null when no single script owns the call
            // (e.g. a shared script running inline).
            Actor = _sourceScript,
            Target = target,
            Status = status,
            HttpStatus = null,
            DurationMs = durationMs,
            ErrorMessage = thrown?.Message,
            ErrorDetail = thrown?.ToString(),
            RequestSummary = requestSummary,
            ResponseSummary = null,
            PayloadTruncated = false,
            Extra = extra,
            ForwardState = AuditForwardState.Pending,
        };
    }

    /// <summary>
    /// Compose a JSON request summary capturing the SQL statement and
    /// parameter values. Parameter values are captured by default per the
    /// M4 acceptance criteria — redaction is opt-in and deferred to M5.
    /// </summary>
    private string? BuildRequestSummary()
    {
        var sql = _inner.CommandText;
        if (string.IsNullOrEmpty(sql))
        {
            return null;
        }

        // Hand-roll the JSON so we don't pull in System.Text.Json for a
        // shape this small. Values are stringified with ToString() — fully
        // structured serialisation arrives with the redaction work in M5.
        var sb = new System.Text.StringBuilder(sql.Length + 64);
        sb.Append("{\"sql\":");
        AppendJsonString(sb, sql);

        if (_inner.Parameters.Count > 0)
        {
            sb.Append(",\"parameters\":{");
            var first = true;
            foreach (DbParameter p in _inner.Parameters)
            {
                if (!first) sb.Append(',');
                first = false;
                AppendJsonString(sb, p.ParameterName);
                sb.Append(':');
                if (p.Value is null || p.Value is DBNull)
                {
                    sb.Append("null");
                }
                else
                {
                    AppendJsonString(sb, p.Value.ToString() ?? string.Empty);
                }
            }
            sb.Append('}');
        }

        sb.Append('}');
        return sb.ToString();
    }

    private static void AppendJsonString(System.Text.StringBuilder sb, string value)
    {
        sb.Append('"');
        foreach (var ch in value)
        {
            switch (ch)
            {
                case '"': sb.Append("\\\""); break;
                case '\\': sb.Append("\\\\"); break;
                case '\b': sb.Append("\\b"); break;
                case '\f': sb.Append("\\f"); break;
                case '\n': sb.Append("\\n"); break;
                case '\r': sb.Append("\\r"); break;
                case '\t': sb.Append("\\t"); break;
                default:
                    if (ch < 0x20)
                    {
                        sb.Append("\\u").Append(((int)ch).ToString("x4"));
                    }
                    else
                    {
                        sb.Append(ch);
                    }
                    break;
            }
        }
        sb.Append('"');
    }
}