Introduce debug levels, AD filter bug workaround, fix legacy homeattr not being lowercased

5 files changed, 99 insertions, 38 deletions

diff --git a/helper.c b/helper.c
index b125f42..fb0e4a9 100644
--- a/helper.c
+++ b/helper.c
@@ -11,6 +11,8 @@
 #include <fcntl.h>
 #include <stdarg.h>
 
+DebugLevel _debugLevel = DEBUG_WARNING;
+
 void bail(char *args, ...)
 {
 	printf("ERROR: ");
@@ -201,3 +203,13 @@ void helper_printfilter(struct Filter* f)
 	putchar('\n');
 }
 
+void plog(const DebugLevel debugLevel, char *args, ...)
+{
+	if (debugLevel < _debugLevel) return;
+	va_list argList;
+	va_start(argList, args);
+	vprintf(args, argList);
+	va_end(argList);
+	putchar('\n');
+	fflush(stdout);
+}
diff --git a/helper.h b/helper.h
index 838078f..17d407e 100644
--- a/helper.h
+++ b/helper.h
@@ -24,5 +24,17 @@ static inline int max(const int a, const int b)
 	return a > b ? a : b;
 }
 
+typedef enum {
+	DEBUG_FATAL = 0,
+	DEBUG_WARNING = 1,
+	DEBUG_INFO = 2,
+	DEBUG_VERBOSE = 3,
+	DEBUG_TRACE = 4,
+} DebugLevel;
+
+extern DebugLevel _debugLevel;
+
+void plog(const DebugLevel debugLevel, char *args, ...);
+
 #endif
 
diff --git a/ldadp.c b/ldadp.c
index 741df5d..923891a 100644
--- a/ldadp.c
+++ b/ldadp.c
@@ -11,6 +11,7 @@
 #include "ini.h"
 #include "helper.h"
 #include "openssl.h"
+#include "helper.h"
 #include <stdio.h>
 #include <socket.h>
 #include <io.h>
@@ -118,6 +119,8 @@ static int loadConfig_handler(void *stuff, const char *section, const char *key,
 			certFile = strdup(value);
 		} else if (strcmp(key, "privkey") == 0) {
 			keyFile = strdup(value);
+		} else if (strcmp(key, "debug") == 0) {
+			_debugLevel = atoi(value);
 		} else {
 			printf("Unknown local config option '%s'\n", key);
 		}
diff --git a/proxy.c b/proxy.c
index f3a5421..2f8d950 100644
--- a/proxy.c
+++ b/proxy.c
@@ -182,7 +182,7 @@ BOOL proxy_fromClient(epoll_client_t *client, const size_t maxLen)
 	size_t len;
 	const size_t res = scan_ldapmessage(client->readBuffer, client->readBuffer + maxLen, &messageId, &op, &len);
 	if (res == 0) return FALSE;
