diff --git a/internal/p9/server.go b/internal/p9/server.go index 323c6fc..4f967df 100644 --- a/internal/p9/server.go +++ b/internal/p9/server.go @@ -47,6 +47,7 @@ import ( "ollie/pkg/agent" "ollie/pkg/backend" "ollie/pkg/config" + olog "ollie/pkg/log" "ollie/pkg/tools" "ollie/pkg/tools/execute" ) @@ -220,7 +221,7 @@ func (s *Server) Serve(conn net.Conn) { fc, err := plan9.ReadFcall(conn) if err != nil { if err != io.EOF { - fmt.Fprintf(os.Stderr, "olliesrv: read: %v\n", err) + plog.Error("read: %v", err) } return } @@ -228,13 +229,7 @@ func (s *Server) Serve(conn net.Conn) { } } -var debug = os.Getenv("OLLIE_9P_DEBUG") != "" - -func dbg(format string, args ...any) { - if debug { - fmt.Fprintf(os.Stderr, "9p: "+format+"\n", args...) - } -} +var plog = olog.New("9p") func (s *Server) handle(cs *connState, fc *plan9.Fcall) *plan9.Fcall { switch fc.Type { @@ -243,12 +238,12 @@ func (s *Server) handle(cs *connState, fc *plan9.Fcall) *plan9.Fcall { if msize > 65536 { msize = 65536 } - dbg("Tversion msize=%d", msize) + plog.Debug("Tversion msize=%d", msize) return &plan9.Fcall{Type: plan9.Rversion, Tag: fc.Tag, Msize: msize, Version: "9P2000"} case plan9.Tauth: return errFcall(fc, "no auth required") case plan9.Tattach: - dbg("Tattach fid=%d", fc.Fid) + plog.Debug("Tattach fid=%d", fc.Fid) return s.attach(cs, fc) case plan9.Twalk: return s.walk(cs, fc) @@ -408,7 +403,7 @@ func (s *Server) walk(cs *connState, fc *plan9.Fcall) *plan9.Fcall { return &plan9.Fcall{Type: plan9.Rwalk, Tag: fc.Tag, Wqid: []plan9.Qid{}} } - dbg("Twalk fid=%d newfid=%d from=%q wnames=%v", fc.Fid, fc.Newfid, f.path, fc.Wname) + plog.Debug("Twalk fid=%d newfid=%d from=%q wnames=%v", fc.Fid, fc.Newfid, f.path, fc.Wname) wqids := make([]plan9.Qid, 0, len(fc.Wname)) cur := f.path @@ -456,7 +451,7 @@ func (s *Server) open(cs *connState, fc *plan9.Fcall) *plan9.Fcall { } f.mode = fc.Mode - dbg("Topen fid=%d path=%q mode=%d", fc.Fid, f.path, fc.Mode) + plog.Debug("Topen fid=%d path=%q mode=%d", fc.Fid, f.path, fc.Mode) return &plan9.Fcall{Type: plan9.Ropen, Tag: fc.Tag, Qid: f.qid} } @@ -473,7 +468,7 @@ func (s *Server) create(cs *connState, fc *plan9.Fcall) *plan9.Fcall { } newPath := pathJoin(f.path, fc.Name) - dbg("Tcreate parent=%q name=%q", f.path, fc.Name) + plog.Debug("Tcreate parent=%q name=%q", f.path, fc.Name) // (e.g. touch) produces a real file. switch f.path { case "/a": @@ -517,34 +512,34 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { cs.mu.RUnlock() if isDir { - dbg("Tread dir path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread dir path=%q offset=%d count=%d", path, fc.Offset, fc.Count) data := s.readDir(path, fc.Offset, fc.Count) - dbg("Rread dir path=%q len=%d", path, len(data)) + plog.Debug("Rread dir path=%q len=%d", path, len(data)) return &plan9.Fcall{Type: plan9.Rread, Tag: fc.Tag, Count: uint32(len(data)), Data: data} } // s/new and s/idx are served from the session store. if path == "/s/new" || path == "/s/idx" { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content, err := s.sessionStore.Get(pathBase(path)) if err != nil { - dbg("Rread path=%q err=%v", path, err) + plog.Debug("Rread path=%q err=%v", path, err) return errFcall(fc, err.Error()) } - dbg("Rread path=%q content_len=%d", path, len(content)) + plog.Debug("Rread path=%q content_len=%d", path, len(content)) return s.readSlice(fc, content) } // backends is a static list of ollie-provided backends. if path == "/backends" { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content := []byte(strings.Join(backend.Backends(), "\n") + "\n") return s.readSlice(fc, content) } // help is served from ~/.config/ollie/help.md. if path == "/help" { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content, err := os.ReadFile(s.helpPath()) if err != nil { return errFcall(fc, err.Error()) @@ -554,7 +549,7 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { // Agent config files are served from the agent store. if strings.HasPrefix(path, "/a/") { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content, err := s.agentStore.Get(pathBase(path)) if err != nil { return errFcall(fc, err.Error()) @@ -564,7 +559,7 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { // Prompt files are served from the prompt store. if strings.HasPrefix(path, "/p/") { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content, err := s.promptStore.Get(pathBase(path)) if err != nil { return errFcall(fc, err.Error()) @@ -574,7 +569,7 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { // Memory files are served from the memory store. if strings.HasPrefix(path, "/m/") { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content, err := s.memStore.Get(pathBase(path)) if err != nil { return errFcall(fc, err.Error()) @@ -584,7 +579,7 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { // Plan files are served from the plan store. if strings.HasPrefix(path, "/pl/") { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content, err := s.planStore.Get(pathBase(path)) if err != nil { return errFcall(fc, err.Error()) @@ -594,7 +589,7 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { // Skill files are served from the skill store. if strings.HasPrefix(path, "/sk/") { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content, err := s.skillStore.Get(pathBase(path)) if err != nil { return errFcall(fc, err.Error()) @@ -604,7 +599,7 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { // Tool files are served from the tool store. if strings.HasPrefix(path, "/t/") { - dbg("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread path=%q offset=%d count=%d", path, fc.Offset, fc.Count) content, err := s.toolStore.Get(pathBase(path)) if err != nil { return errFcall(fc, err.Error()) @@ -616,10 +611,10 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { if strings.HasPrefix(path, "/s/") { parts := strings.SplitN(strings.TrimPrefix(path, "/"), "/", 3) if len(parts) == 3 { - dbg("Tread session file path=%q offset=%d count=%d", path, fc.Offset, fc.Count) + plog.Debug("Tread session file path=%q offset=%d count=%d", path, fc.Offset, fc.Count) store, ok := s.sessionFileStore(parts[1]) if !ok { - dbg("Rread session not found: %s", parts[1]) + plog.Debug("Rread session not found: %s", parts[1]) return &plan9.Fcall{Type: plan9.Rread, Tag: fc.Tag, Count: 0} } // dequeue: non-zero offset is the trailing EOF read after a successful pop. @@ -628,14 +623,14 @@ func (s *Server) read(cs *connState, fc *plan9.Fcall) *plan9.Fcall { } content, err := store.Get(parts[2]) if err != nil { - dbg("Rread session file err=%v", err) + plog.Debug("Rread session file err=%v", err) return errFcall(fc, err.Error()) } - dbg("Rread session file path=%q content_len=%d", path, len(content)) + plog.Debug("Rread session file path=%q content_len=%d", path, len(content)) return s.readSlice(fc, content) } } - dbg("Tread unhandled path=%q", path) + plog.Debug("Tread unhandled path=%q", path) return &plan9.Fcall{Type: plan9.Rread, Tag: fc.Tag, Count: 0} } @@ -667,7 +662,7 @@ func (s *Server) write(cs *connState, fc *plan9.Fcall) *plan9.Fcall { cs.mu.Unlock() return errFcall(fc, "bad fid") } - dbg("Twrite fid=%d path=%q offset=%d len=%d", fc.Fid, f.path, fc.Offset, len(fc.Data)) + plog.Debug("Twrite fid=%d path=%q offset=%d len=%d", fc.Fid, f.path, fc.Offset, len(fc.Data)) // Accumulate; the 9P client may split large writes across multiple Twrite messages. end := int(fc.Offset) + len(fc.Data) if end > len(f.writeBuf) { @@ -688,7 +683,7 @@ func (s *Server) stat(cs *connState, fc *plan9.Fcall) *plan9.Fcall { return errFcall(fc, "bad fid") } dir := s.makeStat(f.path) - dbg("Tstat path=%q mode=%o len=%d", f.path, dir.Mode, dir.Length) + plog.Debug("Tstat path=%q mode=%o len=%d", f.path, dir.Mode, dir.Length) stat, err := dir.Bytes() if err != nil { return errFcall(fc, err.Error()) @@ -712,7 +707,7 @@ func (s *Server) wstat(cs *connState, fc *plan9.Fcall) *plan9.Fcall { } oldName := pathBase(f.path) - dbg("Twstat path=%q oldName=%q newName=%q", f.path, oldName, newDir.Name) + plog.Debug("Twstat path=%q oldName=%q newName=%q", f.path, oldName, newDir.Name) if newDir.Name == "" || newDir.Name == oldName { return &plan9.Fcall{Type: plan9.Rwstat, Tag: fc.Tag} } @@ -828,7 +823,7 @@ func (s *Server) renameSession(oldID, newID string) error { } sess.appendChat([]byte(fmt.Sprintf("(session renamed: %s -> %s)\n", oldID, newID))) - fmt.Fprintf(os.Stderr, "olliesrv: renamed session %s -> %s\n", oldID, newID) + plog.Info("renamed session %s -> %s", oldID, newID) return nil } @@ -847,16 +842,16 @@ func (s *Server) clunk(cs *connState, fc *plan9.Fcall) *plan9.Fcall { } cs.mu.Unlock() if len(data) > 0 { - dbg("Tclunk flush path=%q writeBuf=%d", path, len(data)) + plog.Debug("Tclunk flush path=%q writeBuf=%d", path, len(data)) input := strings.TrimSpace(string(data)) if s.isAsyncWrite(path) { go s.handleWrite(path, input) //nolint:errcheck } else if err := s.handleWrite(path, input); err != nil { - dbg("Tclunk handleWrite err=%v", err) + plog.Debug("Tclunk handleWrite err=%v", err) return errFcall(fc, err.Error()) } } else { - dbg("Tclunk fid=%d path=%q (no write)", fc.Fid, path) + plog.Debug("Tclunk fid=%d path=%q (no write)", fc.Fid, path) } return &plan9.Fcall{Type: plan9.Rclunk, Tag: fc.Tag} } @@ -886,7 +881,7 @@ func (s *Server) remove(cs *connState, fc *plan9.Fcall) *plan9.Fcall { } path := f.path - dbg("Tremove path=%q", path) + plog.Debug("Tremove path=%q", path) var err error switch { case strings.HasPrefix(path, "/a/"): @@ -922,7 +917,7 @@ func (s *Server) remove(cs *connState, fc *plan9.Fcall) *plan9.Fcall { // Called synchronously from clunk; prompt writes are the exception (spawned // as a goroutine because they block for the entire agent turn). func (s *Server) handleWrite(path, input string) error { - dbg("handleWrite path=%q input_len=%d", path, len(input)) + plog.Debug("handleWrite path=%q input_len=%d", path, len(input)) if input == "" { return nil } @@ -973,7 +968,7 @@ func (s *Server) handleWrite(path, input string) error { // handleNewSession parses KV pairs (one per line or space-separated) and creates a session. func (s *Server) handleNewSession(input string) error { - dbg("handleNewSession input=%q", input) + plog.Debug("handleNewSession input=%q", input) // Accept both newline-separated and space-separated KV pairs. args := strings.Fields(input) return s.createSession(args) @@ -1100,7 +1095,7 @@ func (s *Server) createSession(args []string) error { s.sessions[sessID] = sess s.mu.Unlock() - fmt.Fprintf(os.Stderr, "olliesrv: new session %s (backend=%s model=%s agent=%s)\n", + plog.Info("new session %s (backend=%s model=%s agent=%s)", sessID, core.BackendName(), core.ModelName(), core.AgentName()) return nil } @@ -1126,7 +1121,7 @@ func (s *Server) killSession(id string) { if sess != nil { sess.cancel() sess.core.Close() - fmt.Fprintf(os.Stderr, "olliesrv: killed session %s\n", id) + plog.Info("killed session %s", id) } } diff --git a/internal/p9/sessionfilestore.go b/internal/p9/sessionfilestore.go index 6d3180b..f20271b 100644 --- a/internal/p9/sessionfilestore.go +++ b/internal/p9/sessionfilestore.go @@ -216,7 +216,7 @@ func (s *SessionFileStore) handleCtl(input string) error { case "rn": if name := strings.TrimSpace(input[3:]); name != "" { if err := s.rename(name); err != nil { - fmt.Fprintf(os.Stderr, "olliesrv: rename: %v\n", err) + plog.Error("rename: %v", err) } } case "compact", "clear", "backend", "model", "models",