move debug logging to sample handler

README.md

@@ -1,7 +1,7 @@
 # ldapserver
 
-A LDAPv3 server framework for custom integrations or full-blown LDAP servers.
-Zero external dependencies.
+A LDAPv3 server framework for custom integrations or full-blown LDAP servers, with no external dependencies.
+Focus on the logic of your integration and forget the low-level details.
 
 ```
 go get github.com/merlinz01/ldapserver

ber_test.go

@@ -1,3 +1,4 @@
+// These tests are based on the examples in the reference guide on ldap.com.
 package ldapserver_test
 
 import (

handler.go

@@ -73,7 +73,6 @@ func (*BaseHandler) Search(conn *Conn, msg *Message, req *SearchRequest) {
 func (h *BaseHandler) Extended(conn *Conn, msg *Message, req *ExtendedRequest) {
 	switch req.Name {
 	case OIDStartTLS:
-		log.Println("Start TLS request")
 		h.StartTLS(conn, msg)
 	default:
 		log.Println("Unknown extended request:", req.Name)
@@ -96,7 +95,7 @@ func (*BaseHandler) StartTLS(conn *Conn, msg *Message) {
 	err := conn.StartTLS()
 	switch {
 	case err == nil:
-		log.Println("StartTLS succeeded")
+		// pass
 	case errors.Is(err, ErrTLSNotAvailable):
 		log.Println("TLS not available for StartTLS")
 		res.ResultCode = LDAPResultUnwillingToPerform

server.go

@@ -119,7 +119,7 @@ func (s *LDAPServer) handleConnection(c net.Conn) {
 	}
 	for {
 		if ldapConn.closed {
-			log.Println("LDAP connection closed, discarding")
+			// Close() called
 			return
 		}
 		msg, err := ldapConn.ReadMessage()
@@ -146,16 +146,13 @@ func (s *LDAPServer) handleMessage(conn *Conn, msg *Message) {
 	}
 	switch msg.ProtocolOp.Type {
 	case TypeAbandonRequestOp:
-		log.Println("Abandon request")
 		messageID, err := BerGetInteger(msg.ProtocolOp.Data)
 		if err != nil || messageID < 0 || messageID > 2147483647 {
 			log.Println("Invalid Abandon request:", err, messageID)
 			return
 		}
 		s.Handler.Abandon(conn, msg, MessageID(messageID))
-		return
 	case TypeAddRequestOp:
-		log.Println("Add request")
 		req, err := GetAddRequest(msg.ProtocolOp.Data)
 		if err != nil {
 			log.Println("Error parsing Add request:", err)
@@ -168,7 +165,6 @@ func (s *LDAPServer) handleMessage(conn *Conn, msg *Message) {
 			s.Handler.Add(conn, msg, req)
 		}()
 	case TypeBindRequestOp:
-		log.Println("Bind request")
 		req, err := GetBindRequest(msg.ProtocolOp.Data)
 		if err != nil {
 			log.Println("Error parsing Bind request:", err)
@@ -178,7 +174,6 @@ func (s *LDAPServer) handleMessage(conn *Conn, msg *Message) {
 		conn.asyncOperations.Wait()
 		s.Handler.Bind(conn, msg, req)
 	case TypeCompareRequestOp:
-		log.Println("Compare request")
 		req, err := GetCompareRequest(msg.ProtocolOp.Data)
 		if err != nil {
 			log.Println("Error parsing Compare request:", err)
@@ -191,24 +186,22 @@ func (s *LDAPServer) handleMessage(conn *Conn, msg *Message) {
 			s.Handler.Compare(conn, msg, req)
 		}()
 	case TypeDeleteRequestOp:
-		log.Println("Delete request")
 		dn := BerGetOctetString(msg.ProtocolOp.Data)
 		conn.asyncOperations.Add(1)
 		go func() {
 			defer conn.asyncOperations.Done()
 			s.Handler.Delete(conn, msg, dn)
 		}()
 	case TypeExtendedRequestOp:
-		log.Println("Extended request")
 		req, err := GetExtendedRequest(msg.ProtocolOp.Data)
 		if err != nil {
 			log.Println("Error parsing Extended request:", err)
 			conn.SendResult(msg.MessageID, nil, TypeExtendedResponseOp, &ExtendedResult{Result: *ProtocolError})
 			return
 		}
+		// This is not concurrent in case it is a StartTLS request
 		s.Handler.Extended(conn, msg, req)
 	case TypeModifyRequestOp:
-		log.Println("Modify request")
 		req, err := GetModifyRequest(msg.ProtocolOp.Data)
 		if err != nil {
 			log.Println("Error parsing Modify request:", err)
@@ -221,7 +214,6 @@ func (s *LDAPServer) handleMessage(conn *Conn, msg *Message) {
 			s.Handler.Modify(conn, msg, req)
 		}()
 	case TypeModifyDNRequestOp:
-		log.Println("ModifyDN request")
 		req, err := GetModifyDNRequest(msg.ProtocolOp.Data)
 		if err != nil {
 			log.Println("Error parsing ModifyDN request:", err)
@@ -234,7 +226,6 @@ func (s *LDAPServer) handleMessage(conn *Conn, msg *Message) {
 			s.Handler.ModifyDN(conn, msg, req)
 		}()
 	case TypeSearchRequestOp:
-		log.Println("Search request")
 		req, err := GetSearchRequest(msg.ProtocolOp.Data)
 		if err != nil {
 			log.Println("Error parsing Search request:", err)
@@ -247,10 +238,11 @@ func (s *LDAPServer) handleMessage(conn *Conn, msg *Message) {
 			s.Handler.Search(conn, msg, req)
 		}()
 	case TypeUnbindRequestOp:
-		log.Println("Unbind request")
+		// Unbind has no result
+		// Simply close the connection
 		conn.Close()
 	default:
-		log.Println("Unknown operation type:", msg.ProtocolOp.Type)
+		// Let the handler deal with it if it knows how
 		s.Handler.Other(conn, msg)
 	}
 }

test/main.go

@@ -36,10 +36,12 @@ func getAuth(conn *ldapserver.Conn) string {
 			auth = authstr
 		}
 	}
+	log.Println("Authentication:", auth)
 	return auth
 }
 
 func (t *TestHandler) Abandon(conn *ldapserver.Conn, msg *ldapserver.Message, messageID ldapserver.MessageID) {
+	log.Println("Abandon request")
 	t.abandonmentLock.Lock()
 	if _, exists := t.abandonment[messageID]; exists {
 		t.abandonment[messageID] = true
@@ -48,6 +50,7 @@ func (t *TestHandler) Abandon(conn *ldapserver.Conn, msg *ldapserver.Message, me
 }
 
 func (t *TestHandler) Add(conn *ldapserver.Conn, msg *ldapserver.Message, req *ldapserver.AddRequest) {
+	log.Println("Add request")
 	auth := getAuth(conn)
 	if auth != "uid=authorizeduser,ou=users,dc=example,dc=com" {
 		log.Println("Not an authorized connection!", auth)
@@ -66,6 +69,7 @@ func (t *TestHandler) Add(conn *ldapserver.Conn, msg *ldapserver.Message, req *l
 }
 
 func (t *TestHandler) Bind(conn *ldapserver.Conn, msg *ldapserver.Message, req *ldapserver.BindRequest) {
+	log.Println("Bind request")
 	res := &ldapserver.BindResponse{}
 	if req.Version != 3 {
 		res.ResultCode = ldapserver.LDAPResultProtocolError
@@ -105,6 +109,7 @@ func (t *TestHandler) Bind(conn *ldapserver.Conn, msg *ldapserver.Message, req *
 }
 
 func (t *TestHandler) Compare(conn *ldapserver.Conn, msg *ldapserver.Message, req *ldapserver.CompareRequest) {
+	log.Println("Compare request")
 	// Allow cancellation
 	t.abandonment[msg.MessageID] = false
 	defer func() {
@@ -134,6 +139,7 @@ func (t *TestHandler) Compare(conn *ldapserver.Conn, msg *ldapserver.Message, re
 }
 
 func (t *TestHandler) Delete(conn *ldapserver.Conn, msg *ldapserver.Message, dn string) {
+	log.Println("Delete request")
 	auth := getAuth(conn)
 	if auth != "uid=authorizeduser,ou=users,dc=example,dc=com" {
 		log.Println("Not an authorized connection!", auth)
@@ -148,6 +154,7 @@ func (t *TestHandler) Delete(conn *ldapserver.Conn, msg *ldapserver.Message, dn
 }
 
 func (t *TestHandler) Modify(conn *ldapserver.Conn, msg *ldapserver.Message, req *ldapserver.ModifyRequest) {
+	log.Println("Modify request")
 	auth := getAuth(conn)
 	if auth != "uid=authorizeduser,ou=users,dc=example,dc=com" {
 		log.Println("Not an authorized connection!", auth)
@@ -167,23 +174,25 @@ func (t *TestHandler) Modify(conn *ldapserver.Conn, msg *ldapserver.Message, req
 }
 
 func (t *TestHandler) ModifyDN(conn *ldapserver.Conn, msg *ldapserver.Message, req *ldapserver.ModifyDNRequest) {
+	log.Println("Modify DN request")
 	auth := getAuth(conn)
 	if auth != "uid=authorizeduser,ou=users,dc=example,dc=com" {
 		log.Println("Not an authorized connection!", auth)
 		conn.SendResult(msg.MessageID, nil, ldapserver.TypeModifyResponseOp, ldapserver.PermissionDenied)
 		return
 	}
-	log.Println("Modify DN:", req.Object)
-	log.Println("  New RDN:", req.NewRDN)
-	log.Println("  Delete old RDN:", req.DeleteOldRDN)
-	log.Println("  New superior:", req.NewSuperior)
+	log.Println("Old DN:", req.Object)
+	log.Println("New RDN:", req.NewRDN)
+	log.Println("Delete old RDN:", req.DeleteOldRDN)
+	log.Println("New superior:", req.NewSuperior)
 	res := &ldapserver.Result{
 		ResultCode: ldapserver.ResultSuccess,
 	}
 	conn.SendResult(msg.MessageID, nil, ldapserver.TypeModifyDNResponseOp, res)
 }
 
 func (t *TestHandler) Search(conn *ldapserver.Conn, msg *ldapserver.Message, req *ldapserver.SearchRequest) {
+	log.Println("Search request")
 	// Allow cancellation
 	t.abandonment[msg.MessageID] = false
 	defer func() {
@@ -237,11 +246,14 @@ func (t *TestHandler) Search(conn *ldapserver.Conn, msg *ldapserver.Message, req
 		// Pretend to take a while
 		time.Sleep(time.Second * 3)
 		entry := &ldapserver.SearchResultEntry{
-			ObjectName: req.BaseObject,
+			ObjectName: fmt.Sprintf("uid=jdoe%d,%s", i, req.BaseObject),
 			Attributes: []ldapserver.Attribute{
-				{Description: "givenname", Values: []string{fmt.Sprintf("John Doe %d", i)}},
+				{Description: "uid", Values: []string{fmt.Sprintf("jdoe%d", i)}},
+				{Description: "givenname", Values: []string{fmt.Sprintf("John %d", i)}},
+				{Description: "sn", Values: []string{"Doe"}},
 			},
 		}
+		log.Println("Sending entry", i)
 		conn.SendResult(msg.MessageID, nil, ldapserver.TypeSearchResultEntryOp, entry)
 	}
 
@@ -252,6 +264,7 @@ func (t *TestHandler) Search(conn *ldapserver.Conn, msg *ldapserver.Message, req
 }
 
 func (t *TestHandler) Extended(conn *ldapserver.Conn, msg *ldapserver.Message, req *ldapserver.ExtendedRequest) {
+	log.Println("Extended request with OID", req.Name)
 	switch req.Name {
 	case ldapserver.OIDPasswordModify:
 		log.Println("Password modify")
@@ -260,6 +273,7 @@ func (t *TestHandler) Extended(conn *ldapserver.Conn, msg *ldapserver.Message, r
 		res.ResultCode = ldapserver.ResultSuccess
 		conn.SendResult(msg.MessageID, nil, ldapserver.TypeExtendedResponseOp, res)
 	default:
+		log.Println("Passing request to base handler")
 		t.BaseHandler.Extended(conn, msg, req)
 	}
 }