Missing user in logs bug

CHANGELOG.md

@@ -72,6 +72,7 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/en/1.0.0/).
 - [#7182](https://github.com/apache/trafficcontrol/pull/7182) *Traffic Control Cache Config (t3c)* Sort peers used in strategy.yaml to prevent false positive for reload.
 - [#7204](https://github.com/apache/trafficcontrol/pull/7204) *Traffic Control Cache Config (t3c)* strategies.yaml hash_key only for consistent_hash
 - [#7277](https://github.com/apache/trafficcontrol/pull/7277) *Traffic Control Cache Config (t3c)* remapdotconfig: remove skip check at mids for nocache/live
+- [#7282](https://github.com/apache/trafficcontrol/pull/7282) *Traffic Ops* Fixed issue with user getting correctly logged when using an access or bearer token authentication.
 
 ## [7.0.0] - 2022-07-19
 ### Added

lib/go-rfc/http.go

@@ -43,6 +43,7 @@ const (
 	Age                = "Age"                 // RFC7234§5.1
 	Location           = "Location"            // RFC7231§7.1.2
 	Authorization      = "Authorization"       // RFC7235§4.2
+	Cookie             = "Cookie"              // RFC7873
 )
 
 // These are (some) valid values for content encoding and MIME types, for

traffic_ops/traffic_ops_golang/routing/middleware/wrappers.go

@@ -39,6 +39,8 @@ import (
 	"github.com/apache/trafficcontrol/traffic_ops/traffic_ops_golang/api"
 	"github.com/apache/trafficcontrol/traffic_ops/traffic_ops_golang/auth"
 	"github.com/apache/trafficcontrol/traffic_ops/traffic_ops_golang/tocookie"
+
+	"github.com/lestrrat-go/jwx/jwt"
 )
 
 // DefaultRequestTimeout is the default request timeout, if no timeout is configured.
@@ -188,19 +190,45 @@ func GetWrapAccessLog(secret string) Middleware {
 	}
 }
 
+func getCookieToken(r *http.Request) string {
+	cookie, err := r.Cookie(tocookie.Name)
+	if err == nil && cookie != nil {
+		return cookie.Value
+	} else if r.Header.Get(rfc.Cookie) != "" && strings.Contains(r.Header.Get(rfc.Cookie), tocookie.AccessToken) {
+		cookie, err := r.Cookie(tocookie.AccessToken)
+		if err == nil && cookie != nil {
+			decodedToken, err := jwt.Parse([]byte(cookie.Value))
+			if err == nil && cookie != nil {
+				return fmt.Sprintf("%s", decodedToken.PrivateClaims()[tocookie.MojoCookie])
+			}
+		}
+	} else if r.Header.Get(rfc.Authorization) != "" && strings.Contains(r.Header.Get(rfc.Authorization), tocookie.BearerToken) {
+		givenTokenSplit := strings.Split(r.Header.Get(rfc.Authorization), " ")
+		if len(givenTokenSplit) < 2 {
+			return ""
+		}
+		decodedToken, err := jwt.Parse([]byte(givenTokenSplit[1]))
+		if err == nil && decodedToken != nil {
+			return fmt.Sprintf("%s", decodedToken.PrivateClaims()[tocookie.MojoCookie])
+		}
+		return givenTokenSplit[1]
+	}
+	return ""
+}
+
 // WrapAccessLog takes the cookie secret and a http.Handler, and returns a HandlerFunc which writes to the Access Log (which is the lib/go-log EventLog) after the HandlerFunc finishes.
 // This is not a Middleware, because it needs the secret as a parameter. For a Middleware, see GetWrapAccessLog.
 func WrapAccessLog(secret string, h http.Handler) http.HandlerFunc {
 	return func(w http.ResponseWriter, r *http.Request) {
 		var imsType = NONIMS
 		iw := &util.Interceptor{W: w}
 		user := "-"
-		cookie, err := r.Cookie(tocookie.Name)
-		if err == nil && cookie != nil {
-			cookie, userErr, sysErr := tocookie.Parse(secret, cookie.Value)
-			if userErr == nil && sysErr == nil {
-				user = cookie.AuthData
-			}
+		cookieToken := getCookieToken(r)
+		cookie, userErr, sysErr := tocookie.Parse(secret, cookieToken)
+		if userErr == nil && sysErr == nil {
+			user = cookie.AuthData
+		} else {
+			log.Errorf("Error retrieving user from cookie: User Error: %v System Error: %v", userErr, sysErr)
 		}
 		start := time.Now()
 		defer func() {

traffic_ops/traffic_ops_golang/routing/middleware/wrappers_test.go

@@ -42,6 +42,8 @@ import (
 	"github.com/apache/trafficcontrol/traffic_ops/traffic_ops_golang/tocookie"
 
 	"github.com/jmoiron/sqlx"
+	"github.com/lestrrat-go/jwx/jwa"
+	"github.com/lestrrat-go/jwx/jwt"
 	sqlmock "gopkg.in/DATA-DOG/go-sqlmock.v1"
 )
 
@@ -440,4 +442,46 @@ func TestNoOpWhenNoPermissionsRequired(t *testing.T) {
 	}
 }
 
-// TODO: TestWrapAccessLog, et. al
+func TestGetCookieToken(t *testing.T) {
+	var cookies []http.Cookie
+	var jwtToken jwt.Token
+	var jwtSigned []byte
+
+	authUser := "foobar"
+	httpCookie := tocookie.GetCookie(authUser, 0, "fOObAR.")
+
+	jwtToken, _ = jwt.NewBuilder().Claim(api.MojoCookie, httpCookie.Value).Build()
+	jwtSigned, _ = jwt.Sign(jwtToken, jwa.HS256, []byte("fOObAR."))
+
+	mojoCookie := http.Cookie{Name: httpCookie.Name, Value: httpCookie.Value}
+	accessToken := http.Cookie{Name: "access_token", Value: string(jwtSigned)}
+	bearerToken := "Bearer " + string(jwtSigned)
+	cookies = append(cookies, mojoCookie, accessToken, http.Cookie{})
+
+	getUserFromCookie := func(cookieToken string) {
+		secret := "fOObAR."
+		user := ""
+		cookie, userErr, sysErr := tocookie.Parse(secret, cookieToken)
+		if userErr == nil && sysErr == nil {
+			user = cookie.AuthData
+		}
+		if user != "foobar" {
+			t.Errorf("Error: Unable to user from cookie. Expected: %v Got: %v", authUser, user)
+		}
+	}
+
+	r, err := http.NewRequest("GET", "https://localhost:8888", nil)
+	if err == nil && r != nil {
+		for i := range cookies {
+			if cookies[i].Name != "" {
+				r.AddCookie(&cookies[i])
+				cookieToken := getCookieToken(r)
+				getUserFromCookie(cookieToken)
+			} else {
+				r.Header.Add("Authorization", bearerToken)
+				cookieToken := getCookieToken(r)
+				getUserFromCookie(cookieToken)
+			}
+		}
+	}
+}

traffic_ops/traffic_ops_golang/tocookie/cookie.go

@@ -26,6 +26,9 @@ import (
 
 const GeneratedByStr = "trafficcontrol-go-tocookie"
 const Name = "mojolicious"
+const MojoCookie = "mojoCookie"
+const AccessToken = "access_token"
+const BearerToken = "Bearer"
 const DefaultDuration = time.Hour
 
 type Cookie struct {