v2 single-rail 12: first-session-fixes PR 4 — data completeness + operability (Fixes 4+5)

Closes the "final-status.json shows only 3 apps", "every app ~30 s" and "agent log silent during uploads" gaps observed in session 30410cd7. Fix 4c — Per-app install-lifecycle timing. New AppInstallTiming model (StartedAtUtc / CompletedAtUtc / DurationSeconds). ImeLogTrackerAdapter tracks timing in a set-once dictionary (first Downloading/Installing/ InProgress stamps StartedAt; first terminal stamps CompletedAt) and exposes it via a new public AppTimings snapshot. app_install_* DataJson carries startedAt / completedAt / durationSeconds when known; omitted otherwise so the UI can distinguish "not tracked" from "stamp=epoch". Fix 4a — FinalStatusBuilder uses timings. Optional appTimings param on Build(); FinalStatusPackageInfo gets StartedAt / CompletedAt / DurationSeconds with NullValueHandling.Ignore. Existing per-targeted phase bucketing preserved — that was correct. Fix 4b — app_tracking_summary terminal event. EnrollmentTerminationHandler. EmitAppTrackingSummary runs once at termination before diagnostics upload with aggregate counts, per-phase breakdown, and per-app records (appId/name/phase/finalState/optional timing). ImmediateUpload=true, Phase=Unknown (feedback_phase_strategy). Skipped on WhiteGlove Part 1 (apps haven't installed yet). Fix 5 — Upload-cadence logging. BackendTelemetryUploader + TelemetrySpool gained optional AgentLogger params. Uploader logs INFO flushing/ingest OK, WARN ingest TRANSIENT (5xx/timeout/network), ERROR ingest PERMANENT (4xx), with items + durationMs. Spool logs DEBUG per-enqueue with kind + immediate flag + pending count. Empty-batch path stays silent (short-circuit). Plumbing: ImeLogHost.AppTimings → DefaultComponentFactory.ImeAppTimings → Program.cs wires appTimingsAccessor into EnrollmentTerminationHandler; logger flows into uploader (Program.cs) and spool (EnrollmentOrchestrator). All new ctor params are nullable-default → zero breakage for existing call sites and tests. Tests: +18 new (7 adapter timing, 2 builder timing, 5 handler summary, 4 uploader logging). DecisionCore 139, Agent.V2.Core 630, Functions 727, Web vitest 168 — all green. Web typecheck clean. Solution build 0/0. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
2026-10-24 12:42:38 +00:00 · 2026-04-24 02:24:04 +02:00
parent 017c7ca1cd
commit 8fe75a0f4e
17 changed files with 892 additions and 20 deletions
@@ -0,0 +1,188 @@
+using System;
+using System.Collections.Generic;
+using System.Globalization;
+using System.Linq;
+using AutopilotMonitor.Agent.V2.Core.Logging;
+using AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime;
+using AutopilotMonitor.Agent.V2.Core.SignalAdapters;
+using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
+using AutopilotMonitor.Agent.V2.Core.Tests.Orchestration;
+using AutopilotMonitor.DecisionCore.Engine;
+using AutopilotMonitor.DecisionCore.Signals;
+using AutopilotMonitor.Shared.Models;
+using SharedEventTypes = AutopilotMonitor.Shared.Constants.EventTypes;
+using Xunit;
+
+namespace AutopilotMonitor.Agent.V2.Core.Tests.SignalAdapters
+{
+    /// <summary>
+    /// Plan §5 Fix 4c — adapter tracks per-app install-lifecycle timing and surfaces it on
+    /// <c>app_install_*</c> event DataJson (<c>startedAt</c> / <c>completedAt</c> /
+    /// <c>durationSeconds</c>) + via the new <see cref="ImeLogTrackerAdapter.AppTimings"/>
+    /// snapshot for downstream consumers (FinalStatusBuilder, app_tracking_summary).
+    /// </summary>
+    public sealed class ImeLogTrackerAdapterTimingTests
+    {
+        private static readonly DateTime T0 = new DateTime(2026, 4, 24, 10, 0, 0, DateTimeKind.Utc);
+
+        private sealed class Fixture : IDisposable
+        {
+            public TempDirectory Tmp { get; } = new TempDirectory();
+            public AgentLogger Logger { get; }
+            public ImeLogTracker Tracker { get; }
+            public FakeSignalIngressSink Ingress { get; } = new FakeSignalIngressSink();
+            public VirtualClock Clock { get; } = new VirtualClock(T0);
+
+            public Fixture()
+            {
+                Logger = new AgentLogger(Tmp.Path, AgentLogLevel.Info);
+                Tracker = new ImeLogTracker(
+                    logFolder: Tmp.Path,
+                    patterns: new List<ImeLogPattern>(),
+                    logger: Logger);
+            }
+
+            public FakeSignalIngressSink.PostedSignal InfoEvent(string eventType) =>
+                Ingress.Posted.Single(p =>
+                    p.Kind == DecisionSignalKind.InformationalEvent
+                    && p.Payload != null
+                    && p.Payload.TryGetValue(SignalPayloadKeys.EventType, out var et)
+                    && et == eventType);
+
+            public void Dispose()
+            {
+                Tracker.Dispose();
+                Tmp.Dispose();
+            }
+        }
+
+        [Fact]
+        public void First_Installing_transition_stamps_StartedAt_on_adapter_and_payload()
+        {
+            using var f = new Fixture();
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+            var app = new AppPackageState("app-A", 0);
+
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Installing);
+
+            var info = f.InfoEvent(SharedEventTypes.AppInstallStart);
+            Assert.Equal(T0.ToString("o"), info.Payload!["startedAt"]);
+            Assert.False(info.Payload.ContainsKey("completedAt"));
+            Assert.False(info.Payload.ContainsKey("durationSeconds"));
+
+            Assert.True(adapter.AppTimings.ContainsKey("app-A"));
+            Assert.Equal(T0, adapter.AppTimings["app-A"].StartedAtUtc);
+            Assert.Null(adapter.AppTimings["app-A"].CompletedAtUtc);
+        }
+
+        [Fact]
+        public void Downloading_transition_also_stamps_StartedAt()
+        {
+            using var f = new Fixture();
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+            var app = new AppPackageState("app-D", 0);
+
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Downloading);
+
+            Assert.Equal(T0, adapter.AppTimings["app-D"].StartedAtUtc);
+            var info = f.InfoEvent(SharedEventTypes.AppDownloadStarted);
+            Assert.Equal(T0.ToString("o"), info.Payload!["startedAt"]);
+        }
+
+        [Fact]
+        public void Terminal_transition_stamps_CompletedAt_and_emits_DurationSeconds()
+        {
+            using var f = new Fixture();
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+            var app = new AppPackageState("app-T", 0);
+
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Installing);
+            f.Clock.Advance(TimeSpan.FromSeconds(42.5));
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Installing, AppInstallationState.Installed);
+
+            var completeEvent = f.InfoEvent(SharedEventTypes.AppInstallComplete);
+            Assert.Equal(T0.ToString("o"), completeEvent.Payload!["startedAt"]);
+            Assert.Equal(T0.AddSeconds(42.5).ToString("o"), completeEvent.Payload["completedAt"]);
+            Assert.Equal("42.50", completeEvent.Payload["durationSeconds"]);
+
+            var timing = adapter.AppTimings["app-T"];
+            Assert.Equal(T0, timing.StartedAtUtc);
+            Assert.Equal(T0.AddSeconds(42.5), timing.CompletedAtUtc);
+            Assert.Equal(42.5, timing.DurationSeconds);
+        }
+
+        [Fact]
+        public void Error_transition_also_sets_CompletedAt()
+        {
+            using var f = new Fixture();
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+            var app = new AppPackageState("app-E", 0);
+
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Installing);
+            f.Clock.Advance(TimeSpan.FromSeconds(3));
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Installing, AppInstallationState.Error);
+
+            var failedEvent = f.InfoEvent(SharedEventTypes.AppInstallFailed);
+            Assert.Equal("3.00", failedEvent.Payload!["durationSeconds"]);
+            Assert.NotNull(adapter.AppTimings["app-E"].CompletedAtUtc);
+        }
+
+        [Fact]
+        public void Timing_is_set_once_not_overwritten_by_subsequent_same_state_events()
+        {
+            using var f = new Fixture();
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+            var app = new AppPackageState("app-Z", 0);
+
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Installing);
+            f.Clock.Advance(TimeSpan.FromSeconds(10));
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Installing, AppInstallationState.Installing);
+            f.Clock.Advance(TimeSpan.FromSeconds(5));
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Installing, AppInstallationState.Installed);
+
+            var timing = adapter.AppTimings["app-Z"];
+            // StartedAt = first Installing (T0), NOT the second one.
+            Assert.Equal(T0, timing.StartedAtUtc);
+            // CompletedAt = Installed stamp (T0 + 15s).
+            Assert.Equal(T0.AddSeconds(15), timing.CompletedAtUtc);
+        }
+
+        [Fact]
+        public void AppTimings_snapshot_is_an_independent_copy()
+        {
+            using var f = new Fixture();
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+            adapter.TriggerAppStateFromTest(new AppPackageState("a", 0),
+                AppInstallationState.Unknown, AppInstallationState.Installing);
+
+            var snap1 = adapter.AppTimings;
+
+            f.Clock.Advance(TimeSpan.FromSeconds(5));
+            adapter.TriggerAppStateFromTest(new AppPackageState("a", 0),
+                AppInstallationState.Installing, AppInstallationState.Installed);
+
+            // snap1 captured before terminal — CompletedAt must still be null.
+            Assert.Null(snap1["a"].CompletedAtUtc);
+            // Fresh snap reflects the terminal stamp.
+            Assert.NotNull(adapter.AppTimings["a"].CompletedAtUtc);
+        }
+
+        [Fact]
+        public void DownloadProgress_tick_does_not_regress_StartedAt()
+        {
+            // Fix 1 policy: download_progress is ImmediateUpload=true. Fix 4c must not let a
+            // mid-download progress tick rewrite the earlier Downloading-start stamp.
+            using var f = new Fixture();
+            using var adapter = new ImeLogTrackerAdapter(f.Tracker, f.Ingress, f.Clock);
+            var app = new AppPackageState("app-P", 0);
+
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Unknown, AppInstallationState.Downloading);
+            var firstStamp = adapter.AppTimings["app-P"].StartedAtUtc;
+
+            f.Clock.Advance(TimeSpan.FromSeconds(9));
+            adapter.TriggerAppStateFromTest(app, AppInstallationState.Downloading, AppInstallationState.Downloading);
+
+            Assert.Equal(firstStamp, adapter.AppTimings["app-P"].StartedAtUtc);
+        }
+    }
+}
@@ -126,6 +126,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
                };
            }

