Added basic logging for GraphQL and HTTP (#107)

tavern/app.go

@@ -4,13 +4,16 @@ import (
 	"context"
 	"crypto/ed25519"
 	"crypto/rand"
+	"encoding/json"
 	"fmt"
 	"log"
 	"net/http"
+	"os"
 
 	"github.com/kcarretto/realm/contrib/tomes"
 
 	"entgo.io/contrib/entgql"
+	gqlgraphql "github.com/99designs/gqlgen/graphql"
 	"github.com/99designs/gqlgen/graphql/handler"
 	"github.com/99designs/gqlgen/graphql/handler/debug"
 	"github.com/99designs/gqlgen/graphql/playground"
@@ -106,6 +109,26 @@ func NewServer(ctx context.Context, options ...func(*Config)) (*Server, error) {
 	srv.Use(entgql.Transactioner{TxOpener: client})
 	srv.Use(&debug.Tracer{})
 
+	// GraphQL Logging
+	gqlLogger := log.New(os.Stderr, "[GraphQL] ", log.Flags())
+	srv.AroundOperations(func(ctx context.Context, next gqlgraphql.OperationHandler) gqlgraphql.ResponseHandler {
+		oc := gqlgraphql.GetOperationContext(ctx)
+		reqVars, err := json.Marshal(oc.Variables)
+		if err != nil {
+			gqlLogger.Printf("[ERROR] failed to marshal variables to JSON: %v", err)
+			return next(ctx)
+		}
+
+		authName := "unknown"
+		id := auth.IdentityFromContext(ctx)
+		if id != nil {
+			authName = id.String()
+		}
+
+		gqlLogger.Printf("%s (%s): %s", oc.OperationName, authName, string(reqVars))
+		return next(ctx)
+	})
+
 	// Setup HTTP Handler
 	router := http.NewServeMux()
 	router.Handle("/status", newStatusHandler())
@@ -122,12 +145,25 @@ func NewServer(ctx context.Context, options ...func(*Config)) (*Server, error) {
 	router.Handle("/cdn/", cdn.NewDownloadHandler(client))
 	router.Handle("/cdn/upload", cdn.NewUploadHandler(client))
 
+	// Log Middleware
+	httpLogger := log.New(os.Stderr, "[HTTP] ", log.Flags())
+	handlerWithLogging := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+		authName := "unknown"
+		id := auth.IdentityFromContext(r.Context())
+		if id != nil {
+			authName = id.String()
+		}
+
+		httpLogger.Printf("%s (%s) %s %s\n", r.RemoteAddr, authName, r.Method, r.URL)
+		router.ServeHTTP(w, r)
+	})
+
 	// Auth Middleware
 	var endpoint http.Handler
 	if cfg.oauth.ClientID != "" {
-		endpoint = auth.Middleware(router, cfg.client)
+		endpoint = auth.Middleware(handlerWithLogging, cfg.client)
 	} else {
-		endpoint = auth.AuthDisabledMiddleware(router)
+		endpoint = auth.AuthDisabledMiddleware(handlerWithLogging)
 	}
 
 	// Initialize HTTP Server

tavern/auth/authtest/identity.go

@@ -7,6 +7,11 @@ type TestIdentity struct {
 	Admin         bool
 }
 
+// String representation of a TestIdentity will be reported as "test_identity".
+func (t TestIdentity) String() string {
+	return "test_identity"
+}
+
 // IsAuthenticated returns true if the test has configured it to.
 func (t TestIdentity) IsAuthenticated() bool {
 	return t.Authenticated

tavern/auth/context.go

@@ -18,6 +18,9 @@ type ctxKey struct{}
 
 // An Identity making a request.
 type Identity interface {
+	// String representation of the identity, used for logging
+	String() string
+
 	// IsAuthenticated should only return true if the identity has been authenticated.
 	IsAuthenticated() bool
 
@@ -34,6 +37,11 @@ type userIdentity struct {
 	*ent.User
 }
 
+// String returns the underlying user identities username.
+func (u *userIdentity) String() string {
+	return u.Name
+}
+
 // IsAuthenticated returns true if the user has been authenticated.
 func (u *userIdentity) IsAuthenticated() bool {
 	if u == nil || u.User == nil {
@@ -75,6 +83,16 @@ func ContextFromSessionToken(ctx context.Context, graph *ent.Client, token strin
 	return ContextFromIdentity(ctx, &userIdentity{true, u}), nil
 }
 
+// IdentityFromContext returns the identity associated with the provided context, or nil if no identity is associated.
+func IdentityFromContext(ctx context.Context) Identity {
+	val := ctx.Value(ctxKey{})
+	id, ok := val.(Identity)
+	if !ok {
+		return nil
+	}
+	return id
+}
+
 // IsAuthenticatedContext returns true if the context is associated with an authenticated identity, false otherwise.
 func IsAuthenticatedContext(ctx context.Context) bool {
 	v, ok := ctx.Value(ctxKey{}).(Identity)

tavern/auth/middleware.go

@@ -9,6 +9,7 @@ import (
 // authDisabledIdentity is used whenever authentication has been disabled.
 type authDisabledIdentity struct{}
 
+func (id authDisabledIdentity) String() string        { return "auth_disabled" }
 func (id authDisabledIdentity) IsAuthenticated() bool { return true }
 func (id authDisabledIdentity) IsActivated() bool     { return true }
 func (id authDisabledIdentity) IsAdmin() bool         { return true }