Merge pull request #35 from BuoyantIO/flynn/dev/user-propagation

Fix user propagation

cmd/generic/color/color.go

@@ -28,6 +28,7 @@ import (
 	"fmt"
 
 	"github.com/BuoyantIO/faces-demo/v2/pkg/faces"
+	"github.com/BuoyantIO/faces-demo/v2/pkg/utils"
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/codes"
 	"google.golang.org/grpc/metadata"
@@ -45,18 +46,33 @@ type colorServer struct {
 	provider *faces.ColorProvider
 }
 
-func (srv *colorServer) Center(ctx context.Context, req *faces.ColorRequest) (*faces.ColorResponse, error) {
+func (srv *colorServer) GetUserName(ctx context.Context) (string, error) {
 	md, ok := metadata.FromIncomingContext(ctx)
 
 	if !ok {
-		return nil, status.Errorf(codes.DataLoss, "failed to get metadata")
+		return "", status.Errorf(codes.DataLoss, "failed to get metadata")
+	}
+
+	user := ""
+	users := md.Get(srv.provider.BaseProvider.GetUserHeaderName())
+
+	if len(users) > 0 {
+		user = users[0]
 	}
 
-	user := md.Get("user")
+	return user, nil
+}
+
+func (srv *colorServer) Center(ctx context.Context, req *faces.ColorRequest) (*faces.ColorResponse, error) {
+	user, err := srv.GetUserName(ctx)
+
+	if err != nil {
+		return nil, err
+	}
 
 	baseResp := srv.provider.Get(int(req.Row), int(req.Column))
 
-	slog.Debug(fmt.Sprintf("CENTER: %d, %d (%s) => %d, %s\n", req.Row, req.Column, user, baseResp.StatusCode, baseResp.Body))
+	srv.provider.Debugf("CENTER: %d, %d (%s) => %d, %s\n", req.Row, req.Column, user, baseResp.StatusCode, baseResp.Body)
 
 	switch baseResp.StatusCode {
 	case http.StatusOK:
@@ -75,22 +91,15 @@ func (srv *colorServer) Center(ctx context.Context, req *faces.ColorRequest) (*f
 }
 
 func (srv *colorServer) Edge(ctx context.Context, req *faces.ColorRequest) (*faces.ColorResponse, error) {
-	md, ok := metadata.FromIncomingContext(ctx)
-
-	if !ok {
-		return nil, status.Errorf(codes.DataLoss, "failed to get metadata")
-	}
+	user, err := srv.GetUserName(ctx)
 
-	user := ""
-	users := md.Get("x-faces-user")
-
-	if len(users) > 0 {
-		user = users[0]
+	if err != nil {
+		return nil, err
 	}
 
 	baseResp := srv.provider.Get(int(req.Row), int(req.Column))
 
-	slog.Debug(fmt.Sprintf("EDGE: %d, %d (%s) => %d, %s\n", req.Row, req.Column, user, baseResp.StatusCode, baseResp.Body))
+	srv.provider.Debugf("EDGE: %d, %d (%s) => %d, %s\n", req.Row, req.Column, user, baseResp.StatusCode, baseResp.Body)
 
 	switch baseResp.StatusCode {
 	case http.StatusOK:
@@ -118,7 +127,9 @@ func main() {
 	logger := slog.New(slog.NewTextHandler(os.Stdout, slogOpts))
 	slog.SetDefault(logger)
 
-	logLevel.Set(slog.LevelDebug)
+	if utils.BoolFromEnv("DEBUG_ENABLED", false) {
+		logLevel.Set(slog.LevelDebug)
+	}
 
 	// Define a command-line flag for the port number
 	port := flag.Int("port", 8000, "the port number to listen on")

go.mod

@@ -11,8 +11,9 @@ require (
 )
 
 require (
+	github.com/stretchr/testify v1.9.0 // indirect
 	golang.org/x/net v0.28.0 // indirect
-	golang.org/x/sys v0.24.0 // indirect
+	golang.org/x/sys v0.27.0 // indirect
 	golang.org/x/text v0.17.0 // indirect
 	google.golang.org/genproto/googleapis/rpc v0.0.0-20240814211410-ddb44dafa142 // indirect
 )

go.sum

@@ -6,16 +6,16 @@ github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
 github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
 github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
-github.com/stretchr/testify v1.8.2 h1:+h33VjcLVPDHtOdpUCuF+7gSuG3yGIftsP1YvFihtJ8=
-github.com/stretchr/testify v1.8.2/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
+github.com/stretchr/testify v1.9.0 h1:HtqpIVDClZ4nwg75+f6Lvsy/wHu+3BoSGCbBAcpTsTg=
+github.com/stretchr/testify v1.9.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY=
 github.com/warthog618/go-gpiosim v0.1.0 h1:2rTMTcKUVZxpUuvRKsagnKAbKpd3Bwffp87xywEDVGI=
 github.com/warthog618/go-gpiosim v0.1.0/go.mod h1:Ngx/LYI5toxHr4E+Vm6vTgCnt0of0tktsSuMUEJ2wCI=
 github.com/warthog618/gpiod v0.8.2 h1:2HgQ9pNowPp7W77sXhX5ut5Tqq1WoS3t7bXYDxtYvxc=
 github.com/warthog618/gpiod v0.8.2/go.mod h1:O7BNpHjCn/4YS5yFVmoFZAlY1LuYuQ8vhPf0iy/qdi4=
 golang.org/x/net v0.28.0 h1:a9JDOJc5GMUJ0+UDqmLT86WiEy7iWyIhz8gz8E4e5hE=
 golang.org/x/net v0.28.0/go.mod h1:yqtgsTWOOnlGLG9GFRrK3++bGOUEkNBoHZc8MEDWPNg=
-golang.org/x/sys v0.24.0 h1:Twjiwq9dn6R1fQcyiK+wQyHWfaz/BJB+YIpzU/Cv3Xg=
-golang.org/x/sys v0.24.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
+golang.org/x/sys v0.27.0 h1:wBqf8DvsY9Y/2P8gAfPDEYNuS30J4lPHJxXSb/nJZ+s=
+golang.org/x/sys v0.27.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
 golang.org/x/text v0.17.0 h1:XtiM5bkSOt+ewxlOE/aE/AKEHibwj/6gvWMl9Rsh0Qc=
 golang.org/x/text v0.17.0/go.mod h1:BuEKDfySbSR4drPmRPG/7iBdf8hvFMuRexcpahXilzY=
 google.golang.org/genproto/googleapis/rpc v0.0.0-20240814211410-ddb44dafa142 h1:e7S5W7MGGLaSu8j3YjdezkZ+m1/Nm0uRVRMEMGk26Xs=

pkg/faces/base_provider.go

@@ -127,6 +127,10 @@ func (bprv *BaseProvider) SetLatched(latched bool) {
 	bprv.latched = latched
 }
 
+func (bprv *BaseProvider) GetUserHeaderName() string {
+	return bprv.userHeaderName
+}
+
 // CheckUnlatch checks to see if we should unlatch the provider.
 func (bprv *BaseProvider) CheckUnlatch(now time.Time) {
 	bprv.lock.Lock()

pkg/faces/color_provider.go

@@ -42,7 +42,7 @@ func NewColorProviderFromEnvironment() *ColorProvider {
 	colorName := utils.StringFromEnv("COLOR", "blue")
 	cprv.color = Colors.Lookup(colorName)
 
-	cprv.Infof("Using %s => %s\n", colorName, cprv.color)
+	cprv.Infof("Using %s => %s", colorName, cprv.color)
 	return cprv
 }
 
@@ -75,7 +75,7 @@ func (cprv *ColorProvider) Get(row, col int) ProviderResponse {
 		resp.StatusCode = rstat.StatusCode()
 		resp.Body = msg
 	} else {
-		cprv.Infof("OK(%d, %d) => %d, %s\n", row, col, rstat.StatusCode(), cprv.color)
+		cprv.Debugf("OK(%d, %d) => %d, %s\n", row, col, rstat.StatusCode(), cprv.color)
 
 		resp.StatusCode = rstat.StatusCode()
 		resp.Body = cprv.color

pkg/faces/faceserver.go

@@ -95,7 +95,8 @@ func (srv *FaceServer) makeRequest(user string, userAgent string, service string
 	url := fmt.Sprintf("http://%s/%s/?row=%d&col=%d", service, subrequest, row, col)
 
 	if srv.debugEnabled {
-		fmt.Printf("%s %s: %s starting\n", time.Now().Format(time.RFC3339), srv.Name, url)
+		fmt.Printf("%s %s: HTTP starting (%s, r%d c%d, %s) %s\n",
+			time.Now().Format(time.RFC3339), srv.Name, subrequest, row, col, user, url)
 	}
 
 	failed := false
@@ -131,7 +132,7 @@ func (srv *FaceServer) makeRequest(user string, userAgent string, service string
 		body, _ := io.ReadAll(response.Body)
 
 		if srv.debugEnabled {
-			fmt.Printf("%s %s: %s status %d\n", time.Now().Format(time.RFC3339), srv.Name, url, rcode)
+			fmt.Printf("%s %s: HTTP %s status %d\n", time.Now().Format(time.RFC3339), srv.Name, url, rcode)
 		}
 
 		if rcode != http.StatusOK {
@@ -171,7 +172,7 @@ func (srv *FaceServer) makeRequest(user string, userAgent string, service string
 	latency := end.Sub(start)
 
 	if srv.debugEnabled {
-		fmt.Printf("%s %s: %s done (%d, %dms -- %s)\n", time.Now().Format(time.RFC3339), srv.Name, url, rcode, latency.Milliseconds(), rtext)
+		fmt.Printf("%s %s: HTTP %s done (%d, %dms -- %s)\n", time.Now().Format(time.RFC3339), srv.Name, url, rcode, latency.Milliseconds(), rtext)
 	}
 
 	return &FaceResponse{
@@ -206,6 +207,7 @@ func (srv *FaceServer) faceGetHandler(r *http.Request, rstat *BaseRequestStatus)
 
 	if srv.debugEnabled {
 		fmt.Printf("%s %s: request path: %s, query string: %s\n", time.Now().Format(time.RFC3339), srv.Name, r.URL.Path, r.URL.RawQuery)
+		fmt.Printf("%s %s: request headers %#v\n", time.Now().Format(time.RFC3339), srv.Name, r.Header)
 	}
 
 	// Our request URL should start with /center/ or /edge/, and we want to
@@ -303,8 +305,8 @@ func (srv *FaceServer) faceGetHandler(r *http.Request, rstat *BaseRequestStatus)
 			var colorResp *ColorResponse
 
 			if srv.debugEnabled {
-				fmt.Printf("%s %s: starting gRPC to %s for %s (row %d col %d)\n",
-					time.Now().Format(time.RFC3339), srv.Name, srv.colorService, subrequest, colorReq.Row, colorReq.Column)
+				fmt.Printf("%s %s: gRPC starting (%s, r%d c%d, %s) %s\n",
+					time.Now().Format(time.RFC3339), srv.Name, subrequest, colorReq.Row, colorReq.Column, user, srv.colorService)
 			}
 
 			if subrequest == "center" {

pkg/faces/guiserver.go

@@ -144,44 +144,59 @@ func (srv *GUIServer) guiGetHandler(w http.ResponseWriter, r *http.Request) {
 		if user == "" {
 			user = "unknown"
 		}
+
 		userAgent := r.Header.Get("User-Agent")
 		if userAgent == "" {
 			userAgent = "unknown"
 		}
 
-		if srv.debugEnabled {
-			fmt.Printf("...%s: starting\n", url)
-		}
-
-		response, err := http.Get(url)
+		req, err := http.NewRequest("GET", url, nil)
 		if err != nil {
 			rcode = http.StatusInternalServerError
-			rtext = err.Error()
+			rtext = fmt.Sprintf("could not create new Request? %s", err.Error())
 			rtype = "text/plain"
 		} else {
-			rcode = response.StatusCode
-			rtextBytes, err := io.ReadAll(response.Body)
+			for key, values := range r.Header {
+				for _, value := range values {
+					req.Header.Add(key, value)
+				}
+			}
+
+			if srv.debugEnabled {
+				fmt.Printf("...%s: starting\n", url)
+			}
+
+			response, err := http.DefaultClient.Do(req)
+
 			if err != nil {
 				rcode = http.StatusInternalServerError
 				rtext = err.Error()
 				rtype = "text/plain"
 			} else {
-				rtext = string(rtextBytes)
-				rtype = response.Header.Get("Content-Type")
-
-				podID = response.Header.Get("X-Faces-Pod")
-				if podID == "" {
-					podID = srv.hostIP
+				rcode = response.StatusCode
+				rtextBytes, err := io.ReadAll(response.Body)
+				if err != nil {
+					rcode = http.StatusInternalServerError
+					rtext = err.Error()
+					rtype = "text/plain"
+				} else {
+					rtext = string(rtextBytes)
+					rtype = response.Header.Get("Content-Type")
+
+					podID = response.Header.Get("X-Faces-Pod")
+					if podID == "" {
+						podID = srv.hostIP
+					}
 				}
+				response.Body.Close()
 			}
-			response.Body.Close()
-		}
 
-		reqEnd := time.Now()
-		reqLatencyMs := reqEnd.Sub(reqStart).Milliseconds()
+			reqEnd := time.Now()
+			reqLatencyMs := reqEnd.Sub(reqStart).Milliseconds()
 
-		if srv.debugEnabled {
-			fmt.Printf("...%s (%dms): %d\n", url, reqLatencyMs, rcode)
+			if srv.debugEnabled {
+				fmt.Printf("...%s (%dms): %d\n", url, reqLatencyMs, rcode)
+			}
 		}
 	} else if strings.HasSuffix(r.URL.Path, ".svg") {
 		// We'll serve SVG files from the dataPath, though really we don't