+            public IReadOnlyDictionary<string, AppInstallTiming>? AppTimingsOverride { get; set; }
+
            public EnrollmentTerminationHandler Build(AgentConfiguration? config = null)
            {
                config ??= BuildConfig();
@@ -156,7 +158,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
                    // Zero out the timing ceremony for tests — production paths are covered by
                    // the dedicated V1-parity tests below which opt back in via their own Rig.
                    lateEventGracePeriod: TimeSpan.Zero,
-                    spoolDrainPeriod: TimeSpan.Zero);
+                    spoolDrainPeriod: TimeSpan.Zero,
+                    appTimingsAccessor: () => AppTimingsOverride ?? new Dictionary<string, AppInstallTiming>());
            }

            public void Dispose() => Tmp.Dispose();
@@ -436,5 +439,141 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
            Assert.Equal(0, rig.CleanupService.Invocations);
            Assert.DoesNotContain(Constants.EventTypes.AgentShuttingDown, rig.EmittedEventTypes);
        }
+
+        // ============================================================================
+        // Plan §5 Fix 4b — app_tracking_summary event
+        // ============================================================================
+
+        /// <summary>Reflection helper: AppPackageState.Targeted has a private setter.</summary>
+        private static void SetTargeted(AppPackageState pkg, AppTargeted t) =>
+            typeof(AppPackageState).GetProperty(nameof(AppPackageState.Targeted))!.SetValue(pkg, t);
+
+        [Fact]
+        public void Handle_emits_app_tracking_summary_with_counts_and_per_phase_breakdown()
+        {
+            using var rig = new Rig();
+            rig.State = new DecisionStateBuilder(DecisionState.CreateInitial("S1", "T1")) { Stage = SessionStage.Completed }.Build();
+
+            // AppPackageState.UpdateState has an inverse-detection guard: Installed without a
+            // prior DownloadingOrInstallingSeen=true flip is rewritten to Skipped. Seed the
+            // lifecycle via Installing first so the terminal state sticks.
+            var installed = new AppPackageState("app-installed", 0);
+            installed.UpdateState(AppInstallationState.Installing);
+            installed.UpdateState(AppInstallationState.Installed);
+            SetTargeted(installed, AppTargeted.Device);
+            rig.Packages.Add(installed);
+
+            var failed = new AppPackageState("app-failed", 1);
+            failed.UpdateState(AppInstallationState.Error);
+            SetTargeted(failed, AppTargeted.User);
+            rig.Packages.Add(failed);
+
+            var skipped = new AppPackageState("app-skipped", 2);
+            skipped.UpdateState(AppInstallationState.Skipped);
+            SetTargeted(skipped, AppTargeted.User);
+            rig.Packages.Add(skipped);
+
+            rig.Build().Handle(sender: null!,
+                Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed));
+
+            Assert.Contains(Constants.EventTypes.AppTrackingSummary, rig.EmittedEventTypes);
+
+            var data = rig.DataOf(Constants.EventTypes.AppTrackingSummary);
+            Assert.NotNull(data);
+            Assert.Equal(3, Convert.ToInt32(data!["totalApps"]));
+            Assert.Equal(3, Convert.ToInt32(data["completedApps"]));
+            Assert.Equal(1, Convert.ToInt32(data["installedApps"]));
+            Assert.Equal(1, Convert.ToInt32(data["skippedApps"]));
+            Assert.Equal(1, Convert.ToInt32(data["failedApps"]));
+
+            var byPhase = (IReadOnlyDictionary<string, Dictionary<string, int>>)data["byPhase"];
+            Assert.Equal(1, byPhase["Device"]["total"]);
+            Assert.Equal(2, byPhase["User"]["total"]);
+            Assert.Equal(1, byPhase["User"]["failed"]);
+            Assert.Equal(1, byPhase["User"]["skipped"]);
+        }
+
+        [Fact]
+        public void Handle_app_tracking_summary_includes_per_app_timing_when_provided()
+        {
+            using var rig = new Rig();
+            rig.State = new DecisionStateBuilder(DecisionState.CreateInitial("S1", "T1")) { Stage = SessionStage.Completed }.Build();
+
+            var app = new AppPackageState("app-1", 0);
+            app.UpdateState(AppInstallationState.Installing);
+            app.UpdateState(AppInstallationState.Installed);
+            SetTargeted(app, AppTargeted.Device);
+            rig.Packages.Add(app);
+
+            rig.AppTimingsOverride = new Dictionary<string, AppInstallTiming>
+            {
+                ["app-1"] = new AppInstallTiming(StartUtc.AddSeconds(30), StartUtc.AddSeconds(90)),
+            };
+
+            rig.Build().Handle(sender: null!,
+                Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed));
+
+            var data = rig.DataOf(Constants.EventTypes.AppTrackingSummary);
+            Assert.NotNull(data);
+            var perApp = (List<Dictionary<string, object>>)data!["perApp"];
+            var entry = Assert.Single(perApp);
+            Assert.Equal("app-1", entry["appId"]);
+            Assert.Equal("Device", entry["phase"]);
+            Assert.Equal("Installed", entry["finalState"]);
+            Assert.Equal(StartUtc.AddSeconds(30).ToString("o"), entry["startedAt"]);
+            Assert.Equal(StartUtc.AddSeconds(90).ToString("o"), entry["completedAt"]);
+            Assert.Equal(60.0, Convert.ToDouble(entry["durationSeconds"]));
+        }
+
+        [Fact]
+        public void Handle_app_tracking_summary_omits_timing_when_adapter_has_none()
+        {
+            using var rig = new Rig();
+            rig.State = new DecisionStateBuilder(DecisionState.CreateInitial("S1", "T1")) { Stage = SessionStage.Completed }.Build();
+
+            var app = new AppPackageState("untimed", 0);
+            app.UpdateState(AppInstallationState.Installing);
+            app.UpdateState(AppInstallationState.Installed);
+            SetTargeted(app, AppTargeted.Device);
+            rig.Packages.Add(app);
+
+            rig.Build().Handle(sender: null!,
+                Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed));
+
+            var data = rig.DataOf(Constants.EventTypes.AppTrackingSummary);
+            var perApp = (List<Dictionary<string, object>>)data!["perApp"];
+            var entry = Assert.Single(perApp);
+            Assert.False(entry.ContainsKey("startedAt"));
+            Assert.False(entry.ContainsKey("completedAt"));
+            Assert.False(entry.ContainsKey("durationSeconds"));
+        }
+
+        [Fact]
+        public void Handle_does_not_emit_app_tracking_summary_on_whiteglove_part1_exit()
+        {
+            // Part 1 runs pre-provisioning — no apps have installed yet; the summary event
+            // would be vacuous and misleading.
+            using var rig = new Rig();
+            rig.State = new DecisionStateBuilder(DecisionState.CreateInitial("S1", "T1")) { Stage = SessionStage.WhiteGloveSealed }.Build();
+
+            rig.Build().Handle(sender: null!,
+                Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.WhiteGloveSealed));
+
+            Assert.DoesNotContain(Constants.EventTypes.AppTrackingSummary, rig.EmittedEventTypes);
+        }
+
+        [Fact]
+        public void Handle_app_tracking_summary_marked_immediate_upload()
+        {
+            using var rig = new Rig();
+            rig.State = new DecisionStateBuilder(DecisionState.CreateInitial("S1", "T1")) { Stage = SessionStage.Completed }.Build();
+
+            rig.Build().Handle(sender: null!,
+                Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed));
+
+            var payload = rig.PayloadOf(Constants.EventTypes.AppTrackingSummary);
+            Assert.NotNull(payload);
+            Assert.Equal("true", payload![SignalPayloadKeys.ImmediateUpload]);
+        }
    }
 }
