v1.2.0 refactor logging, update dependencies

README.md

@@ -35,6 +35,7 @@ import (
    "fmt"
    "log"
    "net/http"
+   "time"
 
    "github.com/gin-contrib/sessions"
    "github.com/gin-contrib/sessions/cookie"
@@ -50,52 +51,46 @@ func main() {
       Debug: gin.IsDebugging(),
 
       ConnectionString: "ldap://127.0.0.1:389",
-      ReadonlyDN:       "cn=readonly,dc=vodolaz095,dc=life", // only required, if we enable ExtractGroups:true
-      ReadonlyPasswd:   "readonly",  // only required, if we enable ExtractGroups:true
+      ReadonlyDN:       "cn=readonly,dc=vodolaz095,dc=life",
+      ReadonlyPasswd:   "readonly",
       TLS:              &tls.Config{}, // nearly sane default values
       StartTLS:         false,
 
       UserBaseTpl: "uid=%s,ou=people,dc=vodolaz095,dc=life",
       ExtraFields: []string{"l"}, // get location too
 
-      ExtractGroups: true, 
-      GroupsOU:      "ou=groups,dc=vodolaz095,dc=life",  // only required, if we enable ExtractGroups:true
+      ExtractGroups: true,
+      GroupsOU:      "ou=groups,dc=vodolaz095,dc=life",
 
-      // how long to store user's profile in session, 
-      // if profile is expired, it is reloaded from ldap database
-	  // if we set TTL to 0, profile will never expire
-      TTL: 10 * time.Second, 
+      TTL: 10 * time.Second,
    })
    if err != nil {
       log.Fatalf("%s : while initializing ldap4gin authenticator", err)
    }
    log.Println("LDAP server dialed!")
    defer authenticator.Close()
-
    // Application should use any of compatible sessions offered by
    // https://github.com/gin-contrib/sessions module
