From 6a13bc9ca54f06e13e33f4bcd3b01d5382e5c5de Mon Sep 17 00:00:00 2001 From: Flynn Date: Wed, 11 Dec 2024 21:09:22 -0500 Subject: [PATCH 1/5] logs: Clean up logging for the Color workload Signed-off-by: Flynn --- cmd/generic/color/color.go | 9 ++++++--- pkg/faces/color_provider.go | 4 ++-- 2 files changed, 8 insertions(+), 5 deletions(-) diff --git a/cmd/generic/color/color.go b/cmd/generic/color/color.go index d90acad..fefd1fa 100644 --- a/cmd/generic/color/color.go +++ b/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" @@ -56,7 +57,7 @@ func (srv *colorServer) Center(ctx context.Context, req *faces.ColorRequest) (*f 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: @@ -90,7 +91,7 @@ func (srv *colorServer) Edge(ctx context.Context, req *faces.ColorRequest) (*fac 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 +119,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") diff --git a/pkg/faces/color_provider.go b/pkg/faces/color_provider.go index 2b34f18..5d456bf 100644 --- a/pkg/faces/color_provider.go +++ b/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 From fcee744fc20e62f564c556c23a11e4cf6b6ad2b4 Mon Sep 17 00:00:00 2001 From: Flynn Date: Wed, 11 Dec 2024 21:10:50 -0500 Subject: [PATCH 2/5] logs: Clean up logging for the face workload Signed-off-by: Flynn --- pkg/faces/faceserver.go | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/pkg/faces/faceserver.go b/pkg/faces/faceserver.go index 9de1c87..1502eee 100644 --- a/pkg/faces/faceserver.go +++ b/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" { From 086414b46a6598ac47c6885116a95b4c90629baa Mon Sep 17 00:00:00 2001 From: Flynn Date: Wed, 11 Dec 2024 21:18:51 -0500 Subject: [PATCH 3/5] fix(user): honor USER_HEADER_NAME and correctly fetch username in the color workload Signed-off-by: Flynn --- cmd/generic/color/color.go | 34 +++++++++++++++++++++------------- pkg/faces/base_provider.go | 4 ++++ 2 files changed, 25 insertions(+), 13 deletions(-) diff --git a/cmd/generic/color/color.go b/cmd/generic/color/color.go index fefd1fa..0b86e86 100644 --- a/cmd/generic/color/color.go +++ b/cmd/generic/color/color.go @@ -46,14 +46,29 @@ 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 := md.Get("user") + user := "" + users := md.Get(srv.provider.BaseProvider.GetUserHeaderName()) + + if len(users) > 0 { + user = users[0] + } + + 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)) @@ -76,17 +91,10 @@ 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)) diff --git a/pkg/faces/base_provider.go b/pkg/faces/base_provider.go index 29e7735..55e97ae 100644 --- a/pkg/faces/base_provider.go +++ b/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() From 5a0558544b4ffee0791083e45af43c676e0f327e Mon Sep 17 00:00:00 2001 From: Flynn Date: Wed, 11 Dec 2024 21:19:31 -0500 Subject: [PATCH 4/5] fix(user): pass headers through when the GUI is pretending to be an ingress controller Signed-off-by: Flynn --- pkg/faces/guiserver.go | 55 +++++++++++++++++++++++++++--------------- 1 file changed, 35 insertions(+), 20 deletions(-) diff --git a/pkg/faces/guiserver.go b/pkg/faces/guiserver.go index b0f7092..eeac56b 100644 --- a/pkg/faces/guiserver.go +++ b/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 From 78b1894e0a468ee6e8a3efe7503f97ff46025f60 Mon Sep 17 00:00:00 2001 From: Flynn Date: Wed, 11 Dec 2024 21:20:06 -0500 Subject: [PATCH 5/5] chore: go mod tidy Signed-off-by: Flynn --- go.mod | 3 ++- go.sum | 8 ++++---- 2 files changed, 6 insertions(+), 5 deletions(-) diff --git a/go.mod b/go.mod index f68ea80..c09b6b4 100644 --- a/go.mod +++ b/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 ) diff --git a/go.sum b/go.sum index fa78ed7..b90f9b4 100644 --- a/go.sum +++ b/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=