Operating it

What the service says about itself while it runs, and how the whole thing is exercised in a test.

One id everywhere, one report per incident

The request id is stamped on the context, so every log line, query, outbound call and Sentry event of that request carries it without being asked. Which level says what — and why logging an error and returning it files one incident as two issues.

package main

import (
	"errors"
	"net/http"

	core "gitlab.finema.co/finema/idin-core/v2"
	"gitlab.finema.co/finema/idin-core/v2/errmsgs"
)

// --- Example 6: one id through every subsystem, one report per incident ------
//
// The first middleware stamps a request id onto the context itself, and from
// then on everything derived from that context carries it without being asked:
//
//	X-Request-ID ─▶ context ─┬─▶ ctx.Log()          every line: request_id=…
//	                         ├─▶ ctx.DB()           query log, same request
//	                         ├─▶ core.Requester(ctx) outbound calls, same request
//	                         └─▶ ctx.Sentry()       tags and breadcrumbs
//
// So a service needs no logger of its own: none on a struct, none passed as a
// parameter. Under HTTP the logger carries the request id; under the scheduler
// it carries the job name, run id and attempt. Same logger, different unit of
// work.

func registerGreeting(e *core.Server) {
	e.GET("/hello", hello)
	e.GET("/boom", boom)
}

func hello(c core.IHTTPContext) error {
	name := c.QueryParamOr("name", "world")

	// Debug, not Info: this runs on every request. Info is for work that changed
	// something — "user created", "note deleted", "signed in". The access line
	// (method, path, status, latency, request id) is already written by the
	// request middleware, so repeating any of it here only prints it twice.
	//
	// Key-value pairs, never fmt.Sprintf: the output is JSON, and a field can be
	// filtered and aggregated where a sentence cannot. Numbers go out as
	// numbers, so `duration_ms > 500` is a query rather than a string match.
	c.Log().Debug("greeting", "name_len", len(name))

	return c.JSON(http.StatusOK, map[string]string{"hello": name})
}

func boom(c core.IHTTPContext) error {
	err := errors.New("the widget factory is on fire")

	// ✅ one event, one report. NewError attaches this request's user, tags and
	// breadcrumbs, sends it to Sentry, and writes the 5xx log line itself.
	// Returning the error *is* reporting it.
	return c.NewError(err, errmsgs.InternalServerError)

	// ❌ never this. The logger bridges to Sentry too, so logging and then
	// returning files one incident as two issues, triaged separately by two
	// people who each think the other one is theirs:
	//
	//	c.Log().Error("boom", "err", err)
	//	return c.NewError(err, errmsgs.InternalServerError)
	//
	// The same rule upward: a handler that returns an error from a service must
	// not log it either. Whoever returns last is not the one who reports.
}

func sweepExpired(c core.ICronjobContext) error {
	// c.Log() here carries job, run_id and attempt — the cron counterpart of
	// request_id. Adding them by hand just prints them twice.
	deleted := 0 // a real one would delete rows through repository.New[…](c)

	// Reported on every run, including the ones that counted zero: a job that
	// only speaks when it found work is indistinguishable from a job that died
	// three weeks ago.
	c.Log().Info("expired tokens swept", "deleted", deleted)

	c.SetResult(map[string]any{"deleted": deleted})
	return nil
}

// Which level, and what must never appear:
//
//	Info   work that changed data, and every scheduled run
//	Warn   the service worked correctly and refused the caller — a rejected
//	       business rule, a failed sign-in. Alert on the *rate* of these, not on
//	       one appearing.
//	Error  only what nobody else reports. A returned error is already reported,
//	       so this is left for structural mistakes: a route registered without
//	       its middleware, an initialiser never called.
//	Debug  detail for the ten minutes somebody is actually chasing something.
//
// Never logged: tokens, password hashes, any credential — a log store always has
// more readers than the database. Personal data goes in as identifiers, never as
// values: user_id rather than the email, note_id rather than the note.
//
// ⚠ Sentry's scrubber masks sensitive fields on the way *to Sentry only*.
// Whatever is handed to ctx.Log() is printed to stdout in full, so a log
// pipeline that forwards elsewhere has to filter at that layer — or the secret
// has to not be there in the first place.
//
// Field names must match across services, or they cannot be queried together:
// user_id (not userId/uid), err (not error/e), reason (not why/cause),
// duration_ms as a number (not "41ms"). snake_case, like the keys the framework
// pins itself: request_id, trace_id, run_id.

Testing the real service, with nothing mocked

The production composition root mounted on coretest.NewServer, the readiness probe checked for what it does not probe, and a job run through a real runner. Memory implementations replace mocks because they prove the result was right, not that a method was called.

