···33import (
44 "context"
55 "fmt"
66+ "log/slog"
67 "net/http"
7889 "github.com/go-chi/chi/v5"
···2122 db *db.DB
2223 js *jsclient.JetstreamClient
2324 e *rbac.Enforcer
2525+ l *slog.Logger
24262527 // init is a channel that is closed when the knot has been initailized
2628 // i.e. when the first user (knot owner) has been added.
···2830 knotInitialized bool
2931}
30323131-func Setup(ctx context.Context, c *config.Config, db *db.DB, e *rbac.Enforcer) (http.Handler, error) {
3333+func Setup(ctx context.Context, c *config.Config, db *db.DB, e *rbac.Enforcer, l *slog.Logger) (http.Handler, error) {
3234 r := chi.NewRouter()
33353436 h := Handle{
3537 c: c,
3638 db: db,
3739 e: e,
4040+ l: l,
3841 init: make(chan struct{}),
3942 }
4043
+66-34
knotserver/jetstream.go
···55 "encoding/json"
66 "fmt"
77 "io"
88- "log"
98 "net/http"
109 "net/url"
1110 "strings"
···1413 "github.com/sotangled/tangled/api/tangled"
1514 "github.com/sotangled/tangled/knotserver/db"
1615 "github.com/sotangled/tangled/knotserver/jsclient"
1616+ "github.com/sotangled/tangled/log"
1717)
18181919func (h *Handle) StartJetstream(ctx context.Context) error {
2020+ l := h.l.With("component", "jetstream")
2121+ ctx = log.IntoContext(ctx, l)
2022 collections := []string{tangled.PublicKeyNSID, tangled.KnotMemberNSID}
2123 dids := []string{}
22242323- lastTimeUs, err := h.getLastTimeUs()
2525+ lastTimeUs, err := h.getLastTimeUs(ctx)
2426 if err != nil {
2527 return err
2628 }
···3133 return fmt.Errorf("failed to read from jetstream: %w", err)
3234 }
33353434- go h.processMessages(messages)
3636+ go h.processMessages(ctx, messages)
35373638 return nil
3739}
38403939-func (h *Handle) getLastTimeUs() (int64, error) {
4141+func (h *Handle) getLastTimeUs(ctx context.Context) (int64, error) {
4242+ l := log.FromContext(ctx)
4043 lastTimeUs, err := h.db.GetLastTimeUs()
4144 if err != nil {
4242- log.Println("couldn't get last time us, starting from now")
4545+ l.Info("couldn't get last time us, starting from now")
4346 lastTimeUs = time.Now().UnixMicro()
4447 }
45484649 // If last time is older than a week, start from now
4750 if time.Now().UnixMicro()-lastTimeUs > 7*24*60*60*1000*1000 {
4851 lastTimeUs = time.Now().UnixMicro()
4949- log.Printf("last time us is older than a week. discarding that and starting from now.")
5252+ l.Info("last time us is older than a week. discarding that and starting from now")
5053 err = h.db.SaveLastTimeUs(lastTimeUs)
5154 if err != nil {
5252- log.Println("failed to save last time us")
5555+ l.Error("failed to save last time us")
5356 }
5457 }
55585656- log.Printf("found last time_us %d", lastTimeUs)
5959+ l.Info("found last time_us", "time_us", lastTimeUs)
5760 return lastTimeUs, nil
5861}
59626060-func (h *Handle) processPublicKey(did string, record map[string]interface{}) {
6363+func (h *Handle) processPublicKey(ctx context.Context, did string, record map[string]interface{}) error {
6464+ l := log.FromContext(ctx)
6165 if err := h.db.AddPublicKeyFromRecord(did, record); err != nil {
6262- log.Printf("failed to add public key: %v", err)
6363- } else {
6464- log.Printf("added public key from firehose: %s", did)
6666+ l.Error("failed to add public key", "error", err)
6767+ return fmt.Errorf("failed to add public key: %w", err)
6568 }
6969+ l.Info("added public key from firehose", "did", did)
7070+ return nil
6671}
67726868-func (h *Handle) fetchAndAddKeys(did string) {
7373+func (h *Handle) fetchAndAddKeys(ctx context.Context, did string) error {
7474+ l := log.FromContext(ctx)
7575+6976 keysEndpoint, err := url.JoinPath(h.c.AppViewEndpoint, "keys", did)
7077 if err != nil {
7171- log.Printf("error building endpoint url: %s: %v", did, err)
7272- return
7878+ l.Error("error building endpoint url", "did", did, "error", err.Error())
7979+ return fmt.Errorf("error building endpoint url: %w", err)
7380 }
74817582 resp, err := http.Get(keysEndpoint)
7683 if err != nil {
7777- log.Printf("error getting keys for %s: %v", did, err)
7878- return
8484+ l.Error("error getting keys", "did", did, "error", err)
8585+ return fmt.Errorf("error getting keys: %w", err)
7986 }
8087 defer resp.Body.Close()
81888289 plaintext, err := io.ReadAll(resp.Body)
8390 if err != nil {
8484- log.Printf("error reading response body: %v", err)
8585- return
9191+ l.Error("error reading response body", "error", err)
9292+ return fmt.Errorf("error reading response body: %w", err)
8693 }
87948895 for _, key := range strings.Split(string(plaintext), "\n") {
···94101 }
95102 pk.Key = key
96103 if err := h.db.AddPublicKey(pk); err != nil {
9797- log.Printf("failed to add public key: %v", err)
104104+ l.Error("failed to add public key", "error", err)
105105+ return fmt.Errorf("failed to add public key: %w", err)
98106 }
99107 }
108108+ return nil
100109}
101110102102-func (h *Handle) processKnotMember(did string, record map[string]interface{}) {
111111+func (h *Handle) processKnotMember(ctx context.Context, did string, record map[string]interface{}) error {
112112+ l := log.FromContext(ctx)
103113 ok, err := h.e.E.Enforce(did, ThisServer, ThisServer, "server:invite")
104114 if err != nil || !ok {
105105- log.Printf("failed to add member from did %s", did)
106106- return
115115+ l.Error("failed to add member", "did", did)
116116+ return fmt.Errorf("failed to enforce permissions: %w", err)
107117 }
108118109109- log.Printf("adding member")
119119+ l.Info("adding member")
110120 if err := h.e.AddMember(ThisServer, record["member"].(string)); err != nil {
111111- log.Printf("failed to add member: %v", err)
112112- } else {
113113- log.Printf("added member from firehose: %s", record["member"])
121121+ l.Error("failed to add member", "error", err)
122122+ return fmt.Errorf("failed to add member: %w", err)
123123+ }
124124+ l.Info("added member from firehose", "member", record["member"])
125125+126126+ if err := h.db.AddDid(did); err != nil {
127127+ l.Error("failed to add did", "error", err)
128128+ return fmt.Errorf("failed to add did: %w", err)
114129 }
115130116116- h.fetchAndAddKeys(did)
131131+ if err := h.fetchAndAddKeys(ctx, did); err != nil {
132132+ return fmt.Errorf("failed to fetch and add keys: %w", err)
133133+ }
134134+117135 h.js.UpdateDids([]string{did})
136136+ return nil
118137}
119138120120-func (h *Handle) processMessages(messages <-chan []byte) {
139139+func (h *Handle) processMessages(ctx context.Context, messages <-chan []byte) {
140140+ l := log.FromContext(ctx)
141141+ l.Info("waiting for knot to be initialized")
121142 <-h.init
122122- log.Println("initalized jetstream watcher")
143143+ l.Info("initialized jetstream watcher")
123144124145 for msg := range messages {
125146 var data map[string]interface{}
126147 if err := json.Unmarshal(msg, &data); err != nil {
127127- log.Printf("error unmarshaling message: %v", err)
148148+ l.Error("error unmarshaling message", "error", err)
128149 continue
129150 }
130151···133154 did := data["did"].(string)
134155 record := commit["record"].(map[string]interface{})
135156157157+ var processErr error
136158 switch commit["collection"].(string) {
137159 case tangled.PublicKeyNSID:
138138- h.processPublicKey(did, record)
160160+ if err := h.processPublicKey(ctx, did, record); err != nil {
161161+ processErr = fmt.Errorf("failed to process public key: %w", err)
162162+ }
139163 case tangled.KnotMemberNSID:
140140- h.processKnotMember(did, record)
164164+ if err := h.processKnotMember(ctx, did, record); err != nil {
165165+ processErr = fmt.Errorf("failed to process knot member: %w", err)
166166+ }
167167+ }
168168+169169+ if processErr != nil {
170170+ l.Error("error processing message", "error", processErr)
171171+ continue
141172 }
142173143174 lastTimeUs := int64(data["time_us"].(float64))
144175 if err := h.db.SaveLastTimeUs(lastTimeUs); err != nil {
145145- log.Printf("failed to save last time us: %v", err)
176176+ l.Error("failed to save last time us", "error", err)
177177+ continue
146178 }
147179 }
148180 }
+45-22
knotserver/routes.go
···99 "errors"
1010 "fmt"
1111 "html/template"
1212- "log"
1312 "net/http"
1413 "path/filepath"
1514 "strconv"
···30293130func (h *Handle) RepoIndex(w http.ResponseWriter, r *http.Request) {
3231 path := filepath.Join(h.c.Repo.ScanPath, didPath(r))
3232+ l := h.l.With("path", path, "handler", "RepoIndex")
33333434 gr, err := git.Open(path, "")
3535 if err != nil {
···3737 writeMsg(w, "repo empty")
3838 return
3939 } else {
4040- log.Println(err)
4040+ l.Error("opening repo", "error", err.Error())
4141 notFound(w)
4242 return
4343 }
···4545 commits, err := gr.Commits()
4646 if err != nil {
4747 writeError(w, err.Error(), http.StatusInternalServerError)
4848- log.Println(err)
4848+ l.Error("fetching commits", "error", err.Error())
4949 return
5050 }
5151···7373 }
74747575 if readmeContent == "" {
7676- log.Printf("no readme found for %s", path)
7676+ l.Warn("no readme found")
7777 }
78787979 mainBranch, err := gr.FindMainBranch(h.c.Repo.MainBranch)
8080 if err != nil {
8181 writeError(w, err.Error(), http.StatusInternalServerError)
8282- log.Println(err)
8282+ l.Error("finding main branch", "error", err.Error())
8383 return
8484 }
8585···100100 treePath := chi.URLParam(r, "*")
101101 ref := chi.URLParam(r, "ref")
102102103103+ l := h.l.With("handler", "RepoTree", "ref", ref, "treePath", treePath)
104104+103105 path := filepath.Join(h.c.Repo.ScanPath, didPath(r))
104106 gr, err := git.Open(path, ref)
105107 if err != nil {
···110112 files, err := gr.FileTree(treePath)
111113 if err != nil {
112114 writeError(w, err.Error(), http.StatusInternalServerError)
113113- log.Println(err)
115115+ l.Error("file tree", "error", err.Error())
114116 return
115117 }
116118···133135 treePath := chi.URLParam(r, "*")
134136 ref := chi.URLParam(r, "ref")
135137138138+ l := h.l.With("handler", "FileContent", "ref", ref, "treePath", treePath)
139139+136140 path := filepath.Join(h.c.Repo.ScanPath, didPath(r))
137141 gr, err := git.Open(path, ref)
138142 if err != nil {
···155159 if raw {
156160 h.showRaw(string(safe), w)
157161 } else {
158158- h.showFile(string(safe), data, w)
162162+ h.showFile(string(safe), data, w, l)
159163 }
160164}
161165162166func (h *Handle) Archive(w http.ResponseWriter, r *http.Request) {
163167 name := chi.URLParam(r, "name")
164168 file := chi.URLParam(r, "file")
169169+170170+ l := h.l.With("handler", "Archive", "name", name, "file", file)
165171166172 // TODO: extend this to add more files compression (e.g.: xz)
167173 if !strings.HasSuffix(file, ".tar.gz") {
···192198 if err != nil {
193199 // once we start writing to the body we can't report error anymore
194200 // so we are only left with printing the error.
195195- log.Println(err)
201201+ l.Error("writing tar file", "error", err.Error())
196202 return
197203 }
198204···200206 if err != nil {
201207 // once we start writing to the body we can't report error anymore
202208 // so we are only left with printing the error.
203203- log.Println(err)
209209+ l.Error("flushing?", "error", err.Error())
204210 return
205211 }
206212}
207213208214func (h *Handle) Log(w http.ResponseWriter, r *http.Request) {
209209- fmt.Println(r.URL.Path)
210215 ref := chi.URLParam(r, "ref")
216216+ path := filepath.Join(h.c.Repo.ScanPath, didPath(r))
211217212212- path := filepath.Join(h.c.Repo.ScanPath, didPath(r))
218218+ l := h.l.With("handler", "Log", "ref", ref, "path", path)
219219+213220 gr, err := git.Open(path, ref)
214221 if err != nil {
215222 notFound(w)
···219226 commits, err := gr.Commits()
220227 if err != nil {
221228 writeError(w, err.Error(), http.StatusInternalServerError)
222222- log.Println(err)
229229+ l.Error("fetching commits", "error", err.Error())
223230 return
224231 }
225232···269276func (h *Handle) Diff(w http.ResponseWriter, r *http.Request) {
270277 ref := chi.URLParam(r, "ref")
271278279279+ l := h.l.With("handler", "Diff", "ref", ref)
280280+272281 path := filepath.Join(h.c.Repo.ScanPath, didPath(r))
273282 gr, err := git.Open(path, ref)
274283 if err != nil {
···279288 diff, err := gr.Diff()
280289 if err != nil {
281290 writeError(w, err.Error(), http.StatusInternalServerError)
282282- log.Println(err)
291291+ l.Error("getting diff", "error", err.Error())
283292 return
284293 }
285294···297306298307func (h *Handle) Refs(w http.ResponseWriter, r *http.Request) {
299308 path := filepath.Join(h.c.Repo.ScanPath, didPath(r))
309309+ l := h.l.With("handler", "Refs")
310310+300311 gr, err := git.Open(path, "")
301312 if err != nil {
302313 notFound(w)
···306317 tags, err := gr.Tags()
307318 if err != nil {
308319 // Non-fatal, we *should* have at least one branch to show.
309309- log.Println(err)
320320+ l.Error("getting tags", "error", err.Error())
310321 }
311322312323 branches, err := gr.Branches()
313324 if err != nil {
314314- log.Println(err)
325325+ l.Error("getting branches", "error", err.Error())
315326 writeError(w, err.Error(), http.StatusInternalServerError)
316327 return
317328 }
···327338}
328339329340func (h *Handle) Keys(w http.ResponseWriter, r *http.Request) {
341341+ l := h.l.With("handler", "Keys")
342342+330343 switch r.Method {
331344 case http.MethodGet:
332345 keys, err := h.db.GetAllPublicKeys()
333346 if err != nil {
334347 writeError(w, err.Error(), http.StatusInternalServerError)
335335- log.Println(err)
348348+ l.Error("getting public keys", "error", err.Error())
336349 return
337350 }
338351···358371359372 if err := h.db.AddPublicKey(pk); err != nil {
360373 writeError(w, err.Error(), http.StatusInternalServerError)
361361- log.Printf("adding public key: %s", err)
374374+ l.Error("adding public key", "error", err.Error())
362375 return
363376 }
364377···368381}
369382370383func (h *Handle) NewRepo(w http.ResponseWriter, r *http.Request) {
384384+ l := h.l.With("handler", "NewRepo")
385385+371386 data := struct {
372387 Did string `json:"did"`
373388 Name string `json:"name"`
···385400 repoPath := filepath.Join(h.c.Repo.ScanPath, relativeRepoPath)
386401 err := git.InitBare(repoPath)
387402 if err != nil {
388388- log.Println(err)
403403+ l.Error("initializing bare repo", "error", err.Error())
389404 writeError(w, err.Error(), http.StatusInternalServerError)
390405 return
391406 }
···393408 // add perms for this user to access the repo
394409 err = h.e.AddRepo(did, ThisServer, relativeRepoPath)
395410 if err != nil {
396396- log.Println(err)
411411+ l.Error("adding repo permissions", "error", err.Error())
397412 writeError(w, err.Error(), http.StatusInternalServerError)
398413 return
399414 }
···402417}
403418404419func (h *Handle) AddMember(w http.ResponseWriter, r *http.Request) {
420420+ l := h.l.With("handler", "AddMember")
421421+405422 data := struct {
406423 Did string `json:"did"`
407424 PublicKeys []string `json:"keys"`
···427444428445 h.js.UpdateDids([]string{did})
429446 if err := h.e.AddMember(ThisServer, did); err != nil {
430430- log.Println(err)
447447+ l.Error("adding member", "error", err.Error())
431448 writeError(w, err.Error(), http.StatusInternalServerError)
432449 return
433450 }
···436453}
437454438455func (h *Handle) Init(w http.ResponseWriter, r *http.Request) {
456456+ l := h.l.With("handler", "Init")
457457+439458 if h.knotInitialized {
440459 writeError(w, "knot already initialized", http.StatusConflict)
441460 return
···447466 }{}
448467449468 if err := json.NewDecoder(r.Body).Decode(&data); err != nil {
469469+ l.Error("failed to decode request body", "error", err.Error())
450470 writeError(w, "invalid request body", http.StatusBadRequest)
451471 return
452472 }
453473454474 if data.Did == "" {
475475+ l.Error("empty DID in request")
455476 writeError(w, "did is empty", http.StatusBadRequest)
456477 return
457478 }
···464485 pk.Key = k
465486 err := h.db.AddPublicKey(pk)
466487 if err != nil {
488488+ l.Error("failed to add public key", "error", err.Error())
467489 writeError(w, err.Error(), http.StatusInternalServerError)
468490 return
469491 }
470492 }
471493 } else {
494494+ l.Error("failed to add DID", "error", err.Error())
472495 writeError(w, err.Error(), http.StatusInternalServerError)
473496 return
474497 }
475498476499 h.js.UpdateDids([]string{data.Did})
477500 if err := h.e.AddOwner(ThisServer, data.Did); err != nil {
478478- log.Println(err)
501501+ l.Error("adding owner", "error", err.Error())
479502 writeError(w, err.Error(), http.StatusInternalServerError)
480503 return
481504 }
482482- // Signal that the knot is ready
505505+483506 close(h.init)
484507485508 mac := hmac.New(sha256.New, []byte(h.c.Server.Secret))
+49
log/log.go
···11+package log
22+33+import (
44+ "context"
55+ "log/slog"
66+ "os"
77+)
88+99+// NewHandler sets up a new slog.Handler with the service name
1010+// as an attribute
1111+func NewHandler(name string) slog.Handler {
1212+ handler := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{})
1313+1414+ var attrs []slog.Attr
1515+ attrs = append(attrs, slog.Attr{Key: "service", Value: slog.StringValue(name)})
1616+ handler.WithAttrs(attrs)
1717+ return handler
1818+}
1919+2020+func New(name string) *slog.Logger {
2121+ return slog.New(NewHandler(name))
2222+}
2323+2424+func NewContext(ctx context.Context, name string) context.Context {
2525+ return IntoContext(ctx, New(name))
2626+}
2727+2828+type ctxKey struct{}
2929+3030+// IntoContext adds a logger to a context. Use FromContext to
3131+// pull the logger out.
3232+func IntoContext(ctx context.Context, l *slog.Logger) context.Context {
3333+ return context.WithValue(ctx, ctxKey{}, l)
3434+}
3535+3636+// FromContext returns a logger from a context.Context;
3737+// if the passed context is nil, we return the default slog
3838+// logger.
3939+func FromContext(ctx context.Context) *slog.Logger {
4040+ if ctx != nil {
4141+ v := ctx.Value(ctxKey{})
4242+ if v == nil {
4343+ return slog.Default()
4444+ }
4545+ return v.(*slog.Logger)
4646+ }
4747+4848+ return slog.Default()
4949+}