Merge pull request 'http-logs' (#167) from http-logs into master

Reviewed-on: urdt/ussd#167

.gitignore

@@ -6,3 +6,4 @@ go.work*
 cmd/.state/
 id_*
 *.gdbm
+*.log

cmd/africastalking/main.go

@@ -1,9 +1,13 @@
 package main
 
 import (
+	"bytes"
 	"context"
+	"encoding/json"
 	"flag"
 	"fmt"
+	"io"
+	"log"
 	"net/http"
 	"os"
 	"os/signal"
@@ -27,10 +31,26 @@ import (
 var (
 	logg      = logging.NewVanilla()
 	scriptDir = path.Join("services", "registration")
+	InfoLogger    *log.Logger
+	ErrorLogger   *log.Logger
 )
 
 func init() {
 	initializers.LoadEnvVariables()
+
+	logFile := "urdt-ussd-africastalking.log"
+
+	file, err := os.OpenFile(logFile, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666)
+	if err != nil {
+		log.Fatal(err)
+	}
+
+	InfoLogger = log.New(file, "INFO: ", log.Ldate|log.Ltime|log.Lshortfile)
+	ErrorLogger = log.New(file, "ERROR: ", log.Ldate|log.Ltime|log.Lshortfile)
+
+	// Inject into remote package
+	remote.InfoLogger = InfoLogger
+	remote.ErrorLogger = ErrorLogger
 }
 
 type atRequestParser struct{}
@@ -38,9 +58,30 @@ type atRequestParser struct{}
 func (arp *atRequestParser) GetSessionId(rq any) (string, error) {
 	rqv, ok := rq.(*http.Request)
 	if !ok {
+		ErrorLogger.Println("got an invalid request:", rq)
 		return "", handlers.ErrInvalidRequest
 	}
+
+	// Capture body (if any) for logging
+	body, err := io.ReadAll(rqv.Body)
+	if err != nil {
+		ErrorLogger.Println("failed to read request body:", err)
+		return "", fmt.Errorf("failed to read request body: %v", err)
+	}
+	// Reset the body for further reading
+	rqv.Body = io.NopCloser(bytes.NewReader(body))
+
+	// Log the body as JSON
+	bodyLog := map[string]string{"body": string(body)}
+	logBytes, err := json.Marshal(bodyLog)
+	if err != nil {
+		ErrorLogger.Println("failed to marshal request body:", err)
+	} else {
+		InfoLogger.Println("Received request:", string(logBytes))
+	}
+
 	if err := rqv.ParseForm(); err != nil {
+		ErrorLogger.Println("failed to parse form data: %v", err)
 		return "", fmt.Errorf("failed to parse form data: %v", err)
 	}
 

cmd/async/main.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"flag"
 	"fmt"
+	"log"
 	"os"
 	"os/signal"
 	"path"
@@ -23,12 +24,27 @@ import (
 var (
 	logg      = logging.NewVanilla()
 	scriptDir = path.Join("services", "registration")
+	InfoLogger    *log.Logger
+	ErrorLogger   *log.Logger
 )
 
 func init() {
 	initializers.LoadEnvVariables()
-}
 
+	logFile := "urdt-ussd-async.log"
+
+	file, err := os.OpenFile(logFile, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666)
+	if err != nil {
+		log.Fatal(err)
+	}
+
+	InfoLogger = log.New(file, "INFO: ", log.Ldate|log.Ltime|log.Lshortfile)
+	ErrorLogger = log.New(file, "ERROR: ", log.Ldate|log.Ltime|log.Lshortfile)
+
+	// Inject into remote package
+	remote.InfoLogger = InfoLogger
+	remote.ErrorLogger = ErrorLogger
+}
 type asyncRequestParser struct {
 	sessionId string
 	input     []byte

cmd/http/main.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"flag"
 	"fmt"
+	"log"
 	"net/http"
 	"os"
 	"os/signal"
@@ -26,10 +27,26 @@ import (
 var (
 	logg      = logging.NewVanilla()
 	scriptDir = path.Join("services", "registration")
+	InfoLogger    *log.Logger
+	ErrorLogger   *log.Logger
 )
 
 func init() {
 	initializers.LoadEnvVariables()
+
+	logFile := "urdt-ussd-http.log"
+
+	file, err := os.OpenFile(logFile, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666)
+	if err != nil {
+		log.Fatal(err)
+	}
+
+	InfoLogger = log.New(file, "INFO: ", log.Ldate|log.Ltime|log.Lshortfile)
+	ErrorLogger = log.New(file, "ERROR: ", log.Ldate|log.Ltime|log.Lshortfile)
+
+	// Inject into remote package
+	remote.InfoLogger = InfoLogger
+	remote.ErrorLogger = ErrorLogger
 }
 
 func main() {

cmd/main.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"flag"
 	"fmt"
+	"log"
 	"os"
 	"path"
 
@@ -20,10 +21,26 @@ import (
 var (
 	logg      = logging.NewVanilla()
 	scriptDir = path.Join("services", "registration")
+	InfoLogger    *log.Logger
+	ErrorLogger   *log.Logger
 )
 
 func init() {
 	initializers.LoadEnvVariables()
+
+	logFile := "urdt-ussd-cli.log"
+
+	file, err := os.OpenFile(logFile, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666)
+	if err != nil {
+		log.Fatal(err)
+	}
+
+	InfoLogger = log.New(file, "INFO: ", log.Ldate|log.Ltime|log.Lshortfile)
+	ErrorLogger = log.New(file, "ERROR: ", log.Ldate|log.Ltime|log.Lshortfile)
+
+	// Inject into remote package
+	remote.InfoLogger = InfoLogger
+	remote.ErrorLogger = ErrorLogger
 }
 
 func main() {

remote/accountservice.go

@@ -1,20 +1,24 @@
 package remote
 
 import (
+	"bytes"
 	"context"
 	"encoding/json"
 	"errors"
 	"io"
+	"log"
 	"net/http"
 	"net/url"
 
-	dataserviceapi "github.com/grassrootseconomics/ussd-data-service/pkg/api"
-	"github.com/grassrootseconomics/eth-custodial/pkg/api"
 	"git.grassecon.net/urdt/ussd/config"
 	"git.grassecon.net/urdt/ussd/models"
+	"github.com/grassrootseconomics/eth-custodial/pkg/api"
+	dataserviceapi "github.com/grassrootseconomics/ussd-data-service/pkg/api"
 )
 
 var (
+	InfoLogger  *log.Logger
+	ErrorLogger *log.Logger
 )
 
 type AccountServiceInterface interface {
@@ -51,7 +55,7 @@ func (as *AccountService) TrackAccountStatus(ctx context.Context, publicKey stri
 		return nil, err
 	}
 
-	_, err =  doCustodialRequest(ctx, req, &r)
+	_, err = doCustodialRequest(ctx, req, &r)
 	if err != nil {
 		return nil, err
 	}
@@ -79,7 +83,6 @@ func (as *AccountService) CheckBalance(ctx context.Context, publicKey string) (*
 	return &balanceResult, err
 }
 
-
 // CreateAccount creates a new account in the custodial system.
 // Returns:
 //   - *models.AccountResponse: A pointer to an AccountResponse struct containing the details of the created account.
@@ -93,9 +96,9 @@ func (as *AccountService) CreateAccount(ctx context.Context) (*models.AccountRes
 	if err != nil {
 		return nil, err
 	}
-
+	_, err = doCustodialRequest(ctx, req, &r)
-	_, err =  doCustodialRequest(ctx, req, &r)
 	if err != nil {
+		log.Printf("Failed to make custodial %s request to endpoint: %s with reason: %s", req.Method, req.URL, err.Error())
 		return nil, err
 	}
 
@@ -118,7 +121,7 @@ func (as *AccountService) FetchVouchers(ctx context.Context, publicKey string) (
 		return nil, err
 	}
 
-	_, err =  doDataRequest(ctx, req, r)
+	_, err = doDataRequest(ctx, req, r)
 	if err != nil {
 		return nil, err
 	}
@@ -126,7 +129,6 @@ func (as *AccountService) FetchVouchers(ctx context.Context, publicKey string) (
 	return r, nil
 }
 
-
 // FetchTransactions retrieves the last 10 transactions for a given public key from the data indexer API endpoint
 // Parameters:
 //   - publicKey: The public key associated with the account.
@@ -143,7 +145,7 @@ func (as *AccountService) FetchTransactions(ctx context.Context, publicKey strin
 		return nil, err
 	}
 
-	_, err =  doDataRequest(ctx, req, r)
+	_, err = doDataRequest(ctx, req, r)
 	if err != nil {
 		return nil, err
 	}
@@ -151,7 +153,6 @@ func (as *AccountService) FetchTransactions(ctx context.Context, publicKey strin
 	return r, nil
 }
 
-
 // VoucherData retrieves voucher metadata from the data indexer API endpoint.
 // Parameters:
 //   - address: The voucher address.
@@ -173,9 +174,8 @@ func (as *AccountService) VoucherData(ctx context.Context, address string) (*mod
 }
 
 func doRequest(ctx context.Context, req *http.Request, rcpt any) (*api.OKResponse, error) {
-	var okResponse  api.OKResponse
+	var okResponse api.OKResponse
 	var errResponse api.ErrResponse
-
 	req.Header.Set("Content-Type", "application/json")
 	resp, err := http.DefaultClient.Do(req)
 	if err != nil {
@@ -184,6 +184,7 @@ func doRequest(ctx context.Context, req *http.Request, rcpt any) (*api.OKRespons
 	}
 	defer resp.Body.Close()
 
+	InfoLogger.Printf("Received response for %s: Status Code: %d | Content-Type: %s", req.URL, resp.StatusCode, resp.Header.Get("Content-Type"))
 	body, err := io.ReadAll(resp.Body)
 	if err != nil {
 		return nil, err
@@ -214,10 +215,29 @@ func doRequest(ctx context.Context, req *http.Request, rcpt any) (*api.OKRespons
 
 func doCustodialRequest(ctx context.Context, req *http.Request, rcpt any) (*api.OKResponse, error) {
 	req.Header.Set("X-GE-KEY", config.CustodialAPIKey)
+	logRequestDetails(req)
 	return doRequest(ctx, req, rcpt)
 }
 
 func doDataRequest(ctx context.Context, req *http.Request, rcpt any) (*api.OKResponse, error) {
 	req.Header.Set("X-GE-KEY", config.DataAPIKey)
+	logRequestDetails(req)
 	return doRequest(ctx, req, rcpt)
 }
+
+func logRequestDetails(req *http.Request) {
+	var bodyBytes []byte
+	contentType := req.Header.Get("Content-Type")
+	if req.Body != nil {
+		bodyBytes, err := io.ReadAll(req.Body)
+		if err != nil {
+			ErrorLogger.Printf("Error reading request body: %s", err)
+			return
+		}
+		req.Body = io.NopCloser(bytes.NewBuffer(bodyBytes))
+	} else {
+		bodyBytes = []byte("-")
+	}
+
+	InfoLogger.Printf("URL: %s  | Content-Type: %s | Method: %s| Request Body: %s", req.URL, contentType, req.Method, string(bodyBytes))
+}