@@ -172,6 +172,74 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Termination
            Assert.Single(status.PackageStatesByPhase["User"]);
        }

+        [Fact]
+        public void Build_includes_per_app_timing_when_app_timings_provided()
+        {
+            // Plan §5 Fix 4a — FinalStatusBuilder surfaces StartedAt / CompletedAt /
+            // DurationSeconds on per-app package rows when the adapter's timing snapshot is
+            // available. Null snapshot → timing fields stay null (dialog distinguishes the two).
+            using var tmp = new TempDirectory();
+            var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
+            var list = new AppPackageStateList(logger);
+            var installed = new AppPackageState("app-timed", 0);
+            installed.UpdateState(AppInstallationState.Installed);
+            TestHelpers.SetTargeted(installed, AppTargeted.Device);
+            list.Add(installed);
+            var untimed = new AppPackageState("app-untimed", 1);
+            untimed.UpdateState(AppInstallationState.Installed);
+            TestHelpers.SetTargeted(untimed, AppTargeted.Device);
+            list.Add(untimed);
+
+            var timings = new System.Collections.Generic.Dictionary<string, AppInstallTiming>
+            {
+                ["app-timed"] = new AppInstallTiming(StartUtc.AddMinutes(2), StartUtc.AddMinutes(3)),
+                // app-untimed intentionally absent — builder should omit fields
+            };
+
+            var status = FinalStatusBuilder.Build(
+                StateWith(SessionStage.Completed),
+                Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed),
+                packageStates: list,
+                agentStartTimeUtc: StartUtc,
+                appTimings: timings);
+
+            var timedInfo = status.PackageStatesByPhase["Device"].Single(p => p.AppName == "app-timed");
+            Assert.Equal(StartUtc.AddMinutes(2).ToString("o"), timedInfo.StartedAt);
+            Assert.Equal(StartUtc.AddMinutes(3).ToString("o"), timedInfo.CompletedAt);
+            Assert.Equal(60.0, timedInfo.DurationSeconds);
+
+            var untimedInfo = status.PackageStatesByPhase["Device"].Single(p => p.AppName == "app-untimed");
+            Assert.Null(untimedInfo.StartedAt);
+            Assert.Null(untimedInfo.CompletedAt);
+            Assert.Null(untimedInfo.DurationSeconds);
+        }
+
+        [Fact]
+        public void Build_with_null_app_timings_still_produces_package_states()
+        {
+            // Backward-compat: when appTimings is not passed (older call sites / tests), the
+            // builder uses an empty timing map and the timing fields stay null on every row.
+            using var tmp = new TempDirectory();
+            var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
+            var list = new AppPackageStateList(logger);
+            var app = new AppPackageState("a", 0);
+            app.UpdateState(AppInstallationState.Installed);
+            TestHelpers.SetTargeted(app, AppTargeted.Device);
+            list.Add(app);
+
+            var status = FinalStatusBuilder.Build(
+                StateWith(SessionStage.Completed),
+                Args(EnrollmentTerminationReason.DecisionTerminalStage, EnrollmentTerminationOutcome.Succeeded, SessionStage.Completed),
+                packageStates: list,
+                agentStartTimeUtc: StartUtc,
+                appTimings: null);
+
+            var info = status.PackageStatesByPhase["Device"].Single();
+            Assert.Null(info.StartedAt);
+            Assert.Null(info.CompletedAt);
+            Assert.Null(info.DurationSeconds);
+        }
+
        [Fact]
        public void Build_serializes_to_json_with_expected_property_names()
        {
@@ -0,0 +1,151 @@
+using System;
+using System.IO;
+using System.Net;
+using System.Net.Http;
+using System.Threading;
+using System.Threading.Tasks;
+using AutopilotMonitor.Agent.V2.Core.Logging;
+using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
+using AutopilotMonitor.Agent.V2.Core.Transport.Telemetry;
+using Xunit;
+
+namespace AutopilotMonitor.Agent.V2.Core.Tests.Transport
+{
+    /// <summary>
+    /// Plan §5 Fix 5 — <see cref="BackendTelemetryUploader"/> emits upload-cadence log lines
+    /// (flushing / ingest OK / ingest TRANSIENT / ingest PERMANENT) so the agent log is no
+    /// longer silent during the transport path. We assert on log-file content because the
+    /// AgentLogger writes to disk; checking the file is the most faithful production proxy.
+    /// </summary>
+    public sealed class BackendTelemetryUploaderLoggingTests
+    {
+        private static readonly DateTime At = new DateTime(2026, 4, 24, 10, 0, 0, DateTimeKind.Utc);
+
+        private static TelemetryItem NewEventItem(long id) =>
+            new TelemetryItem(
+                kind: TelemetryItemKind.Event,
+                partitionKey: "T1_S1",
+                rowKey: id.ToString("D10"),
+                telemetryItemId: id,
+                sessionTraceOrdinal: id,
+                payloadJson: $"{{\"EventType\":\"test\",\"Sequence\":{id}}}",
+                requiresImmediateFlush: false,
+                enqueuedAtUtc: At);
+
+        private static string ReadLogs(string path)
+        {
+            // AgentLogger writes to a dated file; scan the whole dir to stay robust to format.
+            var sb = new System.Text.StringBuilder();
+            foreach (var f in Directory.EnumerateFiles(path, "*.log", SearchOption.AllDirectories))
+            {
+                try
+                {
+                    // Opened with ReadWrite share so we don't collide with an in-flight logger.
+                    using var fs = new FileStream(f, FileMode.Open, FileAccess.Read, FileShare.ReadWrite);
+                    using var reader = new StreamReader(fs);
+                    sb.AppendLine(reader.ReadToEnd());
+                }
+                catch { /* best-effort */ }
+            }
+            return sb.ToString();
+        }
+
+        [Fact]
+        public async Task UploadBatch_logs_flush_start_and_ingest_OK_on_success()
+        {
+            using var tmp = new TempDirectory();
+            var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
+
+            var handler = new RecordingHttpMessageHandler();
+            handler.QueueStatus(HttpStatusCode.OK);
+            using var http = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(30) };
+
+            var sut = new BackendTelemetryUploader(
+                httpClient: http,
+                baseUrl: "https://backend.test",
+                tenantId: "T1",
+                logger: logger);
+
+            var result = await sut.UploadBatchAsync(new[] { NewEventItem(1), NewEventItem(2) }, CancellationToken.None);
+            Assert.True(result.Success);
+
+            // AgentLogger writes each line with File.AppendAllText — content is already on disk.
+            var logContent = ReadLogs(tmp.Path);
+            Assert.Contains("BackendTelemetryUploader: flushing 2 item(s)", logContent);
+            Assert.Contains("BackendTelemetryUploader: ingest OK (items=2", logContent);
+        }
+
+        [Fact]
+        public async Task UploadBatch_logs_TRANSIENT_on_5xx()
+        {
+            using var tmp = new TempDirectory();
+            var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
+
+            var handler = new RecordingHttpMessageHandler();
+            handler.QueueStatus(HttpStatusCode.InternalServerError);
+            using var http = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(30) };
+
+            var sut = new BackendTelemetryUploader(
+                httpClient: http,
+                baseUrl: "https://backend.test",
+                tenantId: "T1",
+                logger: logger);
+
+            var result = await sut.UploadBatchAsync(new[] { NewEventItem(1) }, CancellationToken.None);
+            Assert.False(result.Success);
+            Assert.True(result.IsTransient);
+
+            var logContent = ReadLogs(tmp.Path);
+            Assert.Contains("BackendTelemetryUploader: ingest TRANSIENT", logContent);
+        }
+
+        [Fact]
+        public async Task UploadBatch_logs_PERMANENT_on_4xx()
+        {
+            using var tmp = new TempDirectory();
+            var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
+
+            var handler = new RecordingHttpMessageHandler();
+            handler.QueueStatus(HttpStatusCode.BadRequest);
+            using var http = new HttpClient(handler) { Timeout = TimeSpan.FromSeconds(30) };
+
+            var sut = new BackendTelemetryUploader(
+                httpClient: http,
+                baseUrl: "https://backend.test",
+                tenantId: "T1",
+                logger: logger);
+
+            var result = await sut.UploadBatchAsync(new[] { NewEventItem(1) }, CancellationToken.None);
+            Assert.False(result.Success);
+            Assert.False(result.IsTransient);
+
+            var logContent = ReadLogs(tmp.Path);
+            Assert.Contains("BackendTelemetryUploader: ingest PERMANENT", logContent);
+        }
+
+        [Fact]
+        public async Task UploadBatch_empty_batch_no_log_no_network()
+        {
+            // Short-circuit empty batch must not burn a log line or an HTTP call.
+            using var tmp = new TempDirectory();
+            var logger = new AgentLogger(tmp.Path, AgentLogLevel.Info);
+
+            var handler = new RecordingHttpMessageHandler();
+            using var http = new HttpClient(handler);
+
+            var sut = new BackendTelemetryUploader(
+                httpClient: http,
+                baseUrl: "https://backend.test",
+                tenantId: "T1",
+                logger: logger);
+
+            var result = await sut.UploadBatchAsync(Array.Empty<TelemetryItem>(), CancellationToken.None);
+            Assert.True(result.Success);
+            Assert.Empty(handler.Captured);
+
+            var logContent = ReadLogs(tmp.Path);
+            Assert.DoesNotContain("flushing", logContent);
+            Assert.DoesNotContain("ingest", logContent);
+        }
+    }
+}
@@ -0,0 +1,40 @@
+#nullable enable
+using System;
+
+namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime
+{
+    /// <summary>
+    /// Per-app install-lifecycle timestamps captured by <see cref="SignalAdapters.ImeLogTrackerAdapter"/>.
+    /// Plan §5 Fix 4 — powers the <c>StartedAt</c> / <c>CompletedAt</c> / <c>DurationSeconds</c>
+    /// fields on <c>app_install_*</c> events, the <c>FinalStatusPackageInfo</c> timing rows, and
+    /// the <c>app_tracking_summary</c> terminal event.
+    /// <para>
+    /// <b>StartedAtUtc</b> is recorded on the first lifecycle transition into Downloading /
+    /// Installing / InProgress. <b>CompletedAtUtc</b> is recorded on the first transition to a
+    /// terminal state (Installed / Skipped / Postponed / Error). Both are "set-once" — subsequent
+    /// identical-state events do not overwrite an earlier stamp.
+    /// </para>
+    /// </summary>
+    public sealed class AppInstallTiming
+    {
+        public AppInstallTiming(DateTime? startedAtUtc, DateTime? completedAtUtc)
+        {
+            StartedAtUtc = startedAtUtc;
+            CompletedAtUtc = completedAtUtc;
+        }
+
+        public DateTime? StartedAtUtc { get; }
+
+        public DateTime? CompletedAtUtc { get; }
+
+        /// <summary>
+        /// Elapsed time from first Downloading/Installing transition to terminal state, in
+        /// seconds. <c>null</c> when either endpoint is missing (e.g. app still installing,
+        /// or the adapter missed the start event because it came online mid-install).
+        /// </summary>
+        public double? DurationSeconds =>
+            StartedAtUtc.HasValue && CompletedAtUtc.HasValue
+                ? (CompletedAtUtc.Value - StartedAtUtc.Value).TotalSeconds
+                : (double?)null;
+    }
+}
@@ -73,6 +73,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
        /// </summary>
        public Monitoring.Enrollment.Ime.AppPackageStateList? ImePackageStates => _imeLogHost?.PackageStates;