-   // CAUTION:  secure cookie session storage has limits on user profile size!!!
+   // CAUTION: secure cookie session storage has limits on user profile size!!!
    store := cookie.NewStore([]byte("secret"))
    r.Use(sessions.Sessions("mysession", store))
 
    // dashboard
    r.GET("/", func(c *gin.Context) {
       session := sessions.Default(c)
       flashes := session.Flashes()
+      defer session.Save()
       //  extracting user's profile from context
       user, err := authenticator.Extract(c)
       if err != nil {
          if err.Error() == "unauthorized" { // render login page
-            session.AddFlash("Authorization failed")
-            session.Save()
             c.HTML(http.StatusUnauthorized, "unauthorized.html", gin.H{
                "flashes": flashes,
             })
             return
          }
          if err.Error() == "malformed username" {
             session.AddFlash("Malformed username")
-            session.Save()
             c.HTML(http.StatusUnauthorized, "unauthorized.html", gin.H{
                "flashes": flashes,
             })
@@ -109,7 +104,6 @@ func main() {
       for _, attr := range user.Entry.Attributes {
          fmt.Fprintf(buff, "%s: %s\n", attr.Name, attr.Values)
       }
-      session.Save()
       c.HTML(http.StatusOK, "profile.html", gin.H{
          "user":    user,
          "flashes": flashes,
@@ -120,18 +114,25 @@ func main() {
    // route to authorize user by username and password
    r.POST("/login", func(c *gin.Context) {
       session := sessions.Default(c)
+      defer session.Save()
       username := c.PostForm("username")
       password := c.PostForm("password")
       log.Printf("User %s tries to authorize from %s...", username, c.ClientIP())
       err := authenticator.Authorize(c, username, password)
       if err != nil {
          log.Printf("User %s failed to authorize from %s because of %s", username, c.ClientIP(), err.Error())
          session.AddFlash(fmt.Sprintf("Authorization error  %s", err))
+         c.Redirect(http.StatusFound, "/")
       } else {
          log.Printf("User %s authorized from %s!", username, c.ClientIP())
          session.AddFlash(fmt.Sprintf("Welcome, %s!", username))
       }
-      session.Save()
+      user, err := authenticator.Extract(c)
+      if err != nil {
+         log.Printf("%s : while extracting user", err)
+      } else {
+         log.Printf("user %s is extracted", user.DN)
+      }
       c.Redirect(http.StatusFound, "/")
    })
 

authenticator.go

@@ -26,8 +26,10 @@ func timeOut(ctx context.Context) (timeout int) {
 	return
 }
 
+// LogDebugFunc used to define requirements for logging function
 type LogDebugFunc func(ctx context.Context, format string, a ...any)
 
+// DefaultLogDebugFunc is used for logging by default
 var DefaultLogDebugFunc = func(ctx context.Context, format string, a ...any) {
 	log.Default().Printf("ldap4gin: "+format+"\n", a...)
 }
@@ -146,19 +148,14 @@ func (a *Authenticator) attachGroups(ctx context.Context, user *User) (err error
 			Name:        res.Entries[i].GetAttributeValue("cn"),
 			Description: res.Entries[i].GetAttributeValue("description"),
 		}
+		a.debug(ctx, "user %s is member of %s %s %s",
+			groups[i].GID, groups[i].Name, groups[i].Description, user.UID, len(res.Entries))
 	}
 	user.Groups = groups
 	return
 }
 
 func (a *Authenticator) reload(ctx context.Context, user *User) (err error) {
-	if !user.Expired() {
-		a.debug(ctx, "user's profile %s not expired", user.UID)
-		return nil
-	}
-	a.debug(ctx, "user's profile %s expired on %s",
-		user.UID, user.ExpiresAt.Format(time.Stamp),
-	)
 	if a.Options.ReadonlyDN == "" {
 		err = fmt.Errorf("readonly distinguished name is not configured")
 		return
@@ -186,8 +183,6 @@ func (a *Authenticator) reload(ctx context.Context, user *User) (err error) {
 	if err != nil {
 		return
 	}
-	a.debug(ctx, "user %s profile is loaded from ldap", user.UID)
-
 	if a.Options.Debug {
 		res.PrettyPrint(2)
 	}
@@ -205,14 +200,15 @@ func (a *Authenticator) reload(ctx context.Context, user *User) (err error) {
 	}
 	if a.Options.TTL > 0 {
 		user.ExpiresAt = time.Now().Add(a.Options.TTL)
-		a.debug(ctx, "user %s session will expire on %s",
+		a.debug(ctx, "set user %s to expire on %s",
 			user.UID,
 			user.ExpiresAt.Format("15:04:05"),
 		)
 	}
 	if a.Options.ExtractGroups {
 		err = a.attachGroups(ctx, user)
 	}
+	a.debug(ctx, "user %s profile is reloaded from ldap", user.UID)
 	return
 }
 
@@ -253,17 +249,29 @@ func (a *Authenticator) Extract(c *gin.Context) (user *User, err error) {
 			err = fmt.Errorf("unknown type")
 			return
 		}
-		a.debug(c.Request.Context(), "user %s is extracted from session of %v using %s",
+
+		a.debug(c.Request.Context(),
+			"user %s is extracted from session of %v using %s",
 			user.UID, c.ClientIP(), c.GetHeader("User-Agent"))
-		err = a.reload(c.Request.Context(), user)
-		if err != nil {
-			return
-		}
-		if user.ExpiresAt.IsZero() {
-			a.debug(c.Request.Context(), "user %s session will expire at %s",
+
+		if user.Expired() {
+			a.debug(c.Request.Context(), "user's profile %s expired on %s %s ago, refreshing...",
+				user.UID, user.ExpiresAt.Format(time.Stamp),
+				time.Now().Sub(user.ExpiresAt).String(),
+			)
+			err = a.reload(c.Request.Context(), user)
+			if err != nil {
+				return
+			}
+			user.ExpiresAt = time.Now().Add(a.Options.TTL)
+		} else {
+			a.debug(c.Request.Context(), "user's profile %s is valid until %s for %s",
 				user.UID, user.ExpiresAt.Format(time.Stamp),
+				user.ExpiresAt.Sub(time.Now()).String(),
 			)
 		}
+		session.Set(SessionKeyName, *user)
+		err = session.Save()
 	} else {
 		err = ErrUnauthorized
 	}

example/example.go

@@ -50,19 +50,18 @@ func main() {
 	r.GET("/", func(c *gin.Context) {
 		session := sessions.Default(c)
 		flashes := session.Flashes()
+		defer session.Save()
 		//  extracting user's profile from context
 		user, err := authenticator.Extract(c)
 		if err != nil {
 			if err.Error() == "unauthorized" { // render login page
-				session.Save()
 				c.HTML(http.StatusUnauthorized, "unauthorized.html", gin.H{
 					"flashes": flashes,
 				})
 				return
 			}
 			if err.Error() == "malformed username" {
 				session.AddFlash("Malformed username")
-				session.Save()
 				c.HTML(http.StatusUnauthorized, "unauthorized.html", gin.H{
 					"flashes": flashes,
 				})
@@ -76,7 +75,6 @@ func main() {
 		for _, attr := range user.Entry.Attributes {
 			fmt.Fprintf(buff, "%s: %s\n", attr.Name, attr.Values)
 		}
-		session.Save()
 		c.HTML(http.StatusOK, "profile.html", gin.H{
 			"user":    user,
 			"flashes": flashes,
@@ -87,6 +85,7 @@ func main() {
 	// route to authorize user by username and password
 	r.POST("/login", func(c *gin.Context) {
 		session := sessions.Default(c)
+		defer session.Save()
 		username := c.PostForm("username")
 		password := c.PostForm("password")
 		log.Printf("User %s tries to authorize from %s...", username, c.ClientIP())
@@ -111,14 +110,14 @@ func main() {
 	// page to list groups
 	r.GET("/groups", func(c *gin.Context) {
 		session := sessions.Default(c)
+		defer session.Save()
 		flashes := session.Flashes()
 		user, err := authenticator.Extract(c)
 		if err != nil {
 			session.AddFlash(fmt.Sprintf("Authorization error  %s", err))
 			c.Redirect(http.StatusFound, "/")
 			return
 		}
-		session.Save()
 		c.HTML(http.StatusOK, "groups.html", gin.H{
 			"user":    user,
 			"flashes": flashes,

go.mod

@@ -1,41 +1,45 @@
 module github.com/vodolaz095/ldap4gin
 
-go 1.18
+go 1.19
 
 require (
 	github.com/gin-contrib/sessions v0.0.5
-	github.com/gin-gonic/gin v1.8.1
+	github.com/gin-gonic/gin v1.9.0
 	github.com/go-ldap/ldap/v3 v3.4.4
-	github.com/stretchr/testify v1.8.0
+	github.com/stretchr/testify v1.8.2
 )
 
 exclude github.com/mattn/go-sqlite3 v2.0.3+incompatible
 
 require (
-	github.com/Azure/go-ntlmssp v0.0.0-20220621081337-cb9428e4ac1e // indirect
+	github.com/Azure/go-ntlmssp v0.0.0-20221128193559-754e69321358 // indirect
+	github.com/bytedance/sonic v1.8.8 // indirect
+	github.com/chenzhuoyu/base64x v0.0.0-20221115062448-fe3a3abad311 // indirect
 	github.com/davecgh/go-spew v1.1.1 // indirect
 	github.com/gin-contrib/sse v0.1.0 // indirect
 	github.com/go-asn1-ber/asn1-ber v1.5.4 // indirect
-	github.com/go-playground/locales v0.14.0 // indirect
-	github.com/go-playground/universal-translator v0.18.0 // indirect
-	github.com/go-playground/validator/v10 v10.11.1 // indirect
-	github.com/goccy/go-json v0.9.11 // indirect
+	github.com/go-playground/locales v0.14.1 // indirect
+	github.com/go-playground/universal-translator v0.18.1 // indirect
+	github.com/go-playground/validator/v10 v10.13.0 // indirect
+	github.com/goccy/go-json v0.10.2 // indirect
 	github.com/gorilla/context v1.1.1 // indirect
 	github.com/gorilla/securecookie v1.1.1 // indirect
 	github.com/gorilla/sessions v1.2.1 // indirect
 	github.com/json-iterator/go v1.1.12 // indirect
-	github.com/leodido/go-urn v1.2.1 // indirect
-	github.com/mattn/go-isatty v0.0.16 // indirect
+	github.com/klauspost/cpuid/v2 v2.2.4 // indirect
+	github.com/leodido/go-urn v1.2.4 // indirect
+	github.com/mattn/go-isatty v0.0.18 // indirect
 	github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect
 	github.com/modern-go/reflect2 v1.0.2 // indirect
-	github.com/pelletier/go-toml/v2 v2.0.5 // indirect
+	github.com/pelletier/go-toml/v2 v2.0.7 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect
-	github.com/ugorji/go/codec v1.2.7 // indirect
-	golang.org/x/crypto v0.0.0-20220924013350-4ba4fb4dd9e7 // indirect
-	golang.org/x/net v0.0.0-20220923203811-8be639271d50 // indirect
-	golang.org/x/sys v0.0.0-20220919091848-fb04ddd9f9c8 // indirect
-	golang.org/x/text v0.3.7 // indirect
-	google.golang.org/protobuf v1.28.1 // indirect
-	gopkg.in/yaml.v2 v2.4.0 // indirect
+	github.com/twitchyliquid64/golang-asm v0.15.1 // indirect
+	github.com/ugorji/go/codec v1.2.11 // indirect
+	golang.org/x/arch v0.3.0 // indirect
+	golang.org/x/crypto v0.9.0 // indirect
+	golang.org/x/net v0.10.0 // indirect
+	golang.org/x/sys v0.8.0 // indirect
+	golang.org/x/text v0.9.0 // indirect
+	google.golang.org/protobuf v1.30.0 // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect
 )