feat(editor): add per-request access audit middleware

editor/server/internal/app/access_audit.go

@@ -0,0 +1,144 @@
+package app
+
+import (
+	"encoding/json"
+	"strings"
+	"time"
+
+	"github.com/labstack/echo/v4"
+	"github.com/reearth/reearth/server/internal/adapter"
+	"github.com/reearth/reearthx/log"
+)
+
+// accessAuditLogPrefix is a stable, greppable prefix on every audit line.
+// Downstream (Cloud Logging → BigQuery) filters on this to pick audit events
+// out of the general application log stream.
+const accessAuditLogPrefix = "editor_access_audit "
+
+// accessAuditRecord is the JSON payload emitted for each authenticated
+// Editor API request. Kept small on purpose: no headers, no bodies, no
+// Authorization values. Downstream schema in BigQuery is:
+//
+//	SAFE.PARSE_JSON(REGEXP_EXTRACT(jsonPayload.message,
+//	  r'^editor_access_audit (\{.*\})$'))
+type accessAuditRecord struct {
+	Ts         string `json:"ts"`
+	Sub        string `json:"sub,omitempty"`
+	UserID     string `json:"user_id,omitempty"`
+	Email      string `json:"email,omitempty"`
+	Name       string `json:"name,omitempty"`
+	Method     string `json:"method"`
+	Path       string `json:"path"`
+	Status     int    `json:"status"`
+	LatencyMS  int64  `json:"latency_ms"`
+	RemoteIP   string `json:"remote_ip,omitempty"`
+	UserAgent  string `json:"ua,omitempty"`
+	RequestID  string `json:"request_id,omitempty"`
+	Referer    string `json:"referer,omitempty"`
+	AuthMethod string `json:"auth,omitempty"` // "jwt" | "mock" | "debug"
+}
+
+// accessAuditSkipPrefixes is the list of URL path prefixes that are excluded
+// from audit logging. These are either unauthenticated (published data), noisy
+// (health checks, static assets), or already covered by other logs.
+var accessAuditSkipPrefixes = []string{
+	"/api/ping",
+	"/api/published/",
+	"/api/published_data/",
+	"/p/",
+	"/assets/",
+	"/static/",
+	"/favicon",
+	"/debug/pprof",
+	"/health",
+	"/robots.txt",
+}
+
+// accessAuditMiddleware records one structured log line per authenticated
+// Editor API request. It runs AFTER attachOpMiddleware so that
+// adapter.User(ctx) is already resolved from the JWT sub.
+//
+// Design notes:
+//   - Unauthenticated requests (no user resolved) are skipped: aggregating
+//     them adds no value for the "who used the Editor, when" question and
+//     would only bloat logs.
+//   - We never log the Authorization header or the raw JWT.
+//   - Email fallback order: DB user → JWT AuthInfo → empty.
+//   - Latency is measured around the downstream handler only.
+func accessAuditMiddleware(enabled bool) echo.MiddlewareFunc {
+	return func(next echo.HandlerFunc) echo.HandlerFunc {
+		return func(c echo.Context) error {
+			if !enabled {
+				return next(c)
+			}
+
+			path := c.Request().URL.Path
+			for _, p := range accessAuditSkipPrefixes {
+				if strings.HasPrefix(path, p) {
+					return next(c)
+				}
+			}
+
+			start := time.Now()
+			err := next(c)
+			latency := time.Since(start)
+
+			ctx := c.Request().Context()
+
+			// Only log authenticated requests. If neither the JWT nor the
+			// resolved user is present, there is nothing to attribute.
+			u := adapter.User(ctx)
+			au := adapter.GetAuthInfo(ctx)
+			if u == nil && au == nil {
+				return err
+			}
+
+			rec := accessAuditRecord{
+				Ts:        start.UTC().Format(time.RFC3339Nano),
+				Method:    c.Request().Method,
+				Path:      path,
+				Status:    c.Response().Status,
+				LatencyMS: latency.Milliseconds(),
+				RemoteIP:  c.RealIP(),
+				UserAgent: c.Request().UserAgent(),
+				RequestID: c.Response().Header().Get(echo.HeaderXRequestID),
+				Referer:   c.Request().Referer(),
+			}
+			if rec.RequestID == "" {
+				rec.RequestID = c.Request().Header.Get(echo.HeaderXRequestID)
+			}
+
+			if au != nil {
+				rec.Sub = au.Sub
+				if au.Email != "" {
+					rec.Email = au.Email
+				}
+				if au.Name != "" {
+					rec.Name = au.Name
+				}
+				rec.AuthMethod = "jwt"
+			}
+			if u != nil {
+				rec.UserID = u.ID().String()
+				if e := u.Email(); e != "" {
+					rec.Email = e
+				}
+				if n := u.Name(); n != "" {
+					rec.Name = n
+				}
+			}
+			if adapter.IsMockAuth(ctx) {
+				rec.AuthMethod = "mock"
+			}
+
+			buf, jerr := json.Marshal(rec)
+			if jerr != nil {
+				// Never let audit logging break a request. Just drop the line.
+				return err
+			}
+			log.Infofc(ctx, "%s%s", accessAuditLogPrefix, string(buf))
+
+			return err
+		}
+	}
+}