+        /// <summary>
+        /// Plan §5 Fix 4c — per-app install-lifecycle timings (StartedAt / CompletedAt /
+        /// DurationSeconds) captured by <c>ImeLogTrackerAdapter</c>. Returns <c>null</c> before
+        /// <see cref="CreateCollectorHosts"/> has been called (Orchestrator start order).
+        /// </summary>
+        public System.Collections.Generic.IReadOnlyDictionary<string, Monitoring.Enrollment.Ime.AppInstallTiming>? ImeAppTimings => _imeLogHost?.AppTimings;
+
        public DefaultComponentFactory(
            AgentConfiguration agentConfig,
            AgentConfigResponse remoteConfig,
@@ -502,6 +509,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
            /// </summary>
            public Monitoring.Enrollment.Ime.AppPackageStateList PackageStates => _tracker.PackageStates;

+            /// <summary>
+            /// Plan §5 Fix 4c — per-app install-lifecycle timings captured by the adapter,
+            /// read-only snapshot. Consumed by <c>FinalStatusBuilder</c> (adds StartedAt/
+            /// CompletedAt/DurationSeconds rows) and by the <c>app_tracking_summary</c>
+            /// emission in <c>EnrollmentTerminationHandler</c>.
+            /// </summary>
+            public System.Collections.Generic.IReadOnlyDictionary<string, Monitoring.Enrollment.Ime.AppInstallTiming> AppTimings => _adapter.AppTimings;
+
            /// <summary>
            /// Reference to the wrapped IME tracker for co-collector wiring. Used by
            /// <c>DeliveryOptimizationHost</c> to set <c>OnDoTelemetryReceived</c> and to chain
@@ -313,7 +313,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
            }

            // 3) Telemetry-Transport.
