Add basic event logging

Reviewed-on: #28

core/api.snap.txt

@@ -23,6 +23,8 @@ func (a *Admin) CreateGroup(name string, reference string) (*Group, error)
 
 func (*Admin) GetUser(id string) (*User, error)
 
+func (a *Admin) ListEvents() ([]Event, error)
+
 func (a *Admin) ListGroups() ([]Group, error)
 
 func (*Admin) ListUsers() ([]User, error)
@@ -37,6 +39,15 @@ func (u *Admin) UserSetLive(userReference string, setting bool) error
 
 type ErrorInvalidCredentials error
 
+type Event struct {
+	Id         string
+	ActorId    string
+	ActionType string
+	TargetType string
+	TargetId   string
+	CreatedAt  time.Time
+}
+
 type Group struct {
 	Id        string
 	Name      string
@@ -72,7 +83,7 @@ func (s *Session) GetOthersWishes(userReference string) ([]Wish, error)
 
 func (s *Session) GetWishes() ([]Wish, error)
 
-func (s *Session) MakeWish(name string) error
+func (s *Session) MakeWish(name string) (string, error)
 
 func (s *Session) RecindWishesForUser(ids ...string) error
 

core/event.go

@@ -0,0 +1,150 @@
+package lishwist
+
+import (
+	"fmt"
+	"log"
+	"strings"
+	"time"
+
+	"lishwist/core/internal/db"
+)
+
+const (
+	eventActionCreate   = "CREATE"
+	eventActionHide     = "HIDE"
+	eventActionUnhide   = "UNHIDE"
+	eventActionClaim    = "CLAIM"
+	eventActionUnclaim  = "UNCLAIM"
+	eventActionComplete = "COMPLETE"
+	// eventActionDelete   = "DELETE" NOTE: We can't have this, because there'll be no target to reference
+)
+
+const (
+	eventTargetGroup       = "GROUP"
+	eventTargetUser        = "USER"
+	eventTargetWish        = "WISH"
+	eventTargetGroupMember = "GROUP_MEMBER"
+)
+
+type Event struct {
+	Id         string
+	ActorId    string
+	ActionType string
+	TargetType string
+	TargetId   string
+	CreatedAt  time.Time
+}
+
+// type EventCreateGroupMember struct {
+// 	Event
+// 	Actor User
+// 	User
+// 	Group
+// }
+
+func queryManyEvents(query string, args ...any) ([]Event, error) {
+	rows, err := db.Connection.Query(query, args...)
+	if err != nil {
+		return nil, err
+	}
+	defer rows.Close()
+	events := []Event{}
+	for rows.Next() {
+		var g Event
+		var createdAt string
+		err = rows.Scan(&g.Id, &g.ActorId, &g.ActionType, &g.TargetType, &g.TargetId, &createdAt)
+		if err != nil {
+			return nil, err
+		}
+		g.CreatedAt, err = time.Parse(time.RFC3339Nano, createdAt)
+		if err != nil {
+			return nil, fmt.Errorf("failed to parse created_at: %w", err)
+		}
+		events = append(events, g)
+	}
+	err = rows.Err()
+	if err != nil {
+		return nil, err
+	}
+	return events, nil
+}
+
+func queryOneEvent(query string, args ...any) (*Event, error) {
+	events, err := queryManyEvents(query, args...)
+	if err != nil {
+		return nil, err
+	}
+	if len(events) < 1 {
+		return nil, nil
+	}
+	return &events[0], nil
+}
+
+func (a *Admin) ListEvents() ([]Event, error) {
+	query := "SELECT id, actor_id, action_type, target_type, target_id, created_at FROM event;"
+	return queryManyEvents(query)
+}
+
+func recordEvent(actorId, actionType, targetType string, targetIds ...string) {
+	// TODO: If this were to accept sql.Tx it could be used in atomic transactions
+	numTargets := len(targetIds)
+	if numTargets < 1 {
+		log.Println("Warning: recordEvent called with no target IDs. Skipping.")
+		return
+	}
+	stmt := "INSERT INTO event (actor_id, action_type, target_type, target_id) VALUES (?, ?, ?, ?)"
+	extraValuePlaceholders := strings.Repeat(", (?, ?, ?, ?)", numTargets-1)
+	args := make([]any, numTargets*4)
+	for i, id := range targetIds {
+		args[i*4] = actorId
+		args[i*4+1] = actionType
+		args[i*4+2] = targetType
+		args[i*4+3] = id
+	}
+	_, err := db.Connection.Exec(stmt+extraValuePlaceholders, args...)
+	if err == nil {
+		return
+	}
+	if numTargets == 1 {
+		log.Printf("Failed to record %s %s event: failed to execute query: %s\n", actionType, targetType, err)
+	} else {
+		log.Printf("Failed to record %d %s %s events: failed to execute query: %s\n", numTargets, actionType, targetType, err)
+	}
+}
+
+func recordEventCreateGroup(actorId, groupId string) {
+	recordEvent(actorId, eventActionCreate, eventTargetGroup, groupId)
+}
+
+func recordEventCreateUser(actorId, userId string) {
+	recordEvent(actorId, eventActionCreate, eventTargetUser, userId)
+}
+
+func recordEventCreateWish(actorId, wishId string) {
+	recordEvent(actorId, eventActionCreate, eventTargetWish, wishId)
+}
+
+func recordEventCreateGroupMember(actorId, groupMemberId string) {
+	recordEvent(actorId, eventActionCreate, eventTargetGroupMember, groupMemberId)
+}
+
+// FIXME: I can't use these yet because the associated actions use reference
+// func recordEventHideUser(actorId, userId string) {
+// 	recordEvent(actorId, eventActionHide, eventTargetUser, userId)
+// }
+
+// func recordEventUnhideUser(actorId, userId string) {
+// 	recordEvent(actorId, eventActionUnhide, eventTargetUser, userId)
+// }
+
+func recordEventClaimWishes(actorId string, wishIds ...string) {
+	recordEvent(actorId, eventActionClaim, eventTargetWish, wishIds...)
+}
+
+func recordEventUnclaimWishes(actorId string, wishIds ...string) {
+	recordEvent(actorId, eventActionUnclaim, eventTargetWish, wishIds...)
+}
+
+func recordEventCompleteWishes(actorId string, wishIds ...string) {
+	recordEvent(actorId, eventActionComplete, eventTargetWish, wishIds...)
+}

core/group.go

@@ -103,15 +103,21 @@ func (a *Admin) CreateGroup(name string, reference string) (*Group, error) {
 		Name:      name,
 		Reference: reference,
 	}
+	recordEventCreateGroup(a.session.user.Id, group.Id)
 	return &group, nil
 }
 
 func (a *Admin) AddUserToGroup(userId, groupId string) error {
 	stmt := "INSERT INTO group_member (user_id, group_id) VALUES (?, ?)"
-	_, err := db.Connection.Exec(stmt, userId, groupId)
+	result, err := db.Connection.Exec(stmt, userId, groupId)
 	if err != nil {
-		return err
+		return fmt.Errorf("query execution failed: %w", err)
 	}
+	id, err := result.LastInsertId()
+	if err != nil {
+		return fmt.Errorf("failed to get last insert id: %w", err)
+	}
+	recordEventCreateGroupMember(a.session.user.Id, strconv.FormatInt(id, 10))
 	return nil
 }
 