editor/server/internal/app/access_audit_test.go

@@ -0,0 +1,184 @@
+package app
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"net/http"
+	"net/http/httptest"
+	"os"
+	"strings"
+	"testing"
+
+	"github.com/labstack/echo/v4"
+	"github.com/reearth/reearth/server/internal/adapter"
+	"github.com/reearth/reearthx/account/accountdomain/user"
+	"github.com/reearth/reearthx/appx"
+	"github.com/reearth/reearthx/log"
+	"github.com/stretchr/testify/assert"
+)
+
+// captureLogs redirects the reearthx global logger to an in-memory buffer so
+// we can inspect emitted audit lines. Restored on t.Cleanup.
+func captureLogs(t *testing.T) *bytes.Buffer {
+	t.Helper()
+	// disable color codes so the plain substring match works reliably
+	_ = os.Setenv("NO_COLOR", "1")
+	buf := &bytes.Buffer{}
+	log.SetOutput(buf)
+	t.Cleanup(func() {
+		log.SetOutput(os.Stdout)
+	})
+	return buf
+}
+
+func newAuditRequest(t *testing.T, method, path string, u *user.User, au *appx.AuthInfo) echo.Context {
+	t.Helper()
+	e := echo.New()
+	req := httptest.NewRequest(method, path, nil)
+	req.Header.Set(echo.HeaderXRequestID, "req-1")
+	req.Header.Set("User-Agent", "test-agent")
+	rec := httptest.NewRecorder()
+	c := e.NewContext(req, rec)
+
+	ctx := req.Context()
+	if u != nil {
+		ctx = adapter.AttachUser(ctx, u)
+	}
+	if au != nil {
+		ctx = context.WithValue(ctx, adapter.ContextAuthInfo, *au)
+	}
+	c.SetRequest(req.WithContext(ctx))
+	return c
+}
+
+// extractAuditRecord finds the last audit line in the captured log output and
+// parses its JSON payload. Returns false when no audit line was emitted.
+func extractAuditRecord(t *testing.T, out string) (accessAuditRecord, bool) {
+	t.Helper()
+	idx := strings.LastIndex(out, accessAuditLogPrefix)
+	if idx < 0 {
+		return accessAuditRecord{}, false
+	}
+	rest := out[idx+len(accessAuditLogPrefix):]
+	// The payload ends at the first newline.
+	if nl := strings.IndexByte(rest, '\n'); nl >= 0 {
+		rest = rest[:nl]
+	}
+	// The console encoder may color-wrap; strip trailing ANSI reset if any.
+	rest = strings.TrimSpace(rest)
+	// Trim to the last '}' to survive any trailing suffix the encoder adds.
+	if end := strings.LastIndexByte(rest, '}'); end >= 0 {
+		rest = rest[:end+1]
+	}
+	var rec accessAuditRecord
+	if err := json.Unmarshal([]byte(rest), &rec); err != nil {
+		t.Fatalf("failed to parse audit payload %q: %v (raw=%q)", rest, err, out)
+	}
+	return rec, true
+}
+
+func TestAccessAuditMiddleware_Disabled(t *testing.T) {
+	buf := captureLogs(t)
+	mw := accessAuditMiddleware(false)
+
+	u := user.New().NewID().Name("Alice").Email("alice@city.osaka.lg.jp").MustBuild()
+	c := newAuditRequest(t, http.MethodPost, "/api/graphql", u, &appx.AuthInfo{Sub: "auth0|abc"})
+
+	err := mw(func(c echo.Context) error {
+		return c.NoContent(http.StatusOK)
+	})(c)
+	assert.NoError(t, err)
+
+	assert.NotContains(t, buf.String(), accessAuditLogPrefix, "should emit no audit line when disabled")
+}
+
+func TestAccessAuditMiddleware_SkipsUnauthenticated(t *testing.T) {
+	buf := captureLogs(t)
+	mw := accessAuditMiddleware(true)
+
+	c := newAuditRequest(t, http.MethodGet, "/api/graphql", nil, nil)
+	err := mw(func(c echo.Context) error {
+		return c.NoContent(http.StatusOK)
+	})(c)
+	assert.NoError(t, err)
+
+	assert.NotContains(t, buf.String(), accessAuditLogPrefix, "should not audit unauthenticated requests")
+}
+
+func TestAccessAuditMiddleware_SkipsExcludedPaths(t *testing.T) {
+	buf := captureLogs(t)
+	mw := accessAuditMiddleware(true)
+
+	u := user.New().NewID().Name("Alice").Email("alice@city.osaka.lg.jp").MustBuild()
+	au := &appx.AuthInfo{Sub: "auth0|abc"}
+	for _, p := range []string{
+		"/api/ping",
+		"/api/published/foo",
+		"/api/published_data/foo",
+		"/p/foo/data.json",
+		"/assets/x.png",
+		"/favicon.ico",
+	} {
+		c := newAuditRequest(t, http.MethodGet, p, u, au)
+		err := mw(func(c echo.Context) error {
+			return c.NoContent(http.StatusOK)
+		})(c)
+		assert.NoError(t, err)
+	}
+
+	assert.NotContains(t, buf.String(), accessAuditLogPrefix, "excluded paths should not be audited")
+}
+
+func TestAccessAuditMiddleware_EmitsForAuthenticated(t *testing.T) {
+	buf := captureLogs(t)
+	mw := accessAuditMiddleware(true)
+
+	u := user.New().NewID().Name("Alice").Email("alice@city.osaka.lg.jp").MustBuild()
+	au := &appx.AuthInfo{Sub: "auth0|abc", Email: "alice-jwt@city.osaka.lg.jp", Name: "Alice JWT"}
+	c := newAuditRequest(t, http.MethodPost, "/api/graphql", u, au)
+
+	err := mw(func(c echo.Context) error {
+		return c.NoContent(http.StatusNoContent)
+	})(c)
+	assert.NoError(t, err)
+
+	rec, ok := extractAuditRecord(t, buf.String())
+	if !ok {
+		t.Fatalf("expected audit record, got none. logs=%q", buf.String())
+	}
+	assert.Equal(t, "auth0|abc", rec.Sub)
+	assert.Equal(t, u.ID().String(), rec.UserID)
+	// DB email wins over JWT email.
+	assert.Equal(t, "alice@city.osaka.lg.jp", rec.Email)
+	assert.Equal(t, "Alice", rec.Name)
+	assert.Equal(t, http.MethodPost, rec.Method)
+	assert.Equal(t, "/api/graphql", rec.Path)
+	assert.Equal(t, http.StatusNoContent, rec.Status)
+	assert.Equal(t, "jwt", rec.AuthMethod)
+	assert.NotEmpty(t, rec.Ts)
+	assert.Equal(t, "req-1", rec.RequestID)
+	assert.Equal(t, "test-agent", rec.UserAgent)
+}
+
+func TestAccessAuditMiddleware_FallsBackToJWTEmail(t *testing.T) {
+	buf := captureLogs(t)
+	mw := accessAuditMiddleware(true)
+
+	au := &appx.AuthInfo{Sub: "auth0|xyz", Email: "jwt@example.com", Name: "JWT Only"}
+	c := newAuditRequest(t, http.MethodGet, "/api/graphql", nil, au)
+
+	err := mw(func(c echo.Context) error {
+		return c.NoContent(http.StatusOK)
+	})(c)
+	assert.NoError(t, err)
+
+	rec, ok := extractAuditRecord(t, buf.String())
+	if !ok {
+		t.Fatalf("expected audit record, got none. logs=%q", buf.String())
+	}
+	assert.Equal(t, "auth0|xyz", rec.Sub)
+	assert.Equal(t, "jwt@example.com", rec.Email)
+	assert.Equal(t, "JWT Only", rec.Name)
+	assert.Empty(t, rec.UserID)
+}