-            _spool = new TelemetrySpool(_transportDirectory, _clock);
+            _spool = new TelemetrySpool(_transportDirectory, _clock, _logger);
            _transport = new TelemetryUploadOrchestrator(_spool, _uploader, _clock);

            // 4) Event-Emitter-Kette. Single-rail (Plan §5.10): der TelemetryEventEmitter wird
@@ -88,6 +88,14 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
        // AppsDevice once, "AccountSetup" -> AppsUser once).
        private readonly HashSet<string> _subPhaseDeclarationsEmitted = new HashSet<string>(StringComparer.Ordinal);

+        // Plan §5 Fix 4c — per-app install-lifecycle timing captured from state transitions.
+        // StartedAtUtc on first Downloading/Installing/InProgress transition (set-once);
+        // CompletedAtUtc on first terminal transition (Installed/Skipped/Postponed/Error).
+        // Surfaced via <see cref="AppTimings"/> to peripheral consumers (FinalStatusBuilder,
+        // app_tracking_summary emission in EnrollmentTerminationHandler).
+        private readonly Dictionary<string, (DateTime? Started, DateTime? Completed)> _appTimings =
+            new Dictionary<string, (DateTime?, DateTime?)>(StringComparer.Ordinal);
+
        public ImeLogTrackerAdapter(
            ImeLogTracker tracker,
            ISignalIngressSink ingress,
@@ -312,6 +320,10 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
            // boundary before the app entry inside it.
            MaybeEmitSubPhaseDeclaration(now);

+            // Plan §5 Fix 4c — set-once per-app timing. Start stamp on the first Downloading/
+            // Installing/InProgress transition, complete stamp on the first terminal state.
+            var timing = UpdateAppTiming(app.Id, newState, now);
+
            // (1) DecisionSignal — terminal states only, once per app.
            var terminalKind = ClassifyTerminalState(newState);
            if (terminalKind != null)
@@ -362,10 +374,64 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
                message: BuildAppStateMessage(app, newState, eventType),
                severity: severity,
                immediateUpload: true,
-                data: BuildAppStatePayload(app, newState),
+                data: BuildAppStatePayload(app, newState, timing),
                occurredAtUtc: now);
        }

+        /// <summary>
+        /// Plan §5 Fix 4c — set-once per-app install-lifecycle timing. Called for every
+        /// state transition, no-op for duplicate stamps. Returns the up-to-date
+        /// <see cref="AppInstallTiming"/> so the emitter can inline the values on the
+        /// current event's payload without a second dictionary lookup.
+        /// </summary>
+        private AppInstallTiming UpdateAppTiming(string appId, AppInstallationState newState, DateTime now)
+        {
+            lock (_lock)
+            {
+                _appTimings.TryGetValue(appId, out var current);
+
+                // First lifecycle-active transition → record StartedAt.
+                if (current.Started == null && IsLifecycleActive(newState))
+                {
+                    current.Started = now;
+                }
+
+                // First terminal transition → record CompletedAt.
+                if (current.Completed == null && IsCompletedState(newState))
+                {
+                    current.Completed = now;
+                }
+
+                _appTimings[appId] = current;
+                return new AppInstallTiming(current.Started, current.Completed);
+            }
+        }
+
+        /// <summary>
+        /// Snapshot of per-app install timings captured during this agent run. Fire-once
+        /// stamps, safe to read concurrently with adapter emissions.
+        /// </summary>
+        public IReadOnlyDictionary<string, AppInstallTiming> AppTimings
+        {
+            get
+            {
+                lock (_lock)
+                {
+                    var snapshot = new Dictionary<string, AppInstallTiming>(_appTimings.Count, StringComparer.Ordinal);
+                    foreach (var kv in _appTimings)
+                    {
+                        snapshot[kv.Key] = new AppInstallTiming(kv.Value.Started, kv.Value.Completed);
+                    }
+                    return snapshot;
+                }
+            }
+        }
+
+        private static bool IsLifecycleActive(AppInstallationState state) =>
+            state == AppInstallationState.Downloading
+            || state == AppInstallationState.Installing
+            || state == AppInstallationState.InProgress;
+
        /// <summary>
        /// Plan §5 Fix 2 — emit a <c>phase_transition</c> declaration event the first time we
        /// see app activity in a given ESP phase, so the Web UI's PhaseTimeline opens an