-	//printf("[C] scan_ldapmessage: Consumed %d, remaining length %d, id %lu, op %lu\n", (int)res, (int)len, messageId, op);
+	plog(DEBUG_TRACE, "[C] scan_ldapmessage: Consumed %d, remaining length %d, id %lu, op %lu", (int)res, (int)len, messageId, op);
 	// TODO: Caching
 	switch (op) {
 	case BindRequest:
@@ -206,7 +206,7 @@ void proxy_removeClient(epoll_client_t * const client)
 	int i, lastValid = -1;
 	for (i = 0; i < _pendingCount; ++i) {
 		if (_pendingRequest[i].client == client) {
-			printf("RemoveClient success %p\n", client);
+			plog(DEBUG_TRACE, "RemoveClient success %p", client);
 			_pendingRequest[i].client = NULL;
 		}
 		else if (_pendingRequest[i].client != NULL) lastValid = i;
@@ -249,7 +249,7 @@ BOOL proxy_fromServer(epoll_server_t *server, const size_t maxLen)
 	if (res == 0) {
 		return FALSE;
 	}
-	//printf("[AD] scan_ldapmessage: Consumed %d, remaining length %d, id %lu, op %lu\n", (int)res, (int)len, messageId, op);
+	plog(DEBUG_TRACE, "[Server] scan_ldapmessage: Consumed %d, remaining length %d, id %lu, op %lu", (int)res, (int)len, messageId, op);
 	switch (op) {
 	case BindResponse:
 		return proxy_serverBindResponse(server, messageId, res, maxLen);
@@ -261,7 +261,7 @@ BOOL proxy_fromServer(epoll_server_t *server, const size_t maxLen)
 		//scan_ldapstring(server->readBuffer + res,const char* max,struct string* s);
 		return TRUE;
 	}
-	printf("Unsupported op: %lu\n", op);
+	plog(DEBUG_WARNING, "[Server] Unsupported op in reply: %lu; dropping connection.", op);
 	return FALSE;
 }
 
@@ -419,6 +419,9 @@ static BOOL request_getGroupFilter(struct Filter *filter, struct string *wantedG
 	return retval;
 }
 
+/**
+ * Gets passed original filter from client.
+ */
 static void request_replaceFilter(server_t *server, struct Filter **filter)
 {
 	while (*filter != NULL) {
@@ -433,6 +436,17 @@ static void request_replaceFilter(server_t *server, struct Filter **filter)
 			}
 			break;
 		case PRESENT:
+			if (!server->plainLdap && iequals(&(*filter)->ava.desc, &s_uid)) {
+				// HACK HACK for some AD server versions. The following filter will act as if no filter
+				// was given at all, returning the entire AD catalogue, which is not what we want:
+				// &(&(!([objectsid == xx]),[objectsid \exist]),[samaccountname \exist],[objectclass == user],[samaccountname == yy])
+				// however, the following works fine:
+				// &(&(!([objectsid == xx]),[objectsid \exist]),[objectclass == user],[samaccountname == yy])
+				// so we get rid of that one exist/present operator
+				del = TRUE;
+				break;
+			}
+			// no break;
 		case SUBSTRING:
 			if (!request_replaceAttribute(server, &(*filter)->ava.desc, NULL, NULL)) {
 				del = TRUE;
@@ -464,7 +478,7 @@ static void request_replaceAdl(server_t *server, struct AttributeDescriptionList
 {
 	while (*adl != NULL) {
 		struct AttributeDescriptionList *next = NULL;
-		if (attr == NULL) { }
+		if (attr == NULL) request_replaceAttribute(server, &(*adl)->a, NULL, NULL);
 		else if (iequals(&(*adl)->a, &s_homedirectory)) {
 			attr->homeDirectory = TRUE;
 			if (server->plainLdap) {
@@ -502,7 +516,7 @@ static BOOL request_replaceAttribute(server_t *server, struct string *attribute,
 		*attribute = server->map.uid;
 		if (attr) attr->hasUser = TRUE;
 		// If uid is of format s[0-9]+, we assume that it's a numeric account name in AD, as a workaround
-		if (value == NULL) return FALSE;
+		if (value == NULL) return TRUE;
 		fixUnNumeric(value);
 		////// ###################
 	} else if (iequals(attribute, &s_homemount)) {
@@ -590,7 +604,7 @@ static void request_filterRequestedAttributes(struct AttributeDescriptionList **
 
 static void response_replacePal(server_t *server, struct PartialAttributeList **pal, attr_t *attr);
 static void response_replaceAdl(server_t *server, struct string *type, struct AttributeDescriptionList **adl, attr_t *attr);
-static void response_replaceAttribute(server_t *server, struct string * const attribute, struct string * const value);
+static void response_replaceAttribute(server_t *server, const struct string * const attribute, struct string * const value);
 static BOOL response_filterHomeDir(struct PartialAttributeList *pal);
 static BOOL response_filterLocalHomeDir(struct PartialAttributeList *pal);
 static struct PartialAttributeList* response_addPal(struct PartialAttributeList *pal, struct string *attribute, const char *format, ...);
@@ -688,13 +702,12 @@ static void response_replaceAdl(server_t *server, struct string *attribute, stru
 	}
 }
 
-static void response_replaceAttribute(server_t *server, struct string * const attribute, struct string * const value)
+static void response_replaceAttribute(server_t *server, const struct string * const attribute, struct string * const value)
 {
-	if (iequals(attribute, &server->map.uid)) {
-		*attribute = s_uid;
+	// Attributes already remapped here!
+	if (iequals(attribute, &s_uid)) {
 		if (value != NULL) fixNumeric(value);
-	} else if (iequals(attribute, &server->map.uidnumber)) {
-		*attribute = s_uidNumber;
+	} else if (iequals(attribute, &s_uidnumber)) {
 		if (!server->plainLdap) {
 			// If this is AD, this must have been objectSid before - convert SID to number
 			if (value == NULL) return;
@@ -722,6 +735,7 @@ static void response_replaceAttribute(server_t *server, struct string * const at
  */
 static BOOL response_filterHomeDir(struct PartialAttributeList *pal)
 {
+	helper_printpal(pal);
 	for (struct AttributeDescriptionList *adl = pal->values; adl != NULL; adl = pal->values /* sic */) {
 		if (adl->a.s != NULL) {
 			if (adl->a.l > 0 && adl->a.s[0] == '\\') {
@@ -788,26 +802,30 @@ static BOOL proxy_clientSearchRequest(epoll_client_t *client, const unsigned lon
 	}
 	server_t *server = server_getFromBase(&req.baseObject);
 	if (server == NULL) {
-		printf("[Client] Invalid search request: baseObj '%.*s' unknown (scope %d).\n", (int)req.baseObject.l, req.baseObject.s, (int)req.scope);
+		plog(DEBUG_WARNING, "[Client] Invalid search request: baseObj '%.*s' unknown (scope %d).", (int)req.baseObject.l, req.baseObject.s, (int)req.scope);
 		return FALSE;
 	}
-	//printf("scan_ldapsearchrequest: baseObj: %.*s, scope: %d, derefAliases: %d\n", (int)req.baseObject.l, req.baseObject.s, req.scope, req.derefAliases);
+	plog(DEBUG_TRACE, "scan_ldapsearchrequest: baseObj: %.*s, scope: %d, derefAliases: %d", (int)req.baseObject.l, req.baseObject.s, req.scope, req.derefAliases);
 	// Try to figure out if this is a lookup for a user/multiple users, or something else (eg. group)
 	if (!request_isUserFilter(req.filter)) {
 		// Handle locally
-		printf("[Client] Search request (handling local): ");
-		helper_printfilter(req.filter);
+		if (_debugLevel >= DEBUG_VERBOSE) {
+			printf("[Client] Search request (handling local): ");
+			helper_printfilter(req.filter);
+		}
 		const BOOL ret = proxy_localSearchRequest(client, messageId, &req);
 		free_ldapsearchrequest(&req);
 		return ret;
 	}
 	// Forward
-	printf("[Client] Search request (forwarding): ");
-	helper_printfilter(req.filter);
+	if (_debugLevel >= DEBUG_TRACE) {
+		printf("[Client] Search request (original): ");
+		helper_printfilter(req.filter);
+	}
 	if (req.sizeLimit == 0 || req.sizeLimit > 20) req.sizeLimit = 20; // TODO: Magic value
 	pending_t *pending = proxy_getFreePendingSlot(client);
 	if (pending == NULL) {
-		printf("No more slots for pending requests\n");
+		plog(DEBUG_WARNING, "Cannot handle incoming client request; too many pending requests on the wire.");
 		free_ldapsearchrequest(&req);
 		return FALSE;
 	}
@@ -827,6 +845,12 @@ static BOOL proxy_clientSearchRequest(epoll_client_t *client, const unsigned lon
 		memset(&pending->attr, -1, sizeof(pending->attr));
 	}
 	request_replaceFilter(server, &req.filter);
+	if (_debugLevel >= DEBUG_TRACE) {
+		printf("[Client] Search request (translated): ");
+		helper_printfilter(req.filter);
+		printf("Wanted attributes: ");
+		helper_printal(req.attributes);
+	}
 	pending->clientMessageId = messageId;
 	if (client->fixedServer == NULL) {
 		pending->serverMessageId = server_searchRequest(server, &req);
@@ -835,7 +859,7 @@ static BOOL proxy_clientSearchRequest(epoll_client_t *client, const unsigned lon
 	}
 	if (pending->serverMessageId == 0) {
 		// Failed to forward.. TODO: Fail client
-		printf("Failed to forward search request.\n");
+		plog(DEBUG_WARNING, "Failed to forward a search request to server.");
 		pending->client = NULL;
 	}
 	free_ldapsearchrequest(&req);
@@ -850,7 +874,7 @@ static BOOL proxy_serverSearchResult(epoll_server_t *server, const unsigned long
 	if (bodyBuffer == NULL) bodyBuffer = malloc(MAXMSGLEN);
 	pending_t *pending = proxy_getPendingFromServer(messageId);
 	if (pending == NULL) {
-		printf("[AD] Received message with unknown messageId %lu, ignoring\n", messageId);
+		plog(DEBUG_WARNING, "[Server] Received response with unknown messageId %lu, ignoring...", messageId);
 		return TRUE;
 	}
 	const char *body;
@@ -859,20 +883,28 @@ static BOOL proxy_serverSearchResult(epoll_server_t *server, const unsigned long
 		// Just forward with new header
 		bodyLen = maxLen - offset;
 		body = server->readBuffer + offset;
+		plog(DEBUG_TRACE, "[Server] SRDONE");
 	} else {
 		// Transform reply
 		struct SearchResultEntry sre;
 		const size_t res = scan_ldapsearchresultentry(server->readBuffer + offset, server->readBuffer + maxLen, &sre);
 		if (res == 0) return FALSE;
+		if (_debugLevel >= DEBUG_TRACE) {
+			printf("SearchResultEntry:\n");
+			helper_printpal(sre.attributes);
+		}
 		response_replacePal(server->serverData, &sre.attributes, &pending->attr);
+		if (_debugLevel >= DEBUG_TRACE) {
+			helper_printpal(sre.attributes);
+		}
 		bodyLen = fmt_ldapsearchresultentry(NULL, &sre);
 		if (bodyLen == 0) {
-			printf("Error formatting ldapsearchresultentry after transformation\n");
+			plog(DEBUG_WARNING, "Error formatting ldapsearchresultentry after transformation.");
 			free_ldapsearchresultentry(&sre);
 			return FALSE;
 		}
 		if (bodyLen > MAXMSGLEN) {
-			printf("ldapsearchresultentry too large after transformation\n");
+			plog(DEBUG_WARNING, "ldapsearchresultentry too large after transformation.");
 			free_ldapsearchresultentry(&sre);
 			return FALSE;
 		}
@@ -901,16 +933,16 @@ static BOOL proxy_clientBindRequest(epoll_client_t *client, const unsigned long
 	if (res == 0) return FALSE; // Parsing request failed
 	if (method != 0) {
 		// Other than simple bind - currently not supported
-		printf("[Client] Unsupported bind method: %lu\n", method);
+		plog(DEBUG_WARNING, "[Client] Unsupported bind method: %lu", method);
 		bodyLen = fmt_ldapbindresponse(bufoff, authMethodNotSupported, "", "SIMPLE only", "");
 	} else {
 		// Simple bind :-)
 		password.l = 0;
-		scan_ldapstring(client->readBuffer + offset + res, client->readBuffer + maxLen, &password);
-		//printf("scan_ldapbindrequest: Consumed %d, version %lu, method %lu, name '%.*s'\n", (int)(res + res2), version, method, (int)name.l, name.s);
+		const size_t res2 = scan_ldapstring(client->readBuffer + offset + res, client->readBuffer + maxLen, &password);
+		plog(DEBUG_TRACE, "[Client] scan_ldapbindrequest: Consumed %d, version %lu, method %lu, name '%.*s'", (int)(res + res2), version, method, (int)name.l, name.s);
 		if (name.l == 0 && password.l == 0) {
 			// Anonymous bind used for "normal" lookups
-			printf("[Client] Anonymous bind accepted\n");
+			plog(DEBUG_VERBOSE, "[Client] Anonymous bind accepted");
 			bodyLen = fmt_ldapbindresponse(bufoff, success, "", "main screen turn on", "");
 		} else {
 			BOOL incorrect = FALSE;
@@ -918,7 +950,7 @@ static BOOL proxy_clientBindRequest(epoll_client_t *client, const unsigned long
 			if (server == NULL || (incorrect = (strncmp(password.s, "\x08\x0a\x0d\x7fINCORRECT", 13) == 0)) || isInt(&name, 0)) {
 				// The INCORRECT part is some weird thing I saw pam_ldap do - probably to identify misconfigured
 				// LDAP servers/accounts that will accept any password - save the round trip to AD and deny
-				if (!incorrect) printf("[Client] Numeric account or invalid binddn for %.*s\n", (int)name.l, name.s);
+				if (!incorrect) plog(DEBUG_WARNING, "[Client] Numeric account or invalid binddn for %.*s", (int)name.l, name.s);
 				bodyLen = fmt_ldapbindresponse(bufoff, invalidCredentials, "", "invalid credentials", "");
 			} else {
 				// Seems to be an actual bind - forward to AD - TODO: SASL (DIGEST-MD5? Something?)
@@ -929,11 +961,11 @@ static BOOL proxy_clientBindRequest(epoll_client_t *client, const unsigned long
 				if (pending == NULL || smid == 0) {
 					// Busy
 					if (pending != NULL) pending->client = NULL;
-					printf("[Client] Too many pending requests, or cannot connect to AD for bind\n");
+					plog(DEBUG_WARNING, "[Client] Too many pending requests, or cannot connect to AD for bind.");
 					bodyLen = fmt_ldapbindresponse(bufoff, busy, "", "can't handle it", "");
 				} else {
 					// Request queued, client needs to wait
-					printf("[Client] Forwarding bind to AD for user %.*s\n", (int)name.l, name.s);
+					plog(DEBUG_INFO, "[Client] Forwarding bind to AD/LDAP for user %.*s (#%lu)", (int)name.l, name.s, smid);
 					pending->clientMessageId = messageId;
 					pending->serverMessageId = smid;
 					con->fixedClient = client;
@@ -955,12 +987,12 @@ static BOOL proxy_serverBindResponse(epoll_server_t *server, const unsigned long
 	struct string binddn, error, refer;
 	const size_t res = scan_ldapbindresponse(server->readBuffer + offset, server->readBuffer + maxLen, &result, &binddn, &error, &refer);
 	if (res == 0) return FALSE; // Parsing request failed
-	//printf("scan_ldapbindresponse: Consumed %d, result: %lu, binddn: %.*s, error: %.*s, referral: %.*s\n", (int)res, result, (int)binddn.l, binddn.s, (int)error.l, error.s, (int)refer.l, refer.s);
+	plog(DEBUG_TRACE, "[Server] scan_ldapbindresponse: Consumed %d, result: %lu, binddn: %.*s, error: %.*s, referral: %.*s", (int)res, result, (int)binddn.l, binddn.s, (int)error.l, error.s, (int)refer.l, refer.s);
 	server->bound = (result == success);
 	if (server->bound) {
-		printf("[AD] Accepted credentials (#%lu)\n", messageId);
+		plog(DEBUG_VERBOSE, "[Server] Accepted credentials (#%lu)", messageId);
 	} else {
-		printf("[AD] Wrong credentials (#%lu)\n", messageId);
+		plog(DEBUG_INFO, "[Server] Wrong credentials (#%lu)", messageId);
 	}
 	if (messageId <= 1) return TRUE;
 	// Was a forwarded auth
@@ -991,7 +1023,7 @@ static void prependPal(struct SearchResultEntry *dest, struct PartialAttributeLi
 
 static BOOL proxy_localFeatureReply(epoll_client_t *client, const unsigned long messageId)
 {
-	printf("[Proxy] Sending static feature request reply to client\n");
+	plog(DEBUG_VERBOSE, "[Proxy] Sending static feature request reply to client.");
 	struct SearchResultEntry sre;
 	struct PartialAttributeList vers;
 	struct AttributeDescriptionList versVal;
@@ -1031,7 +1063,7 @@ static BOOL proxy_localSearchRequest(epoll_client_t *client, const unsigned long
 		}
 		if (number == 1001 || name.l != 0) {
 			// At least one of them was set
-			printf("[Proxy] Sending static group membership to client\n");
+			plog(DEBUG_VERBOSE, "[Proxy] Sending static group membership to client.");
 			struct SearchResultEntry sre;
 			struct PartialAttributeList gidNumber, cn, objectClass;
 			struct AttributeDescriptionList gidNumberVal, cnVal, objectClassVal;
@@ -1048,7 +1080,7 @@ static BOOL proxy_localSearchRequest(epoll_client_t *client, const unsigned long
 			fmt_ldapsearchresultentry(buffer + headerLen, &sre);
 			client_send(client, buffer, headerLen + bodyLen, TRUE);
 		} else {
-			printf("[Proxy] Sending empty posixGroup search result to client.\n");
+			plog(DEBUG_VERBOSE, "[Proxy] Sending empty posixGroup search result to client.");
 		}
 		const size_t doneLen = fmt_ldapsearchresultdone(NULL, success, "", "", "");
 		const size_t doneHeaderLen = fmt_ldapmessage(NULL, messageId, SearchResultDone, doneLen);
diff --git a/server.c b/server.c
index ae6a4ae..d5fba2a 100644
--- a/server.c
+++ b/server.c
@@ -173,8 +173,10 @@ void server_setHomeAttribute(const char *server, const char *homeattribute)
 	server_t *entry = server_create(server);
 	if (entry == NULL || entry->sslContext != NULL) return;
 	free((void*)entry->map.homemount.s);
-	entry->map.homemount.s = strdup(homeattribute);
-	entry->map.homemount.l = strlen(homeattribute);
+	char *tmp = strdup(homeattribute);
+	strtolower(tmp);
+	entry->map.homemount.s = tmp;
+	entry->map.homemount.l = strlen(tmp);
 }
 
 void server_setFingerprint(const char *server, const char *fingerprint)