core/group_test.go

@@ -15,6 +15,12 @@ func TestCreateGroup(t *testing.T) {
 
 	fixtures.AssertEq(t, "Number of users", "My Friends", group.Name)
 	fixtures.AssertEq(t, "Number of users", "my-friends", group.Reference)
+
+	// FIXME: disabled for now because datetimes break this
+	// events, err := s.Admin().ListEvents()
+	// assert.FatalErr(t, "listing events", err)
+
+	// assert.JsonSnapshot(t, "TestCreateGroup.snap.txt", events)
 }
 
 func TestCantSeeSelfInGroup(t *testing.T) {
@@ -39,4 +45,10 @@ func TestCantSeeSelfInGroup(t *testing.T) {
 	fixtures.AssertEq(t, "Group contains 2 users", 2, len(group.Members))
 	fixtures.AssertEq(t, "Group user 1 is thomas", "thomas", group.Members[0].Name)
 	fixtures.AssertEq(t, "Group user 2 is caleb", "caleb", group.Members[1].Name)
+
+	// FIXME: disabled for now because datetimes break this
+	// events, err := s.Admin().ListEvents()
+	// assert.FatalErr(t, "listing events", err)
+
+	// assert.JsonSnapshot(t, "TestCantSeeSelfInGroup.snap.txt", events)
 }

core/internal/assert/assert.go

@@ -0,0 +1,49 @@
+package assert
+
+import (
+	"errors"
+	"slices"
+	"testing"
+)
+
+func Eq[C comparable](t *testing.T, context string, expected, actual C) {
+	if expected != actual {
+		t.Errorf("%s: %#v != %#v", context, expected, actual)
+	}
+}
+
+func True(t *testing.T, context string, condition bool) {
+	if !condition {
+		t.Errorf("false: %s", context)
+	}
+}
+
+func FatalTrue(t *testing.T, context string, condition bool) {
+	if !condition {
+		t.Fatalf("%s", context)
+	}
+}
+
+func FatalErr(t *testing.T, context string, err error) {
+	if err != nil {
+		t.Fatalf("%s: %s", context, err)
+	}
+}
+
+func FatalErrIs(t *testing.T, context string, err, target error) {
+	if !errors.Is(err, target) {
+		t.Fatalf("%s: encountered unexpected error: %s", context, err)
+	}
+}
+
+func FatalErrAs(t *testing.T, context string, err error, target any) {
+	if !errors.As(err, target) {
+		t.Fatalf("%s: encountered unexpected error: %s", context, err)
+	}
+}
+
+func SlicesEq[S ~[]E, E comparable](t *testing.T, context string, expected, actual S) {
+	if !slices.Equal(expected, actual) {
+		t.Errorf("%s: %#v != %#v", context, expected, actual)
+	}
+}

core/internal/assert/snapshot.go

@@ -0,0 +1,62 @@
+package assert
+
+import (
+	"encoding/json"
+	"errors"
+	"fmt"
+	"os"
+	"testing"
+)
+
+func pathExists(path string) bool {
+	_, err := os.Stat(path)
+	return !errors.Is(err, os.ErrNotExist)
+}
+
+func writeSnapshot(t *testing.T, path, actual string) {
+	f, err := os.Create(path)
+	if err != nil {
+		t.Fatalf("Failed to create snapshot file: %s", err)
+	}
+	_, err = f.Write([]byte(actual))
+	if err != nil {
+		t.Fatalf("Failed to write to snapshot file: %s", err)
+	}
+	err = f.Close()
+	if err != nil {
+		t.Fatalf("Failed to close snapshot file: %s", err)
+	}
+}
+
+func TextSnapshot(t *testing.T, path, actual string) {
+	if !pathExists(path) {
+		writeSnapshot(t, path, actual)
+		t.Errorf("Snapshot file created: %s", path)
+		return
+	}
+
+	content, err := os.ReadFile(path)
+	if err != nil {
+		t.Fatalf("Failed to read snapshot file: %s", err)
+	}
+	expected := string(content)
+
+	if expected != actual {
+		t.Errorf("Value doesn't match snapshot %s:\n%s", path, actual)
+	}
+
+	if os.Getenv("UPDATE_SNAPSHOTS") == "" {
+		return
+	}
+
+	writeSnapshot(t, path, actual)
+	fmt.Printf("Snapshot file %s updated\n", path)
+}
+
+func JsonSnapshot(t *testing.T, path string, actual any) {
+	data, err := json.MarshalIndent(actual, "", "  ")
+	if err != nil {
+		t.Fatalf("Snapshot failed to serialize actual to JSON: %s", err)
+	}
+	TextSnapshot(t, path, string(data))
+}

core/internal/db/init.sql

@@ -30,8 +30,10 @@ CREATE TABLE IF NOT EXISTS "group" (
 	PRIMARY KEY("id" AUTOINCREMENT)
 );
 CREATE TABLE IF NOT EXISTS "group_member" (
+	"id"	INTEGER NOT NULL UNIQUE,
 	"group_id"	INTEGER NOT NULL,
 	"user_id"	INTEGER NOT NULL,
+	PRIMARY KEY("id" AUTOINCREMENT),
 	UNIQUE("user_id","group_id"),
 	FOREIGN KEY("group_id") REFERENCES "group"("id"),
 	FOREIGN KEY("user_id") REFERENCES "user"("id")
@@ -44,6 +46,15 @@ CREATE TABLE IF NOT EXISTS "session" (
 	PRIMARY KEY("id" AUTOINCREMENT),
 	FOREIGN KEY("user_id") REFERENCES "user"("id")
 );
+CREATE TABLE IF NOT EXISTS "event" (
+	"id"	INTEGER NOT NULL UNIQUE,
+	"actor_id"	INTEGER NOT NULL,
+	"action_type"	TEXT NOT NULL,
+	"target_type"	TEXT NOT NULL,
+	"target_id"	INTEGER NOT NULL,
+	"created_at" TEXT NOT NULL DEFAULT (STRFTIME('%Y-%m-%dT%H:%M:%fZ')),
+	PRIMARY KEY("id" AUTOINCREMENT)
+);
 
 DROP VIEW IF EXISTS "v_user";
 CREATE VIEW "v_user"

core/internal/db/migration/4.sql

@@ -0,0 +1,19 @@
+BEGIN TRANSACTION;
+
+ALTER TABLE group_member RENAME TO old_group_member;
+
+CREATE TABLE "group_member" (
+	"id"	INTEGER NOT NULL UNIQUE,
+	"group_id"	INTEGER NOT NULL,
+	"user_id"	INTEGER NOT NULL,
+	PRIMARY KEY("id" AUTOINCREMENT),
+	UNIQUE("user_id","group_id"),
+	FOREIGN KEY("group_id") REFERENCES "group"("id"),
+	FOREIGN KEY("user_id") REFERENCES "user"("id")
+);
+
+INSERT INTO group_member (group_id, user_id) SELECT group_id, user_id FROM old_group_member;
+
+DROP TABLE "old_group_member";
+
+COMMIT;

core/internal/fixtures/assert.go

@@ -2,24 +2,28 @@ package fixtures
 
 import "testing"
 
+// Deprecated: use internal/assert
 func AssertEq[C comparable](t *testing.T, context string, expected, actual C) {
 	if expected != actual {
 		t.Errorf("%s: %#v != %#v", context, expected, actual)
 	}
 }
 
+// Deprecated: use internal/assert
 func Assert(t *testing.T, context string, condition bool) {
 	if !condition {
 		t.Errorf("%s", context)
 	}
 }
 
+// Deprecated: use internal/assert
 func FatalAssert(t *testing.T, context string, condition bool) {
 	if !condition {
 		t.Fatalf("%s", context)
 	}
 }
 
+// Deprecated: use internal/assert
 func FailIfErr(t *testing.T, err error, context string) {
 	if err != nil {
 		t.Fatalf("%s: %s\n", context, err)

core/internal/fixtures/login.go

@@ -1,7 +1,6 @@
 package fixtures
 
 import (
-	"log"
 	"testing"
 	"time"
 
@@ -15,21 +14,36 @@ func TestInit(t *testing.T) error {
 	return lishwist.Init(uri)
 }
 
+// Deprecated: This function also inits the test, which prevents it from being used more than once per test
 func Login(t *testing.T, username, password string) *lishwist.Session {
 	uri := memdb.TestDB(t)
 	err := lishwist.Init(uri)
 	if err != nil {
-		log.Fatalf("Failed to init db: %s\n", err)
+		t.Fatalf("Failed to init db: %s\n", err)
 	}
 
 	_, err = lishwist.Register(username, password)
 	if err != nil {
-		log.Fatalf("Failed to register on login fixture: %s\n", err)
+		t.Fatalf("Failed to register on login fixture: %s\n", err)
 	}
 
 	session, err := lishwist.Login(username, password, time.Hour*24)
 	if err != nil {
-		log.Fatalf("Failed to login on fixture: %s\n", err)
+		t.Fatalf("Failed to login on fixture: %s\n", err)
+	}
+
+	return session
+}
+
+func Login2(t *testing.T, username, password string) *lishwist.Session {
+	_, err := lishwist.Register(username, password)
+	if err != nil {
+		t.Fatalf("Failed to register on login fixture: %s\n", err)
+	}
+
+	session, err := lishwist.Login(username, password, time.Hour*24)
+	if err != nil {
+		t.Fatalf("Failed to login on fixture: %s\n", err)
 	}
 
 	return session

core/user.go

@@ -78,6 +78,7 @@ func createUser(name string, passHash []byte, isAdmin bool) (*User, error) {
 		Id:   fmt.Sprintf("%d", id),
 		Name: name,
 	}
+	recordEventCreateUser(user.Id, user.Id)
 	return &user, nil
 }
 

core/wish.go

@@ -4,6 +4,7 @@ import (
 	"database/sql"
 	"errors"
 	"fmt"
+	"strconv"
 	"strings"
 
 	"lishwist/core/internal/db"
@@ -52,13 +53,20 @@ func (s *Session) GetWishes() ([]Wish, error) {
 	return wishs, nil
 }
 
-func (s *Session) MakeWish(name string) error {
+// May return the id of the wish
+func (s *Session) MakeWish(name string) (string, error) {
 	stmt := "INSERT INTO wish (name, recipient_id, creator_id) VALUES (?, ?, ?)"
-	_, err := db.Connection.Exec(stmt, strings.TrimSpace(name), s.User().Id, s.User().Id)
+	result, err := db.Connection.Exec(stmt, strings.TrimSpace(name), s.User().Id, s.User().Id)
 	if err != nil {
-		return fmt.Errorf("Query execution failed: %w", err)
+		return "", fmt.Errorf("Query execution failed: %w", err)
 	}
-	return nil
+	id, err := result.LastInsertId()
+	if err != nil {
+		return "", fmt.Errorf("failed to get last insert id: %w", err)
+	}
+	wishId := strconv.FormatInt(id, 10)
+	recordEventCreateWish(s.user.Id, wishId)
+	return wishId, nil
 }
 
 func (s *Session) deleteWishes(tx *sql.Tx, ids []string) error {
@@ -194,7 +202,10 @@ func (s *Session) executeClaims(tx *sql.Tx, claims, unclaims []string) error {
 
 // Undertake or abandon wishes made by other users
 func (s *Session) ClaimWishes(claims, unclaims []string) error {
-	if len(claims) < 1 && len(unclaims) < 1 {
+	lenClaims := len(claims)
+	lenUnclaims := len(unclaims)
+	// TODO: Would be nice if this used a request builder
+	if lenClaims < 1 && lenUnclaims < 1 {
 		return fmt.Errorf("Attempt to claim/unclaim zero wishes")
 	}
 
@@ -213,7 +224,17 @@ func (s *Session) ClaimWishes(claims, unclaims []string) error {
 	}
 
 	err = tx.Commit()
-	return err
+	if err != nil {
+		return err
+	}
+	// TODO: This could be atomic. See recordEvent function
+	if lenClaims > 0 {
+		recordEventClaimWishes(s.user.Id, claims...)
+	}
+	if lenUnclaims > 0 {
+		recordEventUnclaimWishes(s.user.Id, unclaims...)
+	}
+	return nil
 }
 
 func executeCompletions(tx *sql.Tx, claims []string) error {
@@ -234,8 +255,8 @@ func executeCompletions(tx *sql.Tx, claims []string) error {
 	return nil
 }
 
-// TODO: User ought not be able to interact with wishes outside their group network
 func (s *Session) CompleteWishes(claims []string) error {
+	// TODO: User ought not be able to interact with wishes outside their group network
 	if len(claims) < 1 {
 		return fmt.Errorf("Attempt to complete zero wishes")
 	}
@@ -255,7 +276,13 @@ func (s *Session) CompleteWishes(claims []string) error {
 	}
 
 	err = tx.Commit()
-	return err
+	if err != nil {
+		return err
+	}
+
+	recordEventCompleteWishes(s.user.Id, claims...)
+
+	return nil
 }
 
 func (u *Session) SuggestWishForUser(otherUserReference string, wishName string) error {
@@ -291,5 +318,8 @@ func (s *Session) RecindWishesForUser(ids ...string) error {
 	}
 
 	err = tx.Commit()
-	return err
+	if err != nil {
+		return nil
+	}
+	return nil
 }

core/wish_test.go

@@ -3,17 +3,18 @@ package lishwist_test
 import (
 	"testing"
 
+	"lishwist/core/internal/assert"
 	"lishwist/core/internal/fixtures"
 )
 
 func TestMakeWish(t *testing.T) {
 	s := fixtures.Login(t, "thomas", "123")
 
-	if err := s.MakeWish("apple"); err != nil {
+	if _, err := s.MakeWish("apple"); err != nil {
 		t.Fatalf("Failed to make wish 1: %s\n", err)
 	}
 
-	if err := s.MakeWish(" A car "); err != nil {
+	if _, err := s.MakeWish(" A car "); err != nil {
 		t.Fatalf("Failed to make wish 2: %s\n", err)
 	}
 
@@ -26,3 +27,35 @@ func TestMakeWish(t *testing.T) {
 	fixtures.AssertEq(t, "Wish 1 name", wishes[0].Name, "apple")
 	fixtures.AssertEq(t, "Wish 2 name", wishes[1].Name, "A car")
 }
+
+func TestClaimUnclaimWishes(t *testing.T) {
+	err := fixtures.TestInit(t)
+	assert.FatalErr(t, "initializing db", err)
+
+	thomas := fixtures.Login2(t, "thomas", "123")
+	assert.FatalErr(t, "registering thomas", err)
+
+	caleb := fixtures.Login2(t, "caleb", "123")
+	assert.FatalErr(t, "registering caleb", err)
+
+	food, err := caleb.MakeWish("food")
+	assert.FatalErr(t, "making wish 1", err)
+
+	box, err := caleb.MakeWish("box")
+	assert.FatalErr(t, "making wish 2", err)
+
+	drink, err := caleb.MakeWish("drink")
+	assert.FatalErr(t, "making wish 3", err)
+
+	err = thomas.ClaimWishes([]string{food, box, drink}, []string{})
+	assert.FatalErr(t, "claiming wishes", err)
+
+	err = thomas.ClaimWishes([]string{}, []string{food, box, drink})
+	assert.FatalErr(t, "unclaiming wishes", err)
+
+	// FIXME: disabled for now because datetimes break this
+	// events, err := thomas.Admin().ListEvents()
+	// assert.FatalErr(t, "listing events", err)
+
+	// assert.JsonSnapshot(t, "TestClaimUnclaimWishes.snap.txt", events)
+}

http/dev.sh

@@ -1,4 +1,5 @@
 top_level=$(git rev-parse --show-toplevel)
 git_version=$($top_level/scripts/git-version)
 
+go generate ../core/internal/db
 go run -ldflags=-X=lishwist/http/env.GitVersion=$git_version main.go

http/routing/events.go

@@ -0,0 +1,30 @@
+package routing
+
+import (
+	lishwist "lishwist/core"
+	"lishwist/http/response"
+	"log"
+	"net/http"
+
+	"github.com/Teajey/rsvp"
+)
+
+type Events struct {
+	Events []lishwist.Event `xml:"Event"`
+}
+
+func EventList(app *lishwist.Session, session *response.Session, h http.Header, r *http.Request) rsvp.Response {
+	admin := app.Admin()
+	if admin == nil {
+		log.Println("Attempt to access EventList by non-admin. Responding 404 Not Found.")
+		return response.NotFound()
+	}
+
+	events, err := admin.ListEvents()
+	if err != nil {
+		log.Printf("Admin failed to ListEvents: %s\n", err)
+		return response.Error(http.StatusInternalServerError, "Failed to get events: %s", err)
+	}
+
+	return response.Data("", Events{Events: events})
+}

http/routing/wishlist.go

@@ -17,7 +17,7 @@ func WishlistAdd(app *lishwist.Session, h http.Header, r *http.Request) rsvp.Res
 	}
 
 	newGiftName := r.Form.Get("gift_name")
-	err = app.MakeWish(newGiftName)
+	_, err = app.MakeWish(newGiftName)
 	if err != nil {
 		log.Printf("%s\n", err)
 		return response.Error(http.StatusInternalServerError, "Failed to add gift.")

http/server/server.go

@@ -50,6 +50,7 @@ func Create(useSecureCookies bool) *router.VisibilityRouter {
 	r.Public.HandleFunc("POST /", routing.LoginPost)
 	r.Public.HandleFunc("POST /register", routing.RegisterPost)
 
+	r.Private.HandleFunc("GET /events", routing.ExpectAppSession(routing.EventList))
 	r.Private.HandleFunc("GET /account", routing.ExpectAppSession(routing.Account))
 	r.Private.HandleFunc("GET /health", routing.ExpectAppSession(routing.Health))
 	r.Private.HandleFunc("GET /", routing.NotFound)