package main

import (
	"net/http"
	"testing"

	core "gitlab.finema.co/finema/idin-core/v2"
	"gitlab.finema.co/finema/idin-core/v2/coretest"
)

// --- Example 7: testing the real service, with nothing mocked ---------------
//
// These are ordinary tests; they live in this file rather than a _test.go one
// only so the documentation can show them next to the code they exercise. Copy
// them into service_test.go in your own repository and they run as they stand.
//
// v2 ships no generated mocks and no mock generator. Every capability exports an
// in-memory implementation instead — NewMemoryCache, NewMemoryStorage,
// NewMemoryMailer, NewMemoryPusher, NewRecordingSentry — and coretest composes
// them into fixtures. The reason is that a generated mock proves a method was
// called, while a memory implementation proves the result was right; and being
// real code compiled against the real interface, it breaks the day the interface
// changes rather than staying silent until somebody regenerates.

// TestHTTP drives the same routes production serves, through the same middleware
// stack: request id, recovery, the IError renderer. What the test asserts is
// therefore what a caller receives, not an internal struct.
func TestHTTP(t *testing.T) {
	app := coretest.NewApp(t)
	srv := coretest.NewServerWithApp(t, app, nil)
	registerModules(srv.Server) // ★ the production composition root, not a copy

	// liveness must answer without touching anything
	srv.Get("/healthz").RequireStatus(http.StatusOK)

	body := srv.Get("/hello?name=ada").RequireStatus(http.StatusOK).Map()
	if body["hello"] != "ada" {
		t.Fatalf("the handler must echo the name it was given, got %v", body["hello"])
	}

	// a failing route returns core.IError, so the body has the framework's
	// shape — asserting on it is asserting on the contract clients depend on
	failure := srv.Get("/boom").RequireStatus(http.StatusInternalServerError).Error()
	if failure.Code != "INTERNAL_SERVER_ERROR" {
		t.Fatalf("a 5xx must carry its error code so clients can branch on it, got %q", failure.Code)
	}
}

// TestReadiness proves the probe reports what this deployment actually depends
// on. The fixture registers a SQL connection and nothing else, so "database" is
// checked and there is no cache check to fail.
func TestReadiness(t *testing.T) {
	app := coretest.NewApp(t)

	report := core.CheckHealth(t.Context(), app)
	if report.Status != core.HealthUp {
		t.Fatalf("a fixture with a live sqlite must be up, got %s: %+v", report.Status, report.Checks)
	}
	if _, ok := report.Checks["cache"]; ok {
		t.Fatal("an unconfigured cache must be absent from the probe, not a check that always fails")
	}
}

// TestSweepExpired runs the job through a real runner, so the test exercises the
// path a schedule or a manual trigger would: parameters are validated, a panic
// becomes a failed run, and the run is recorded with a status.
func TestSweepExpired(t *testing.T) {
	j := coretest.NewJob(t)
	j.Register("sweep-expired-tokens", sweepExpired)

	run := j.Run("sweep-expired-tokens", nil)

	// a failing run does not fail the test — assert on the status, because a
	// failure is often exactly what is being tested
	if run.Status != core.RunSucceeded {
		t.Fatalf("the sweep must succeed with nothing to delete, got %s: %v", run.Status, run.Error)
	}
}

// TestWithCache shows the substitution: the service code is unchanged, the App
// is given a memory cache instead of redis, and the assertions are about stored
// values rather than about calls.
func TestWithCache(t *testing.T) {
	ctx := coretest.NewContext(t,
		coretest.WithAppOptions(core.WithCache("default", core.NewMemoryCache())),
		coretest.WithEnv(map[string]string{"service": "example-service"}),
	)

	if err := ctx.Cache().Set("greeting", "hello", core.NoExpiry); err != nil {
		t.Fatalf("the memory cache must accept writes: %v", err)
	}
	var got string
	if err := ctx.Cache().Get("greeting", &got); err != nil || got != "hello" {
		t.Fatalf("what was written must read back, got %q (%v)", got, err)
	}
}

// Two backends, one suite. sqlite needs nothing installed and gives each test
// its own database, so it is what runs on every save; postgres is the schema you
// deploy:
//
//	go test ./...                                    # sqlite, in memory
//	TEST_DATABASE_URL=postgres://… go test ./...      # the real engine
//
// Run the postgres path before pushing, pointed at your real migrations
// (coretest.WithMigrations). sqlite has no partial indexes, no UUID type and no
// ILIKE, and builds its schema from your Go structs — a suite that only ever
// sees sqlite passes on constraints postgres rejects.