chore: Add debug logs (#195)

Add debug logs to Toolbox. 

For example when a http fail, it will just show Error at the http level,
but not log with actual error message. err message are returned to the
api as following `{"status":"Internal Server Error","error":"error while
invoking tool: unable to execute client: spanner: code =
\"InvalidArgument\", desc = \"invalid session pool\""}`.

After adding this, if user/dev run toolbox with `--log-level=debug`, it
will output the following (debug log in addition to the error for http
request):

```
2025-01-08T14:16:25.040824-08:00 DEBUG "error while invoking tool: unable to execute client: spanner: code = \"InvalidArgument\", desc = \"invalid session pool\""

2025-01-08T14:16:25.040968-08:00 ERROR Response: 500 Server Error service: "httplog" httpRequest: {url: "http://127.0.0.1:5000/api/tool/test_tool_two/invoke" method: "POST" path: "/api/tool/test_tool_two/invoke" remoteIP: "127.0.0.1:51708" proto: "HTTP/1.1" requestID: "yuanteoh-macbookpro.roam.internal/N7LNMcLIUH-000001" scheme: "http" header: {user-agent: "curl/8.7.1" accept: "*/*" content-type: "application/json" content-length: "2"}} httpResponse: {status: 500 bytes: 167 elapsed: 0.301917}
```
This commit is contained in:
Yuan
2025-01-12 21:47:46 -08:00
committed by GitHub
parent ae732e637f
commit d65cefc600
2 changed files with 12 additions and 0 deletions

View File

@@ -15,6 +15,7 @@
package server
import (
"context"
"encoding/json"
"fmt"
"io"
@@ -51,6 +52,7 @@ func toolsetHandler(s *Server, w http.ResponseWriter, r *http.Request) {
toolset, ok := s.toolsets[toolsetName]
if !ok {
err := fmt.Errorf("Toolset %q does not exist", toolsetName)
s.logger.DebugContext(context.Background(), err.Error())
_ = render.Render(w, r, newErrResponse(err, http.StatusNotFound))
return
}
@@ -63,6 +65,7 @@ func toolGetHandler(s *Server, w http.ResponseWriter, r *http.Request) {
tool, ok := s.tools[toolName]
if !ok {
err := fmt.Errorf("invalid tool name: tool with name %q does not exist", toolName)
s.logger.DebugContext(context.Background(), err.Error())
_ = render.Render(w, r, newErrResponse(err, http.StatusNotFound))
return
}
@@ -83,6 +86,7 @@ func toolInvokeHandler(s *Server, w http.ResponseWriter, r *http.Request) {
tool, ok := s.tools[toolName]
if !ok {
err := fmt.Errorf("invalid tool name: tool with name %q does not exist", toolName)
s.logger.DebugContext(context.Background(), err.Error())
_ = render.Render(w, r, newErrResponse(err, http.StatusNotFound))
return
}
@@ -94,6 +98,7 @@ func toolInvokeHandler(s *Server, w http.ResponseWriter, r *http.Request) {
claims, err := aS.GetClaimsFromHeader(r.Header)
if err != nil {
err := fmt.Errorf("failure getting claims from header: %w", err)
s.logger.DebugContext(context.Background(), err.Error())
_ = render.Render(w, r, newErrResponse(err, http.StatusBadRequest))
return
}
@@ -115,6 +120,7 @@ func toolInvokeHandler(s *Server, w http.ResponseWriter, r *http.Request) {
isAuthorized := tool.Authorized(verifiedAuthSources)
if !isAuthorized {
err := fmt.Errorf("tool invocation not authorized. Please make sure your specify correct auth headers")
s.logger.DebugContext(context.Background(), err.Error())
_ = render.Render(w, r, newErrResponse(err, http.StatusUnauthorized))
return
}
@@ -123,6 +129,7 @@ func toolInvokeHandler(s *Server, w http.ResponseWriter, r *http.Request) {
if err := decodeJSON(r.Body, &data); err != nil {
render.Status(r, http.StatusBadRequest)
err := fmt.Errorf("request body was invalid JSON: %w", err)
s.logger.DebugContext(context.Background(), err.Error())
_ = render.Render(w, r, newErrResponse(err, http.StatusBadRequest))
return
}
@@ -130,6 +137,7 @@ func toolInvokeHandler(s *Server, w http.ResponseWriter, r *http.Request) {
params, err := tool.ParseParams(data, claimsFromAuth)
if err != nil {
err := fmt.Errorf("provided parameters were invalid: %w", err)
s.logger.DebugContext(context.Background(), err.Error())
_ = render.Render(w, r, newErrResponse(err, http.StatusBadRequest))
return
}
@@ -137,6 +145,7 @@ func toolInvokeHandler(s *Server, w http.ResponseWriter, r *http.Request) {
res, err := tool.Invoke(params)
if err != nil {
err := fmt.Errorf("error while invoking tool: %w", err)
s.logger.DebugContext(context.Background(), err.Error())
_ = render.Render(w, r, newErrResponse(err, http.StatusInternalServerError))
return
}

View File

@@ -175,16 +175,19 @@ func (s *Server) Listen(ctx context.Context) error {
if s.listener, err = lc.Listen(ctx, "tcp", s.srv.Addr); err != nil {
return fmt.Errorf("failed to open listener for %q: %w", s.srv.Addr, err)
}
s.logger.DebugContext(ctx, fmt.Sprintf("server listening on %s", s.srv.Addr))
return nil
}
// Serve starts an HTTP server for the given Server instance.
func (s *Server) Serve() error {
s.logger.DebugContext(context.Background(), "Starting a HTTP server.")
return s.srv.Serve(s.listener)
}
// Shutdown gracefully shuts down the server without interrupting any active
// connections. It uses http.Server.Shutdown() and has the same functionality.
func (s *Server) Shutdown(ctx context.Context) error {
s.logger.DebugContext(context.Background(), "shutting down the server.")
return s.srv.Shutdown(ctx)
}