@@ -636,8 +702,10 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters

        private static IReadOnlyDictionary<string, string> BuildAppStatePayload(
            AppPackageState app,
-            AppInstallationState newState)
+            AppInstallationState newState,
+            AppInstallTiming timing)
        {
+            var culture = System.Globalization.CultureInfo.InvariantCulture;
            var data = new Dictionary<string, string>(StringComparer.Ordinal)
            {
                ["appId"] = app.Id,
@@ -646,18 +714,29 @@ namespace AutopilotMonitor.Agent.V2.Core.SignalAdapters
                ["intent"] = app.Intent.ToString(),
                ["targeted"] = app.Targeted.ToString(),
                ["runAs"] = app.RunAs.ToString(),
-                ["progressPercent"] = (app.ProgressPercent ?? 0).ToString(System.Globalization.CultureInfo.InvariantCulture),
-                ["bytesDownloaded"] = app.BytesDownloaded.ToString(System.Globalization.CultureInfo.InvariantCulture),
-                ["bytesTotal"] = app.BytesTotal.ToString(System.Globalization.CultureInfo.InvariantCulture),
+                ["progressPercent"] = (app.ProgressPercent ?? 0).ToString(culture),
+                ["bytesDownloaded"] = app.BytesDownloaded.ToString(culture),
+                ["bytesTotal"] = app.BytesTotal.ToString(culture),
                ["isError"] = (newState == AppInstallationState.Error).ToString().ToLowerInvariant(),
                ["isCompleted"] = IsCompletedState(newState).ToString().ToLowerInvariant(),
            };

            if (!string.IsNullOrEmpty(app.AppVersion)) data["appVersion"] = app.AppVersion!;
            if (!string.IsNullOrEmpty(app.AppType)) data["appType"] = app.AppType!;
-            if (app.AttemptNumber > 0) data["attemptNumber"] = app.AttemptNumber.ToString(System.Globalization.CultureInfo.InvariantCulture);
+            if (app.AttemptNumber > 0) data["attemptNumber"] = app.AttemptNumber.ToString(culture);
            if (!string.IsNullOrEmpty(app.DetectionResult)) data["detectionResult"] = app.DetectionResult!;

+            // Plan §5 Fix 4c — per-app install-lifecycle timing. StartedAt appears on the
+            // first Downloading/Installing/InProgress event; CompletedAt + DurationSeconds
+            // light up on the terminal event. Values are omitted when not yet known so the
+            // UI can distinguish "not yet started" from "stamp=epoch".
+            if (timing.StartedAtUtc.HasValue)
+                data["startedAt"] = timing.StartedAtUtc.Value.ToString("o", culture);
+            if (timing.CompletedAtUtc.HasValue)
+                data["completedAt"] = timing.CompletedAtUtc.Value.ToString("o", culture);
+            if (timing.DurationSeconds.HasValue)
+                data["durationSeconds"] = timing.DurationSeconds.Value.ToString("F2", culture);
+
            if (newState == AppInstallationState.Error)
            {
                if (!string.IsNullOrEmpty(app.ErrorPatternId)) data["errorPatternId"] = app.ErrorPatternId!;
@@ -57,6 +57,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
        private readonly DateTime _agentStartTimeUtc;
        private readonly Func<DecisionState> _currentStateAccessor;
        private readonly Func<AppPackageStateList> _packageStatesAccessor;
+        private readonly Func<IReadOnlyDictionary<string, AppInstallTiming>> _appTimingsAccessor;
        private readonly Func<CleanupService> _cleanupServiceFactory;
        private readonly Func<bool, string, Task<DiagnosticsUploadResult>> _uploadDiagnosticsAsync;
        private readonly Action _signalShutdown;
@@ -86,7 +87,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
            SessionIdPersistence sessionPersistence = null,
            Action<int> triggerReboot = null,
            TimeSpan? lateEventGracePeriod = null,
-            TimeSpan? spoolDrainPeriod = null)
+            TimeSpan? spoolDrainPeriod = null,
+            Func<IReadOnlyDictionary<string, AppInstallTiming>> appTimingsAccessor = null)
        {
            _configuration = configuration ?? throw new ArgumentNullException(nameof(configuration));
            _logger = logger ?? throw new ArgumentNullException(nameof(logger));
@@ -94,6 +96,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
            _agentStartTimeUtc = agentStartTimeUtc;
            _currentStateAccessor = currentStateAccessor ?? throw new ArgumentNullException(nameof(currentStateAccessor));
            _packageStatesAccessor = packageStatesAccessor ?? throw new ArgumentNullException(nameof(packageStatesAccessor));
+            // Plan §5 Fix 4 — optional timing accessor (older call sites / tests without IME
+            // plumbing pass null → empty timings, which is handled below).
+            _appTimingsAccessor = appTimingsAccessor ?? (() => new Dictionary<string, AppInstallTiming>());
            _cleanupServiceFactory = cleanupServiceFactory ?? throw new ArgumentNullException(nameof(cleanupServiceFactory));
            _uploadDiagnosticsAsync = uploadDiagnosticsAsync ?? throw new ArgumentNullException(nameof(uploadDiagnosticsAsync));
            _signalShutdown = signalShutdown ?? throw new ArgumentNullException(nameof(signalShutdown));
@@ -136,6 +141,15 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
                    RunBuildAndLaunchDialog(state, args);
                }

+                // Plan §5 Fix 4b — emit app_tracking_summary terminal event before the
+                // late-event grace + diagnostics upload, so the backend has the final per-app
+                // summary even if the diagnostics upload fails. Skipped on WhiteGlove Part 1
+                // (apps haven't installed yet — Part 2 is where user apps land).
+                if (!isWhiteGlovePart1)
+                {
+                    EmitAppTrackingSummary();
+                }
+
                // WhiteGlove Part-1 exit: keep the session alive, but announce the handoff so
                // the timeline clearly marks the transition. The `whiteglove.complete` marker
                // lets the next agent boot classify itself as a Part-2 resume.
@@ -198,6 +212,16 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
            }
        }

+        private IReadOnlyDictionary<string, AppInstallTiming> TryGetAppTimings()
+        {
+            try { return _appTimingsAccessor() ?? new Dictionary<string, AppInstallTiming>(); }
+            catch (Exception ex)
+            {
+                _logger.Warning($"EnrollmentTerminationHandler: app timings accessor threw: {ex.Message}");
+                return new Dictionary<string, AppInstallTiming>();
+            }
+        }
+
        private void RunShutdownAnalyzers(EnrollmentTerminatedEventArgs args)
        {
            if (_analyzerManager == null) return;
@@ -220,7 +244,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
            try
            {
                var packages = TryGetPackageStates();
-                var status = FinalStatusBuilder.Build(state, args, packages, _agentStartTimeUtc);
+                var timings = TryGetAppTimings();
+                var status = FinalStatusBuilder.Build(state, args, packages, _agentStartTimeUtc, timings);
                SummaryDialogLauncher.WriteAndLaunch(status, _configuration, _stateDirectory, _logger, _dialogExePathOverride);

                if (_configuration.ShowEnrollmentSummary)
@@ -251,6 +276,112 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
            }
        }

