Adding api-logs-enabled flag (#734)

api/api.go

@@ -12,6 +12,7 @@ import (
 
 	"github.com/gorilla/handlers"
 	"github.com/gorilla/mux"
+	"github.com/inconshreveable/log15"
 	"github.com/vechain/thor/v2/api/accounts"
 	"github.com/vechain/thor/v2/api/blocks"
 	"github.com/vechain/thor/v2/api/debug"
@@ -29,6 +30,8 @@ import (
 	"github.com/vechain/thor/v2/txpool"
 )
 
+var log = log15.New("pkg", "api")
+
 // New return api router
 func New(
 	repo *chain.Repository,
@@ -43,6 +46,7 @@ func New(
 	pprofOn bool,
 	skipLogs bool,
 	allowCustomTracer bool,
+	isReqLoggerEnabled bool,
 	forkConfig thor.ForkConfig,
 ) (http.HandlerFunc, func()) {
 	origins := strings.Split(strings.TrimSpace(allowedOrigins), ",")
@@ -92,11 +96,15 @@ func New(
 	}
 
 	handler := handlers.CompressHandler(router)
+	if isReqLoggerEnabled {
+		handler = RequestLoggerHandler(handler, log)
+	}
+
 	handler = handlers.CORS(
 		handlers.AllowedOrigins(origins),
 		handlers.AllowedHeaders([]string{"content-type", "x-genesis-id"}),
 		handlers.ExposedHeaders([]string{"x-genesis-id", "x-thorest-ver"}),
 	)(handler)
-	return handler.ServeHTTP,
-		subs.Close // subscriptions handles hijacked conns, which need to be closed
+
+	return handler.ServeHTTP, subs.Close // subscriptions handles hijacked conns, which need to be closed
 }

api/request_logger.go

@@ -0,0 +1,47 @@
+// Copyright (c) 2024 The VeChainThor developers
+
+// Distributed under the GNU Lesser General Public License v3.0 software license, see the accompanying
+// file LICENSE or <https://www.gnu.org/licenses/lgpl-3.0.html>
+
+package api
+
+import (
+	"bytes"
+	"io"
+	"net/http"
+	"time"
+
+	"github.com/inconshreveable/log15"
+)
+
+// RequestLoggerHandler returns a http handler to ensure requests are syphoned into the writer
+func RequestLoggerHandler(handler http.Handler, logger log15.Logger) http.Handler {
+	fn := func(w http.ResponseWriter, r *http.Request) {
+		// Read and log the body (note: this can only be done once)
+		// Ensure you don't disrupt the request body for handlers that need to read it
+		var bodyBytes []byte
+		var err error
+		if r.Body != nil {
+			bodyBytes, err = io.ReadAll(r.Body)
+			if err != nil {
+				logger.Warn("unexpected body read error", "err", err)
+				return // don't pass bad request to the next handler
+			}
+			r.Body = io.NopCloser(io.Reader(bytes.NewReader(bodyBytes)))
+		}
+
+		logger.Info("API Request",
+			"timestamp", time.Now().Unix(),
+			"URI", r.URL.String(),
+			"Method", r.Method,
+			"Body", string(bodyBytes),
+		)
+
+		// call the original http.Handler we're wrapping
+		handler.ServeHTTP(w, r)
+	}
+
+	// http.HandlerFunc wraps a function so that it
+	// implements http.Handler interface
+	return http.HandlerFunc(fn)
+}

api/request_logger_test.go

@@ -0,0 +1,95 @@
+// Copyright (c) 2024 The VeChainThor developers
+
+// Distributed under the GNU Lesser General Public License v3.0 software license, see the accompanying
+// file LICENSE or <https://www.gnu.org/licenses/lgpl-3.0.html>
+package api
+
+import (
+	"net/http"
+	"net/http/httptest"
+	"strings"
+	"testing"
+
+	"github.com/inconshreveable/log15"
+	"github.com/stretchr/testify/assert"
+)
+
+// mockLogger is a simple logger implementation for testing purposes
+type mockLogger struct {
+	loggedData []interface{}
+}
+
+func (m *mockLogger) New(ctx ...interface{}) log15.Logger { return m }
+
+func (m *mockLogger) GetHandler() log15.Handler { return nil }
+
+func (m *mockLogger) SetHandler(h log15.Handler) {}
+
+func (m *mockLogger) Debug(msg string, ctx ...interface{}) {}
+
+func (m *mockLogger) Error(msg string, ctx ...interface{}) {}
+
+func (m *mockLogger) Crit(msg string, ctx ...interface{}) {}
+
+func (m *mockLogger) Info(msg string, ctx ...interface{}) {
+	m.loggedData = append(m.loggedData, ctx...)
+}
+
+func (m *mockLogger) Warn(msg string, ctx ...interface{}) {
+	m.loggedData = append(m.loggedData, ctx...)
+}
+
+func (m *mockLogger) GetLoggedData() []interface{} {
+	return m.loggedData
+}
+
+func TestRequestLoggerHandler(t *testing.T) {
+	mockLog := &mockLogger{}
+
+	// Define a test handler to wrap
+	testHandler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		w.WriteHeader(http.StatusOK)
+		w.Write([]byte("OK"))
+	})
+
+	// Create the RequestLoggerHandler
+	loggerHandler := RequestLoggerHandler(testHandler, mockLog)
+
+	// Create a test HTTP request
+	reqBody := "test body"
+	req := httptest.NewRequest("POST", "http://example.com/foo", strings.NewReader(reqBody))
+	req.Header.Set("Content-Type", "application/json")
+
+	// Create a ResponseRecorder to record the response
+	rr := httptest.NewRecorder()
+
+	// Serve the HTTP request
+	loggerHandler.ServeHTTP(rr, req)
+
+	// Check the response status code
+	assert.Equal(t, http.StatusOK, rr.Code)
+
+	// Check the response body
+	assert.Equal(t, "OK", rr.Body.String())
+
+	// Verify that the logger recorded the correct information
+	loggedData := mockLog.GetLoggedData()
+	assert.Contains(t, loggedData, "URI")
+	assert.Contains(t, loggedData, "http://example.com/foo")
+	assert.Contains(t, loggedData, "Method")
+	assert.Contains(t, loggedData, "POST")
+	assert.Contains(t, loggedData, "Body")
+	assert.Contains(t, loggedData, reqBody)
+
+	// Check if timestamp is present
+	foundTimestamp := false
+	for i := 0; i < len(loggedData); i += 2 {
+		if loggedData[i] == "timestamp" {
+			_, ok := loggedData[i+1].(int64)
+			assert.True(t, ok, "timestamp should be an int64")
+			foundTimestamp = true
+			break
+		}
+	}
+	assert.True(t, foundTimestamp, "timestamp should be logged")
+}

cmd/thor/flags.go

@@ -59,6 +59,10 @@ var (
 		Name:  "api-allow-custom-tracer",
 		Usage: "allow custom JS tracer to be used tracer API",
 	}
+	apiLogsEnabledFlag = cli.BoolFlag{
+		Name:  "enable-api-logs",
+		Usage: "enables API requests logging",
+	}
 	verbosityFlag = cli.IntFlag{
 		Name:  "verbosity",
 		Value: int(log15.LvlInfo),

cmd/thor/main.go

@@ -78,6 +78,7 @@ func main() {
 			apiCallGasLimitFlag,
 			apiBacktraceLimitFlag,
 			apiAllowCustomTracerFlag,
+			apiLogsEnabledFlag,
 			verbosityFlag,
 			maxPeersFlag,
 			p2pPortFlag,
@@ -104,6 +105,7 @@ func main() {
 					apiCallGasLimitFlag,
 					apiBacktraceLimitFlag,
 					apiAllowCustomTracerFlag,
+					apiLogsEnabledFlag,
 					onDemandFlag,
 					persistFlag,
 					gasLimitFlag,
@@ -210,6 +212,7 @@ func defaultAction(ctx *cli.Context) error {
 		ctx.Bool(pprofFlag.Name),
 		skipLogs,
 		ctx.Bool(apiAllowCustomTracerFlag.Name),
+		ctx.Bool(apiLogsEnabledFlag.Name),
 		forkConfig)
 	defer func() { log.Info("closing API..."); apiCloser() }()
 
@@ -279,6 +282,7 @@ func soloAction(ctx *cli.Context) error {
 			return err
 		}
 		defer func() { log.Info("closing main database..."); mainDB.Close() }()
+
 		if logDB, err = openLogDB(ctx, instanceDir); err != nil {
 			return err
 		}
@@ -323,14 +327,18 @@ func soloAction(ctx *cli.Context) error {
 		ctx.Bool(pprofFlag.Name),
 		skipLogs,
 		ctx.Bool(apiAllowCustomTracerFlag.Name),
+		ctx.Bool(apiLogsEnabledFlag.Name),
 		forkConfig)
 	defer func() { log.Info("closing API..."); apiCloser() }()
 
 	apiURL, srvCloser, err := startAPIServer(ctx, apiHandler, repo.GenesisBlock().Header().ID())
 	if err != nil {
 		return err
 	}
-	defer func() { log.Info("stopping API server..."); srvCloser() }()
+	defer func() {
+		log.Info("stopping API server...")
+		srvCloser()
+	}()
 
 	printSoloStartupMessage(gene, repo, instanceDir, apiURL, forkConfig)