Add Serilog console logging across the API

Information at endpoint and service-method boundaries, Debug in deeper
helpers, Warning before expected/recoverable failures (not-found,
validation, agent tool errors), Error on caught exceptions. Serilog
wraps the exception handler so request-completion logs report the
resolved status code rather than the raw exception. Never logs prose
bodies or the Anthropic API key.
This commit is contained in:
James Wampler
2026-08-06 12:11:20 -07:00
parent 4f396bb5f9
commit 04917fa09e
34 changed files with 790 additions and 147 deletions
@@ -1,3 +1,4 @@
using Microsoft.Extensions.Logging.Abstractions;
using Microsoft.Extensions.Options;
using Novelly.Api.Agent;
using Novelly.Api.Common;
@@ -13,7 +14,7 @@ public class AnthropicClientTests
// (listing conversations, reading a transcript). Throwing at construction would
// take those down on any install that has not configured a key yet.
Assert.That(
() => new AnthropicAgentModelClient(Options.Create(new AgentOptions())),
() => new AnthropicAgentModelClient(Options.Create(new AgentOptions()), NullLogger<AnthropicAgentModelClient>.Instance),
Throws.Nothing);
[Test]
@@ -24,7 +25,7 @@ public class AnthropicClientTests
try
{
var client = new AnthropicAgentModelClient(Options.Create(new AgentOptions()));
var client = new AnthropicAgentModelClient(Options.Create(new AgentOptions()), NullLogger<AnthropicAgentModelClient>.Instance);
Assert.That(
async () => await client.CompleteAsync("system", [], []),
@@ -0,0 +1,24 @@
using Microsoft.Extensions.Logging;
namespace Novelly.Api.Tests;
/// <summary>Records every entry logged through it, so tests can assert on what a service logged.</summary>
public record CapturedLogEntry(LogLevel Level, string Message, Exception? Exception);
/// <summary>
/// A test double for <see cref="ILogger{TCategoryName}"/> that captures entries instead of
/// writing them anywhere, so tests can assert a service logged at the right level with the
/// right values without standing up a real sink.
/// </summary>
public class CapturingLogger<T> : ILogger<T>
{
public List<CapturedLogEntry> Entries { get; } = [];
public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
public bool IsEnabled(LogLevel logLevel) => true;
public void Log<TState>(
LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter) =>
Entries.Add(new CapturedLogEntry(logLevel, formatter(state, exception), exception));
}
+1 -1
View File
@@ -97,7 +97,7 @@ public class ListingTests : ServiceTestFixture
var agent = new NovelAgentService(
Db.Context,
new ScriptedModelClient([[new AgentTextBlock("Reply.")]]),
new NovelAgentToolset(Projects, Characters, Arcs, Chapters, Beats, Scenes, Tags, Questions),
new NovelAgentToolset(Projects, Characters, Arcs, Chapters, Beats, Scenes, Tags, Questions, NullLogger<NovelAgentToolset>.Instance),
Options.Create(new AgentOptions()),
NullLogger<NovelAgentService>.Instance);
+88
View File
@@ -0,0 +1,88 @@
using Microsoft.Extensions.Logging;
using Novelly.Api.Beats;
using Novelly.Api.Chapters;
using Novelly.Api.Characters;
using Novelly.Api.Common;
using Novelly.Api.Projects;
namespace Novelly.Api.Tests;
/// <summary>
/// Covers the logging behaviour added across the services: a warning fires before a
/// not-found is thrown, and prose bodies never leak into a log message.
/// </summary>
[TestFixture]
public class LoggingTests : ServiceTestFixture
{
[Test]
public void Fetching_a_missing_chapter_logs_a_warning_before_throwing()
{
var missingId = Guid.NewGuid();
Assert.That(() => Chapters.GetAsync(missingId), Throws.TypeOf<NotFoundException>());
var warning = ChapterLogs.Entries.Single(e => e.Level == LogLevel.Warning);
Assert.That(warning.Message, Does.Contain(missingId.ToString()));
}
[Test]
public async Task Creating_a_chapter_logs_the_project_and_title_at_information()
{
var project = await Projects.CreateAsync(new CreateProjectRequest("The Salt Road"));
ChapterLogs.Entries.Clear();
await Chapters.CreateAsync(project.Id, new CreateChapterRequest("Landfall"));
var info = ChapterLogs.Entries.Single(e => e.Level == LogLevel.Information);
Assert.Multiple(() =>
{
Assert.That(info.Message, Does.Contain("Landfall"));
Assert.That(info.Message, Does.Contain(project.Id.ToString()));
});
}
[Test]
public async Task Logged_values_never_include_a_chapter_summary_body()
{
var project = await Projects.CreateAsync(new CreateProjectRequest("The Salt Road"));
const string secretSummary = "A very specific plot twist nobody should see in a log line.";
ChapterLogs.Entries.Clear();
await Chapters.CreateAsync(project.Id, new CreateChapterRequest("Landfall", Summary: secretSummary));
Assert.That(ChapterLogs.Entries.Select(e => e.Message), Has.None.Contain(secretSummary));
}
[Test]
public async Task Deleting_a_project_logs_information_before_the_lookup()
{
var project = await Projects.CreateAsync(new CreateProjectRequest("The Salt Road"));
ProjectLogs.Entries.Clear();
await Projects.DeleteAsync(project.Id);
Assert.That(
ProjectLogs.Entries,
Has.Some.Matches<CapturedLogEntry>(e => e.Level == LogLevel.Information && e.Message.Contains(project.Id.ToString())));
}
[Test]
public async Task Rejecting_a_beat_with_a_foreign_character_logs_a_warning_not_an_error()
{
var projectA = await Projects.CreateAsync(new CreateProjectRequest("Project A"));
var projectB = await Projects.CreateAsync(new CreateProjectRequest("Project B"));
var chapter = await Chapters.CreateAsync(projectA.Id, new CreateChapterRequest("Landfall"));
var foreignCharacter = await Characters.CreateAsync(projectB.Id, new CreateCharacterRequest("Ines"));
BeatLogs.Entries.Clear();
Assert.That(
() => Beats.CreateAsync(chapter.Id, new CreateBeatRequest("Arrival", CharacterId: foreignCharacter.Id)),
Throws.TypeOf<InvalidOperationException>());
Assert.Multiple(() =>
{
Assert.That(BeatLogs.Entries.Where(e => e.Level == LogLevel.Error), Is.Empty);
Assert.That(BeatLogs.Entries.Any(e => e.Level == LogLevel.Warning), Is.True);
});
}
}
@@ -12,7 +12,7 @@ public class NovelAgentServiceTests : ServiceTestFixture
private NovelAgentToolset _toolset = null!;
protected override void OnSetUp() =>
_toolset = new NovelAgentToolset(Projects, Characters, Arcs, Chapters, Beats, Scenes, Tags, Questions);
_toolset = new NovelAgentToolset(Projects, Characters, Arcs, Chapters, Beats, Scenes, Tags, Questions, NullLogger<NovelAgentToolset>.Instance);
private NovelAgentService BuildAgent(ScriptedModelClient model) => new(
Db.Context,
+27 -8
View File
@@ -29,18 +29,37 @@ public abstract class ServiceTestFixture
protected CharacterArcService Arcs { get; private set; } = null!;
protected OpenQuestionService Questions { get; private set; } = null!;
protected CapturingLogger<ProjectService> ProjectLogs { get; private set; } = null!;
protected CapturingLogger<CharacterService> CharacterLogs { get; private set; } = null!;
protected CapturingLogger<ChapterService> ChapterLogs { get; private set; } = null!;
protected CapturingLogger<SceneService> SceneLogs { get; private set; } = null!;
protected CapturingLogger<BeatService> BeatLogs { get; private set; } = null!;
protected CapturingLogger<TagService> TagLogs { get; private set; } = null!;
protected CapturingLogger<CharacterArcService> ArcLogs { get; private set; } = null!;
protected CapturingLogger<OpenQuestionService> QuestionLogs { get; private set; } = null!;
[SetUp]
public void SetUpFixture()
{
Db = new TestDatabase();
Tags = new TagService(Db.Context);
Projects = new ProjectService(Db.Context);
Characters = new CharacterService(Db.Context, Tags);
Chapters = new ChapterService(Db.Context, Tags);
Scenes = new SceneService(Db.Context);
Beats = new BeatService(Db.Context, Tags);
Arcs = new CharacterArcService(Db.Context);
Questions = new OpenQuestionService(Db.Context);
TagLogs = new CapturingLogger<TagService>();
ProjectLogs = new CapturingLogger<ProjectService>();
CharacterLogs = new CapturingLogger<CharacterService>();
ChapterLogs = new CapturingLogger<ChapterService>();
SceneLogs = new CapturingLogger<SceneService>();
BeatLogs = new CapturingLogger<BeatService>();
ArcLogs = new CapturingLogger<CharacterArcService>();
QuestionLogs = new CapturingLogger<OpenQuestionService>();
Tags = new TagService(Db.Context, TagLogs);
Projects = new ProjectService(Db.Context, ProjectLogs);
Characters = new CharacterService(Db.Context, Tags, CharacterLogs);
Chapters = new ChapterService(Db.Context, Tags, ChapterLogs);
Scenes = new SceneService(Db.Context, SceneLogs);
Beats = new BeatService(Db.Context, Tags, BeatLogs);
Arcs = new CharacterArcService(Db.Context, ArcLogs);
Questions = new OpenQuestionService(Db.Context, QuestionLogs);
OnSetUp();
}