+        /// <summary>
+        /// Plan §5 Fix 4b — emit a single <c>app_tracking_summary</c> event at termination time
+        /// with aggregate counts, per-phase breakdown, and per-app install-lifecycle timing.
+        /// Consumed by the Web UI's <c>useSessionDerivedData</c> hook to build authoritative
+        /// per-app durations (matching V1's <c>EnrollmentTracker.Diagnostics.cs:164</c> behaviour).
+        /// Best-effort: if any accessor throws, we log a warning and skip — the dialog has
+        /// already written <c>final-status.json</c> at this point, so the summary event is
+        /// supplementary observability, not load-bearing.
+        /// </summary>
+        private void EmitAppTrackingSummary()
+        {
+            if (_post == null)
+            {
+                // No informational event post (constructed in tests without wiring) — skip.
+                return;
+            }
+
+            try
+            {
+                var packages = TryGetPackageStates();
+                var timings = TryGetAppTimings();
+
+                var totalApps = 0;
+                var installedApps = 0;
+                var skippedApps = 0;
+                var postponedApps = 0;
+                var failedApps = 0;
+                var byPhase = new Dictionary<string, Dictionary<string, int>>(StringComparer.Ordinal);
+                var perApp = new List<Dictionary<string, object>>();
+
+                if (packages != null)
+                {
+                    foreach (var pkg in packages)
+                    {
+                        totalApps++;
+                        switch (pkg.InstallationState)
+                        {
+                            case AppInstallationState.Installed: installedApps++; break;
+                            case AppInstallationState.Skipped: skippedApps++; break;
+                            case AppInstallationState.Postponed: postponedApps++; break;
+                            case AppInstallationState.Error: failedApps++; break;
+                        }
+
+                        var phaseKey = pkg.Targeted.ToString();
+                        if (!byPhase.TryGetValue(phaseKey, out var bucket))
+                        {
+                            bucket = new Dictionary<string, int>(StringComparer.Ordinal)
+                            {
+                                ["total"] = 0, ["installed"] = 0, ["skipped"] = 0, ["postponed"] = 0, ["failed"] = 0,
+                            };
+                            byPhase[phaseKey] = bucket;
+                        }
+                        bucket["total"]++;
+                        if (pkg.InstallationState == AppInstallationState.Installed) bucket["installed"]++;
+                        else if (pkg.InstallationState == AppInstallationState.Skipped) bucket["skipped"]++;
+                        else if (pkg.InstallationState == AppInstallationState.Postponed) bucket["postponed"]++;
+                        else if (pkg.InstallationState == AppInstallationState.Error) bucket["failed"]++;
+
+                        timings.TryGetValue(pkg.Id, out var timing);
+                        var appEntry = new Dictionary<string, object>(StringComparer.Ordinal)
+                        {
+                            ["appId"] = pkg.Id,
+                            ["appName"] = pkg.Name ?? string.Empty,
+                            ["phase"] = phaseKey,
+                            ["finalState"] = pkg.InstallationState.ToString(),
+                        };
+                        if (timing?.StartedAtUtc != null) appEntry["startedAt"] = timing.StartedAtUtc.Value.ToString("o");
+                        if (timing?.CompletedAtUtc != null) appEntry["completedAt"] = timing.CompletedAtUtc.Value.ToString("o");
+                        if (timing?.DurationSeconds != null) appEntry["durationSeconds"] = timing.DurationSeconds.Value;
+                        perApp.Add(appEntry);
+                    }
+                }
+
+                var completedApps = installedApps + skippedApps + postponedApps + failedApps;
+
+                var data = new Dictionary<string, object>(StringComparer.Ordinal)
+                {
+                    ["totalApps"] = totalApps,
+                    ["completedApps"] = completedApps,
+                    ["installedApps"] = installedApps,
+                    ["skippedApps"] = skippedApps,
+                    ["postponedApps"] = postponedApps,
+                    ["failedApps"] = failedApps,
+                    ["byPhase"] = byPhase,
+                    ["perApp"] = perApp,
+                };
+
+                _post.Emit(new EnrollmentEvent
+                {
+                    SessionId = _configuration.SessionId,
+                    TenantId = _configuration.TenantId,
+                    EventType = Constants.EventTypes.AppTrackingSummary,
+                    Severity = EventSeverity.Info,
+                    Source = "EnrollmentTerminationHandler",
+                    Phase = EnrollmentPhase.Unknown,
+                    Message = $"App summary: {completedApps}/{totalApps} completed, {failedApps} failed.",
+                    Data = data,
+                    ImmediateUpload = true,
+                });
+            }
+            catch (Exception ex)
+            {
+                _logger.Warning($"EnrollmentTerminationHandler: app_tracking_summary emit failed: {ex.Message}");
+            }
+        }
+
        private void RunUploadDiagnosticsWithEvents(EnrollmentTerminatedEventArgs args)
        {
            var mode = _configuration.DiagnosticsUploadMode ?? "Off";
@@ -80,5 +80,17 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination

        [JsonProperty("targeted")]
        public string Targeted { get; set; }
+
+        // Plan §5 Fix 4a / 4c — per-app install-lifecycle timestamps. Omitted from the
+        // JSON when not yet captured (e.g. agent started mid-install), so the dialog can
+        // distinguish "not tracked" from "stamp=epoch".
+        [JsonProperty("startedAt", NullValueHandling = NullValueHandling.Ignore)]
+        public string StartedAt { get; set; }
+
+        [JsonProperty("completedAt", NullValueHandling = NullValueHandling.Ignore)]
+        public string CompletedAt { get; set; }
+
+        [JsonProperty("durationSeconds", NullValueHandling = NullValueHandling.Ignore)]
+        public double? DurationSeconds { get; set; }
    }
 }
@@ -28,12 +28,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
            DecisionState state,
            EnrollmentTerminatedEventArgs terminated,
            AppPackageStateList? packageStates,
-            DateTime agentStartTimeUtc)
+            DateTime agentStartTimeUtc,
+            IReadOnlyDictionary<string, AppInstallTiming>? appTimings = null)
        {
            if (state == null) throw new ArgumentNullException(nameof(state));
            if (terminated == null) throw new ArgumentNullException(nameof(terminated));

            var uptimeSeconds = Math.Max(0, (terminated.TerminatedAtUtc - agentStartTimeUtc).TotalSeconds);
+            var timings = appTimings ?? new Dictionary<string, AppInstallTiming>();

            var status = new FinalStatus
            {
@@ -45,7 +47,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
                AgentUptimeSeconds = uptimeSeconds,
                SignalsSeen = BuildSignalsSeen(state),
                AppSummary = BuildAppSummary(packageStates),
-                PackageStatesByPhase = BuildPackageStatesByPhase(packageStates),
+                PackageStatesByPhase = BuildPackageStatesByPhase(packageStates, timings),
            };

            return status;
@@ -109,7 +111,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
        }

        private static Dictionary<string, List<FinalStatusPackageInfo>> BuildPackageStatesByPhase(
-            AppPackageStateList? packageStates)
+            AppPackageStateList? packageStates,
+            IReadOnlyDictionary<string, AppInstallTiming> timings)
        {
            var result = new Dictionary<string, List<FinalStatusPackageInfo>>();
            if (packageStates == null) return result;
@@ -123,6 +126,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
                    result[phaseKey] = bucket;
                }

+                timings.TryGetValue(pkg.Id, out var timing);
+
                bucket.Add(new FinalStatusPackageInfo
                {
                    AppName = string.IsNullOrEmpty(pkg.Name) ? pkg.Id : pkg.Name,
@@ -130,6 +135,9 @@ namespace AutopilotMonitor.Agent.V2.Core.Termination
                    IsError = pkg.InstallationState == AppInstallationState.Error,
                    IsCompleted = IsCompleted(pkg.InstallationState),
                    Targeted = pkg.Targeted.ToString(),
+                    StartedAt = timing?.StartedAtUtc?.ToString("o"),
+                    CompletedAt = timing?.CompletedAtUtc?.ToString("o"),
+                    DurationSeconds = timing?.DurationSeconds,
                });
            }

