diff --git a/src/Packages/Audience/Runtime/AudienceError.cs b/src/Packages/Audience/Runtime/AudienceError.cs index c8da6704..dd6f0672 100644 --- a/src/Packages/Audience/Runtime/AudienceError.cs +++ b/src/Packages/Audience/Runtime/AudienceError.cs @@ -1,7 +1,46 @@ +#nullable enable + using System; +using System.Collections.Generic; namespace Immutable.Audience { + /// One validation failure the backend reported for a single message. + public sealed class RejectionError + { + /// Name of the offending field, or a message-level sentinel when no single field applies. + public string Field { get; } + + /// Machine-readable reason, e.g. INVALID_ENUM, MISSING_REQUIRED_FIELD. + public string Code { get; } + + /// Human-readable description. Not contractual; wording may change. + public string Message { get; } + + internal RejectionError(string field, string code, string message) + { + Field = field; + Code = code; + Message = message; + } + } + + /// A single message the backend rejected, with every reason it gave. + public sealed class MessageRejection + { + /// Echoes the client-supplied messageId verbatim. + public string MessageId { get; } + + /// Every violation reported for this message. + public IReadOnlyList Errors { get; } + + internal MessageRejection(string messageId, IReadOnlyList errors) + { + MessageId = messageId; + Errors = errors; + } + } + /// /// Categorises errors raised through . /// @@ -66,16 +105,25 @@ public class AudienceError : Exception /// public AudienceErrorCode Code { get; } + /// + /// Per-message rejection detail, when is + /// and the backend + /// reported one. + /// + public IReadOnlyList? Rejections { get; } + /// /// Wraps a code and message into an for /// delivery through . /// /// The reason for the failure. /// Human-readable description. - public AudienceError(AudienceErrorCode code, string message) + /// Per-message rejection detail, when the backend reported one. + public AudienceError(AudienceErrorCode code, string message, IReadOnlyList? rejections = null) : base(message) { Code = code; + Rejections = rejections; } } } diff --git a/src/Packages/Audience/Runtime/Transport/HttpTransport.cs b/src/Packages/Audience/Runtime/Transport/HttpTransport.cs index fa62d067..d93eed27 100644 --- a/src/Packages/Audience/Runtime/Transport/HttpTransport.cs +++ b/src/Packages/Audience/Runtime/Transport/HttpTransport.cs @@ -102,18 +102,23 @@ internal async Task SendBatchAsync(CancellationToken ct = default) if (statusCode >= 200 && statusCode < 300) { // Server accepted the batch. Count how many messages it - // rejected; if any, tell the studio via onError. Rejected - // messages are validation failures, so retrying won't help. - // The batch is deleted either way. - var rejected = await ParseRejectedCount(response, ct).ConfigureAwait(false); + // rejected; if any, log the detail and tell the studio via + // onError. Rejected messages are validation failures, so + // retrying won't help. The batch is deleted either way. + var (rejected, rejections) = await ParseRejectedResult(response, ct).ConfigureAwait(false); _store.Delete(batch); ResetBackoff(); - if (rejected > 0) + // rejected and rejections are parsed independently from the same body; + // fall back to rejections.Count so a body where they've drifted (e.g. + // rejected wasn't updated but rejections was) doesn't silently drop detail. + var rejectedCount = Math.Max(rejected, rejections?.Count ?? 0); + if (rejectedCount > 0) { + LogRejections(rejections); NotifyError(AudienceErrorCode.ValidationRejected, - $"Batch partially rejected: {rejected} of {batch.Count} events dropped"); + $"Batch partially rejected: {rejectedCount} of {batch.Count} events dropped", rejections); } - LogFlushOutcome(rejected == 0, batch.Count); + LogFlushOutcome(rejectedCount == 0, batch.Count); } else if (statusCode == 429) { @@ -137,10 +142,12 @@ internal async Task SendBatchAsync(CancellationToken ct = default) // publishable key", "missing field X", etc.) rather than a // bare status code. var rejectionBody = await ReadBodyForErrorAsync(response).ConfigureAwait(false); + var rejections = ExtractRejectionsFromBody(rejectionBody); _store.Delete(batch); ResetBackoff(); + LogRejections(rejections); NotifyError(AudienceErrorCode.ValidationRejected, - FormatHttpError("Batch rejected", statusCode, rejectionBody)); + FormatHttpError("Batch rejected", statusCode, rejectionBody), rejections); LogFlushOutcome(false, batch.Count); } else @@ -277,10 +284,12 @@ private void ResetBackoff() return sb.ToString(); } - // Reads the response body and pulls out the "rejected" count. Returns - // 0 if the body is missing or unreadable. The body is only for - // reporting, so failing to read it must not break the success path. - private static async Task ParseRejectedCount(HttpResponseMessage response, CancellationToken ct = default) + // Reads the response body and pulls out the rejected count and + // per-message rejection detail. Returns (0, null) if the body is + // missing or unreadable. The body is only for reporting, so failing + // to read it must not break the success path. + private static async Task<(int Rejected, IReadOnlyList? Rejections)> ParseRejectedResult( + HttpResponseMessage response, CancellationToken ct = default) { string body; try @@ -293,26 +302,91 @@ private static async Task ParseRejectedCount(HttpResponseMessage response, } catch (Exception ex) { - Log.Warn(AudienceLogs.ParseRejectedCountThrew(ex)); - return 0; + Log.Warn(AudienceLogs.ParseRejectedResultThrew(ex)); + return (0, null); } - if (string.IsNullOrEmpty(body)) return 0; + if (string.IsNullOrEmpty(body)) return (0, null); try { var parsed = JsonReader.DeserializeObject(body); - if (!parsed.TryGetValue("rejected", out var raw)) return 0; - return raw switch - { - int i => i, - long l => (int)l, - _ => 0, - }; + var rejected = parsed.TryGetValue("rejected", out var raw) + ? raw switch { int i => i, long l => (int)l, _ => 0 } + : 0; + return (rejected, ExtractRejections(parsed)); } catch (FormatException) { - return 0; + return (0, null); + } + } + + private static IReadOnlyList? ExtractRejectionsFromBody(string? body) + { + if (string.IsNullOrEmpty(body)) return null; + try + { + return ExtractRejections(JsonReader.DeserializeObject(body)); + } + catch (FormatException) + { + return null; + } + } + + // Best-effort: malformed entries are skipped rather than failing the whole parse. + private static List? ExtractRejections(Dictionary parsed) + { + if (!parsed.TryGetValue("rejections", out var raw) || raw is not List list || list.Count == 0) + return null; + + var result = new List(list.Count); + foreach (var item in list) + { + if (item is not Dictionary obj) continue; + if (!(obj.TryGetValue("messageId", out var midObj) && midObj is string messageId)) continue; + + var errors = new List(); + if (obj.TryGetValue("errors", out var errorsRaw) && errorsRaw is List errorList) + { + foreach (var errItem in errorList) + { + if (errItem is not Dictionary errObj) continue; + errors.Add(new RejectionError( + errObj.TryGetValue("field", out var f) ? f as string ?? "" : "", + errObj.TryGetValue("code", out var c) ? c as string ?? "" : "", + errObj.TryGetValue("message", out var m) ? m as string ?? "" : "")); + } + } + result.Add(new MessageRejection(messageId, errors)); + } + return result.Count > 0 ? result : null; + } + + // Fires unconditionally, independent of onError, so a rejection the SDK + // didn't catch client-side doesn't fail silently. Log.Error, not Warn: + // this is lost data, not an advisory. One call per batch, not one per + // rejected message: a batch can carry many rejections, and that many + // separate Debug.LogError calls would flood the Editor console (and + // fail an unsuspecting test via Unity's LogAssert). + private static void LogRejections(IReadOnlyList? rejections) + { + if (rejections == null || rejections.Count == 0) return; + + var detail = new StringBuilder(); + for (var i = 0; i < rejections.Count; i++) + { + var rejection = rejections[i]; + if (i > 0) detail.Append('\n'); + detail.Append(" ").Append(rejection.MessageId).Append(": "); + for (var j = 0; j < rejection.Errors.Count; j++) + { + if (j > 0) detail.Append("; "); + var e = rejection.Errors[j]; + detail.Append(e.Field).Append(' ').Append(e.Code).Append(": ").Append(e.Message); + } } + Log.Error(AudienceLogs.MessageRejectedByServer(rejections.Count, detail.ToString())); } // Best-effort body extraction; null on read failure. @@ -335,12 +409,12 @@ private static string FormatHttpError(string prefix, int statusCode, string? bod ? $"{prefix} with {statusCode}" : $"{prefix} with {statusCode}: {body}"; - private void NotifyError(AudienceErrorCode code, string message) + private void NotifyError(AudienceErrorCode code, string message, IReadOnlyList? rejections = null) { if (_onError == null) return; try { - _onError(new AudienceError(code, message)); + _onError(new AudienceError(code, message, rejections)); } catch (Exception ex) { diff --git a/src/Packages/Audience/Runtime/Unity/AudienceUnityHooks.cs b/src/Packages/Audience/Runtime/Unity/AudienceUnityHooks.cs index 2712c3d9..38710f9d 100644 --- a/src/Packages/Audience/Runtime/Unity/AudienceUnityHooks.cs +++ b/src/Packages/Audience/Runtime/Unity/AudienceUnityHooks.cs @@ -34,6 +34,7 @@ private static void Install() // Set before the collectors below run so a collector failure logs via Debug.Log, not Console.WriteLine. if (Log.Writer == null) Log.Writer = Debug.Log; + if (Log.ErrorWriter == null) Log.ErrorWriter = Debug.LogError; // Captured once on main thread; ReadOnlyDictionary blocks downstream mutation. // Each collector is isolated so one throwing can't block the other's provider or abort Install(). diff --git a/src/Packages/Audience/Runtime/Utility/Log.cs b/src/Packages/Audience/Runtime/Utility/Log.cs index 976f8627..eef021aa 100644 --- a/src/Packages/Audience/Runtime/Utility/Log.cs +++ b/src/Packages/Audience/Runtime/Utility/Log.cs @@ -13,26 +13,36 @@ internal static class Log // Tests set this to capture output; AudienceUnityHooks sets it to Debug.Log. internal static Action? Writer { get; set; } + // Separate from Writer so production wiring can route this to a real + // Debug.LogError (red Editor console entry, picked up by crash/error + // reporting integrations) while Writer stays on plain Debug.Log. + // Tests set this to capture output; AudienceUnityHooks sets it to Debug.LogError. + internal static Action? ErrorWriter { get; set; } + internal static void Debug(string message) { if (!Enabled) return; - Emit($"{Prefix} {message}"); + Emit(Writer, $"{Prefix} {message}"); } internal static void Warn(string message) => - Emit($"{Prefix} WARN: {message}"); + Emit(Writer, $"{Prefix} WARN: {message}"); + + // Fires unconditionally, independent of Enabled, like Warn. + internal static void Error(string message) => + Emit(ErrorWriter, $"{Prefix} ERROR: {message}"); - private static void Emit(string line) + private static void Emit(Action? writer, string line) { - // Swallow anything the Writer or Console throws so Log.Warn and - // Log.Debug never throw themselves. If they did, an exception from - // logging inside a catch block would reach the background timer - // and crash the game on modern .NET. + // Swallow anything the writer or Console throws so the Log methods + // never throw themselves. If they did, an exception from logging + // inside a catch block would reach the background timer and + // crash the game on modern .NET. try { - if (Writer != null) + if (writer != null) { - Writer(line); + writer(line); return; } Console.WriteLine(line); @@ -124,8 +134,11 @@ internal static string SendBatchUnexpected(Exception ex) => internal static string FlushOutcome(bool ok, int count) => $"flush {(ok ? "ok" : "failed")} ({count} messages)"; - internal static string ParseRejectedCountThrew(Exception ex) => - $"ParseRejectedCount threw {ex.GetType().Name}: {ex.Message}"; + internal static string ParseRejectedResultThrew(Exception ex) => + $"ParseRejectedResult threw {ex.GetType().Name}: {ex.Message}"; + + internal static string MessageRejectedByServer(int count, string detail) => + $"{count} message(s) rejected by the server:\n{detail}"; // ---- Session ---- diff --git a/src/Packages/Audience/Tests/Runtime/Transport/HttpTransportTests.cs b/src/Packages/Audience/Tests/Runtime/Transport/HttpTransportTests.cs index 6e662e3b..24c53d4c 100644 --- a/src/Packages/Audience/Tests/Runtime/Transport/HttpTransportTests.cs +++ b/src/Packages/Audience/Tests/Runtime/Transport/HttpTransportTests.cs @@ -324,6 +324,111 @@ public async Task SendBatchAsync_200_WithRejected_DeletesFilesAndSurfacesValidat StringAssert.Contains("1", reportedError.Message, "message should include the rejected count"); } + [Test] + public async Task SendBatchAsync_200_WithRejections_PopulatesAudienceErrorRejections() + { + _store.Write("{\"type\":\"track\",\"eventName\":\"a\"}"); + + var body = "{\"accepted\":0,\"rejected\":1,\"rejections\":[{\"messageId\":\"msg-1\"," + + "\"errors\":[{\"field\":\"surface\",\"code\":\"INVALID_ENUM\",\"message\":\"invalid surface\"}]}]}"; + var handler = new MockHandler(HttpStatusCode.OK, body); + AudienceError? reportedError = null; + using var transport = new HttpTransport(_store, "pk_imapik-test-key1", + onError: e => reportedError = e, handler: handler); + + await transport.SendBatchAsync(); + + Assert.IsNotNull(reportedError!.Rejections); + Assert.AreEqual(1, reportedError.Rejections!.Count); + Assert.AreEqual("msg-1", reportedError.Rejections[0].MessageId); + Assert.AreEqual("surface", reportedError.Rejections[0].Errors[0].Field); + Assert.AreEqual("INVALID_ENUM", reportedError.Rejections[0].Errors[0].Code); + } + + [Test] + public async Task SendBatchAsync_200_WithRejections_LogsOneAggregatedErrorIndependentOfOnError() + { + _store.Write("{\"type\":\"track\",\"eventName\":\"a\"}"); + _store.Write("{\"type\":\"track\",\"eventName\":\"b\"}"); + + var body = "{\"accepted\":0,\"rejected\":2,\"rejections\":[" + + "{\"messageId\":\"msg-1\",\"errors\":[{\"field\":\"surface\",\"code\":\"INVALID_ENUM\",\"message\":\"bad\"}]}," + + "{\"messageId\":\"msg-2\",\"errors\":[{\"field\":\"eventName\",\"code\":\"MISSING_REQUIRED_FIELD\",\"message\":\"req\"}]}]}"; + var handler = new MockHandler(HttpStatusCode.OK, body); + // No onError passed: the log must not depend on one being wired. + using var transport = new HttpTransport(_store, "pk_imapik-test-key1", handler: handler); + + var lines = new List(); + Log.ErrorWriter = lines.Add; + try + { + await transport.SendBatchAsync(); + } + finally + { + Log.ErrorWriter = null; + } + + Assert.AreEqual(1, lines.Count, "expected exactly one aggregated log call, not one per rejected message"); + Assert.That(lines[0], Does.Contain("2 message(s) rejected by the server")); + Assert.That(lines[0], Does.Contain("msg-1: surface INVALID_ENUM: bad")); + Assert.That(lines[0], Does.Contain("msg-2: eventName MISSING_REQUIRED_FIELD: req")); + } + + [Test] + public async Task SendBatchAsync_4xx_WithRejections_PopulatesAudienceErrorRejections() + { + _store.Write("{\"type\":\"track\"}"); + + var body = "{\"success\":false,\"accepted\":0,\"rejected\":1,\"rejections\":[{\"messageId\":\"msg-1\"," + + "\"errors\":[{\"field\":\"eventName\",\"code\":\"MISSING_REQUIRED_FIELD\",\"message\":\"required\"}]}]}"; + var handler = new MockHandler(HttpStatusCode.BadRequest, body); + AudienceError? reportedError = null; + using var transport = new HttpTransport(_store, "pk_imapik-test-key1", + onError: e => reportedError = e, handler: handler); + + await transport.SendBatchAsync(); + + Assert.IsNotNull(reportedError!.Rejections); + Assert.AreEqual("msg-1", reportedError.Rejections![0].MessageId); + } + + [Test] + public async Task SendBatchAsync_200_MalformedRejections_LeavesRejectionsNull() + { + _store.Write("{\"type\":\"track\",\"eventName\":\"a\"}"); + + var handler = new MockHandler(HttpStatusCode.OK, "{\"accepted\":0,\"rejected\":1,\"rejections\":\"not-an-array\"}"); + AudienceError? reportedError = null; + using var transport = new HttpTransport(_store, "pk_imapik-test-key1", + onError: e => reportedError = e, handler: handler); + + await transport.SendBatchAsync(); + + Assert.IsNull(reportedError!.Rejections); + } + + [Test] + public async Task SendBatchAsync_200_RejectionsPresentButRejectedCountZero_StillFiresOnError() + { + // Defends against rejected/rejections drifting apart in the response body: + // rejections must not be silently dropped just because the numeric count is 0. + _store.Write("{\"type\":\"track\",\"eventName\":\"a\"}"); + + var body = "{\"accepted\":1,\"rejected\":0,\"rejections\":[{\"messageId\":\"msg-1\"," + + "\"errors\":[{\"field\":\"surface\",\"code\":\"INVALID_ENUM\",\"message\":\"bad\"}]}]}"; + var handler = new MockHandler(HttpStatusCode.OK, body); + AudienceError? reportedError = null; + using var transport = new HttpTransport(_store, "pk_imapik-test-key1", + onError: e => reportedError = e, handler: handler); + + await transport.SendBatchAsync(); + + Assert.IsNotNull(reportedError, "a non-empty rejections array must fire onError even if rejected is 0"); + Assert.AreEqual(1, reportedError!.Rejections!.Count); + Assert.AreEqual("msg-1", reportedError.Rejections[0].MessageId); + } + [Test] public async Task SendBatchAsync_200_ZeroRejected_DoesNotFireOnError() { diff --git a/src/Packages/Audience/Tests/Runtime/Utility/LogTests.cs b/src/Packages/Audience/Tests/Runtime/Utility/LogTests.cs index 42a3cda0..afa196bb 100644 --- a/src/Packages/Audience/Tests/Runtime/Utility/LogTests.cs +++ b/src/Packages/Audience/Tests/Runtime/Utility/LogTests.cs @@ -7,12 +7,15 @@ namespace Immutable.Audience.Tests internal class LogTests { private List _captured; + private List _capturedErrors; [SetUp] public void SetUp() { _captured = new List(); + _capturedErrors = new List(); Log.Writer = line => _captured.Add(line); + Log.ErrorWriter = line => _capturedErrors.Add(line); Log.Enabled = false; } @@ -20,6 +23,7 @@ public void SetUp() public void TearDown() { Log.Writer = null; + Log.ErrorWriter = null; Log.Enabled = false; } @@ -56,5 +60,26 @@ public void Warn_AlwaysEmits_EvenWhenDisabled() StringAssert.Contains("WARN", _captured[0]); StringAssert.Contains("something off", _captured[0]); } + + [Test] + public void Error_AlwaysEmits_EvenWhenDisabled() + { + Log.Enabled = false; + + Log.Error("data lost"); + + Assert.AreEqual(1, _capturedErrors.Count); + StringAssert.Contains("ERROR", _capturedErrors[0]); + StringAssert.Contains("data lost", _capturedErrors[0]); + } + + [Test] + public void Error_UsesErrorWriter_NotWriter() + { + Log.Error("data lost"); + + Assert.AreEqual(0, _captured.Count, "Error must not go through Writer"); + Assert.AreEqual(1, _capturedErrors.Count); + } } }