editor/server/internal/app/app.go

@@ -78,6 +78,9 @@ func initEcho(ctx context.Context, cfg *ServerConfig) *echo.Echo {
 
 	e.Use(echo.WrapMiddleware(wrapHandler))
 	e.Use(attachOpMiddleware(cfg))
+	// Access audit runs after auth/op resolution so it can attribute each
+	// request to a specific user (sub / email / user id) for reporting.
+	e.Use(accessAuditMiddleware(cfg.Config.AccessAudit))
 
 	// enable pprof
 	if e.Debug {

editor/server/internal/app/config/config.go

@@ -52,6 +52,13 @@ type Config struct {
 	SignupDisabled   bool              `pp:",omitempty"`
 	HTTPSREDIRECT    bool              `pp:",omitempty"`
 
+	// AccessAudit toggles per-request audit logging for authenticated Editor
+	// API requests. Emits one structured JSON line (prefixed with
+	// "editor_access_audit ") per request via the standard logger so it can
+	// be picked up by Cloud Logging and routed to BigQuery.
+	// Defaults to true; set REEARTH_ACCESSAUDIT=false to disable.
+	AccessAudit bool `default:"true" pp:",omitempty"`
+
 	// storage
 	GCS GCSConfig `pp:",omitempty"`
 	S3  S3Config  `pp:",omitempty"`