@@ -48,6 +48,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Transport.Telemetry
        private readonly string? _bootstrapToken;
        private readonly string? _agentVersion;
        private readonly AuthFailureTracker? _authFailureTracker;
+        private readonly Logging.AgentLogger? _logger;

        public BackendTelemetryUploader(
            HttpClient httpClient,
@@ -58,7 +59,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Transport.Telemetry
            string? serialNumber = null,
            string? bootstrapToken = null,
            string? agentVersion = null,
-            AuthFailureTracker? authFailureTracker = null)
+            AuthFailureTracker? authFailureTracker = null,
+            Logging.AgentLogger? logger = null)
        {
            _httpClient = httpClient ?? throw new ArgumentNullException(nameof(httpClient));
            if (string.IsNullOrEmpty(baseUrl)) throw new ArgumentException("BaseUrl is mandatory.", nameof(baseUrl));
@@ -72,6 +74,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Transport.Telemetry
            _bootstrapToken = bootstrapToken;
            _agentVersion = agentVersion;
            _authFailureTracker = authFailureTracker;
+            _logger = logger;
        }

        public async Task<UploadResult> UploadBatchAsync(
@@ -91,6 +94,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Transport.Telemetry
            // MtlsHttpClientFactory — we only need to compress outbound here.
            var body = SerializeBatch(items);
            var compressedBody = CompressWithGzip(body);
+
+            // Plan §5 Fix 5 — upload-cadence logging. First line users see when diagnosing
+            // "why didn't my event arrive" — records batch size + sent-bytes pre-response.
+            _logger?.Info(
+                $"BackendTelemetryUploader: flushing {items.Count} item(s) (bytes={compressedBody.Length}, firstId={items[0].TelemetryItemId}, lastId={items[items.Count - 1].TelemetryItemId}).");
+            var sw = System.Diagnostics.Stopwatch.StartNew();
+
            using (var request = new HttpRequestMessage(HttpMethod.Post, _endpointUrl))
            {
                request.Content = new ByteArrayContent(compressedBody);
@@ -111,19 +121,39 @@ namespace AutopilotMonitor.Agent.V2.Core.Transport.Telemetry
                }
                catch (TaskCanceledException ex)
                {
+                    sw.Stop();
+                    _logger?.Warning($"BackendTelemetryUploader: ingest TIMEOUT after {sw.ElapsedMilliseconds}ms (items={items.Count}): {ex.Message}");
                    // HttpClient timeout (not caller cancellation) surfaces as TaskCanceledException
                    // with cancellationToken.IsCancellationRequested == false.
                    return UploadResult.Transient($"timeout: {ex.Message}");
                }
                catch (HttpRequestException ex)
                {
+                    sw.Stop();
+                    _logger?.Warning($"BackendTelemetryUploader: ingest NETWORK fail after {sw.ElapsedMilliseconds}ms (items={items.Count}): {ex.Message}");
                    // DNS failure, socket error, etc. — network-layer is retryable.
                    return UploadResult.Transient($"network: {ex.Message}");
                }

                using (response)
                {
-                    return await MapResponseAsync(response).ConfigureAwait(false);
+                    var result = await MapResponseAsync(response).ConfigureAwait(false);
+                    sw.Stop();
+
+                    if (result.Success)
+                    {
+                        _logger?.Info($"BackendTelemetryUploader: ingest OK (items={items.Count}, durationMs={sw.ElapsedMilliseconds}, status={(int)response.StatusCode}).");
+                    }
+                    else if (result.IsTransient)
+                    {
+                        _logger?.Warning($"BackendTelemetryUploader: ingest TRANSIENT (items={items.Count}, durationMs={sw.ElapsedMilliseconds}, status={(int)response.StatusCode}): {result.ErrorReason}");
+                    }
+                    else
+                    {
+                        _logger?.Error($"BackendTelemetryUploader: ingest PERMANENT fail (items={items.Count}, durationMs={sw.ElapsedMilliseconds}, status={(int)response.StatusCode}): {result.ErrorReason}");
+                    }
+
+                    return result;
                }
            }
        }
@@ -28,12 +28,13 @@ namespace AutopilotMonitor.Agent.V2.Core.Transport.Telemetry
        private readonly string _spoolPath;
        private readonly UploadCursorPersistence _cursor;
        private readonly IClock _clock;
+        private readonly Logging.AgentLogger? _logger;
        private readonly object _lock = new object();

        private long _lastAssignedItemId = -1;
        private long _lastUploadedItemId = -1;

-        public TelemetrySpool(string directoryPath, IClock clock)
+        public TelemetrySpool(string directoryPath, IClock clock, Logging.AgentLogger? logger = null)
        {
            if (string.IsNullOrEmpty(directoryPath))
            {
@@ -41,6 +42,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Transport.Telemetry
            }

            _clock = clock ?? throw new ArgumentNullException(nameof(clock));
+            _logger = logger;

            if (!Directory.Exists(directoryPath))
            {
@@ -99,6 +101,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Transport.Telemetry
                }

                _lastAssignedItemId = itemId;
+                // Plan §5 Fix 5 — spool-cadence logging (DEBUG to avoid noise under heavy
+                // event flows; users can enable at troubleshoot-time).
+                _logger?.Debug(
+                    $"TelemetrySpool: enqueued itemId={itemId} kind={item.Kind} immediate={item.RequiresImmediateFlush} pending={itemId - _lastUploadedItemId}.");
                return item;
            }
        }
@@ -423,7 +423,8 @@ namespace AutopilotMonitor.Agent.V2
                    serialNumber: hardwareForReporters.SerialNumber,
                    bootstrapToken: agentConfig.UseBootstrapTokenAuth ? agentConfig.BootstrapToken : null,
                    agentVersion: GetAgentVersion(),
-                    authFailureTracker: authFailureTracker);
+                    authFailureTracker: authFailureTracker,
+                    logger: logger);     // Plan §5 Fix 5 — upload-cadence logging
            }
            catch (Exception ex)
            {
@@ -702,7 +703,10 @@ namespace AutopilotMonitor.Agent.V2
                                signalShutdown: () => shutdown.Set(),
                                analyzerManager: analyzerManager,
                                post: lifecyclePost,
-                                sessionPersistence: sessionPersistence);
+                                sessionPersistence: sessionPersistence,
+                                // Plan §5 Fix 4 — per-app timing snapshot for FinalStatusBuilder +
+                                // app_tracking_summary emission. Null-safe via the handler's default.
+                                appTimingsAccessor: () => componentFactory.ImeAppTimings);

                            // Single-rail refactor (plan §5.3) — ServerActionDispatcher emits through
                            // the same InformationalEventPost. Constructed inside this hook so
@@ -1 +1 @@
-244
+256
@@ -1 +1 @@
-1115
+1119
@@ -217,6 +217,7 @@ namespace AutopilotMonitor.Shared
            public const string ImeUserSessionCompleted   = "ime_user_session_completed";
            public const string DoTelemetry               = "do_telemetry";
            public const string AllAppsCompleted          = "all_apps_completed";
+            public const string AppTrackingSummary        = "app_tracking_summary";  // Plan §5 Fix 4b — terminal per-session app summary

            // Stall detection (Ebene 2 — StallProbeCollector)
            public const string StallProbeCheck           = "stall_probe_check";   // Trace heartbeat from Probe 2 (15 min) when no anomaly found