4 debug levels, 3 default

git-svn-id: https://svn.testnett.uninett.no/radsecproxy/trunk@78 e88ac4ed-0b26-0410-9574-a7f39faa03bf

6 files changed, 77 insertions, 69 deletions

diff --git a/README b/README
index f541519..62a7714 100644
--- a/README
+++ b/README
@@ -12,11 +12,11 @@ proxy's current work directory. You may alter the path near
 the top of radsecproxy.h if necessary.
 
 There are two options that may be specified on the command line.
-They are "-d loglevel" to set a loglevel of 1, 2 or 3 where 3
+They are "-d loglevel" to set a loglevel of 1, 2, 3 or 4 where 4
 is the most detailed logging. Also "-f" to run the proxy in
 the foreground with logging to stderr. Without "-f" the default
 is to detach as a daemon and log to syslog.
 
 For more information, feedback etc. contact <venaas@uninett.no>.
 
-Stig Venaas, 2007.05.07
+Stig Venaas, 2007.05.09
diff --git a/debug.c b/debug.c
index d852a8d..c36a7be 100644
--- a/debug.c
+++ b/debug.c
@@ -19,7 +19,7 @@
 #include "debug.h"
 
 static char *debug_ident = NULL;
-static uint8_t debug_level = DBG_WARN;
+static uint8_t debug_level = DBG_INFO;
 static FILE *debug_file = NULL;
 static int debug_syslogfacility = 0;
 
@@ -40,6 +40,9 @@ void debug_set_level(uint8_t level) {
     case 3:
 	debug_level = DBG_INFO;
 	return;
+    case 4:
+	debug_level = DBG_DBG;
+	return;
     }
 }
 
@@ -90,6 +93,9 @@ void debug_logit(uint8_t level, const char *format, va_list ap) {
     
     if (debug_syslogfacility) {
 	switch (level) {
+	case DBG_DBG:
+	    priority = LOG_DEBUG;
+	    break;
 	case DBG_INFO:
 	    priority = LOG_INFO;
 	    break;
diff --git a/debug.h b/debug.h
index 036be21..fc2f1d6 100644
--- a/debug.h
+++ b/debug.h
@@ -6,6 +6,7 @@
  * copyright notice and this permission notice appear in all copies.
  */
 
+#define DBG_DBG 8
 #define DBG_INFO 16
 #define DBG_WARN 32
 #define DBG_ERR 64
diff --git a/radsecproxy.c b/radsecproxy.c
index 4b8dccc..f936bba 100644
--- a/radsecproxy.c
+++ b/radsecproxy.c
@@ -331,7 +331,7 @@ unsigned char *radudpget(int s, struct client **client, struct server **server,
 	    debug(DBG_WARN, "radudpget: recv failed");
 	    continue;
 	}
-	debug(DBG_INFO, "radudpget: got %d bytes from %s", cnt, addr2string((struct sockaddr *)&from, fromlen));
+	debug(DBG_DBG, "radudpget: got %d bytes from %s", cnt, addr2string((struct sockaddr *)&from, fromlen));
 
 	if (cnt < 20) {
 	    debug(DBG_WARN, "radudpget: packet too small");
@@ -345,7 +345,7 @@ unsigned char *radudpget(int s, struct client **client, struct server **server,
 	    continue;
 	}
 	if (cnt > len)
-	    debug(DBG_INFO, "radudpget: packet was padded with %d bytes", cnt - len);
+	    debug(DBG_DBG, "radudpget: packet was padded with %d bytes", cnt - len);
 
 	f = (client
 	     ? (void *)find_client('U', (struct sockaddr *)&from, *client)
@@ -410,7 +410,7 @@ int tlsverifycert(struct peer *peer) {
 	}
 #endif	
 	if (l == strlen(peer->host) && !strncasecmp(peer->host, (char *)v, l)) {
-	    debug(DBG_INFO, "tlsverifycert: Found cn matching host %s, All OK", peer->host);
+	    debug(DBG_DBG, "tlsverifycert: Found cn matching host %s, All OK", peer->host);
 	    return 1;
 	}
 	debug(DBG_ERR, "tlsverifycert: cn not matching host %s", peer->host);
@@ -423,16 +423,16 @@ void tlsconnect(struct server *server, struct timeval *when, char *text) {
     struct timeval now;
     time_t elapsed;
 
-    debug(DBG_INFO, "tlsconnect called from %s", text);
+    debug(DBG_DBG, "tlsconnect called from %s", text);
     pthread_mutex_lock(&server->lock);
     if (when && memcmp(&server->lastconnecttry, when, sizeof(struct timeval))) {
 	/* already reconnected, nothing to do */
-	debug(DBG_INFO, "tlsconnect(%s): seems already reconnected", text);
+	debug(DBG_DBG, "tlsconnect(%s): seems already reconnected", text);
 	pthread_mutex_unlock(&server->lock);
 	return;
     }
 
-    debug(DBG_INFO, "tlsconnect %s", text);
+    debug(DBG_DBG, "tlsconnect %s", text);
 
     for (;;) {
 	gettimeofday(&now, NULL);
@@ -443,10 +443,10 @@ void tlsconnect(struct server *server, struct timeval *when, char *text) {
 	} else if (elapsed < 5)
 	    sleep(10);
 	else if (elapsed < 600) {
-	    debug(DBG_WARN, "tlsconnect: sleeping %lds", elapsed);
+	    debug(DBG_INFO, "tlsconnect: sleeping %lds", elapsed);
 	    sleep(elapsed);
 	} else if (elapsed < 1000) {
-	    debug(DBG_WARN, "tlsconnect: sleeping %ds", 900);
+	    debug(DBG_INFO, "tlsconnect: sleeping %ds", 900);
 	    sleep(900);
 	} else
 	    server->lastconnecttry.tv_sec = now.tv_sec;  /* no sleep at startup */
@@ -514,7 +514,7 @@ unsigned char *radtlsget(SSL *ssl) {
 	debug(DBG_WARN, "radtlsget: packet smaller than minimum radius size");
     }
     
-    debug(DBG_INFO, "radtlsget: got %d bytes", total);
+    debug(DBG_DBG, "radtlsget: got %d bytes", total);
     return rad;
 }
 
@@ -527,7 +527,7 @@ int clientradput(struct server *server, unsigned char *rad) {
     len = RADLEN(rad);
     if (server->peer.type == 'U') {
 	if (send(server->sock, rad, len, 0) >= 0) {
-	    debug(DBG_INFO, "clienradput: sent UDP of length %d to %s port %s", len, server->peer.host, server->peer.port);
+	    debug(DBG_DBG, "clienradput: sent UDP of length %d to %s port %s", len, server->peer.host, server->peer.port);
 	    return 1;
 	}
 	debug(DBG_WARN, "clientradput: send failed");
@@ -543,7 +543,7 @@ int clientradput(struct server *server, unsigned char *rad) {
     }
 
     server->connectionok = 1;
-    debug(DBG_INFO, "clientradput: Sent %d bytes, Radius packet of length %d to TLS peer %s",
+    debug(DBG_DBG, "clientradput: Sent %d bytes, Radius packet of length %d to TLS peer %s",
 	   cnt, len, server->peer.host);
     return 1;
 }
@@ -685,7 +685,7 @@ void sendrq(struct server *to, struct client *from, struct request *rq) {
     
     to->nextid = i + 1;
     rq->buf[1] = (char)i;
-    debug(DBG_INFO, "sendrq: inserting packet with id %d in queue for %s", i, to->peer.host);
+    debug(DBG_DBG, "sendrq: inserting packet with id %d in queue for %s", i, to->peer.host);
     
     if (!createmessageauth(rq->buf, rq->messageauthattrval, to->peer.secret))
 	return;
@@ -694,7 +694,7 @@ void sendrq(struct server *to, struct client *from, struct request *rq) {
 
     if (!to->newrq) {
 	to->newrq = 1;
-	debug(DBG_INFO, "signalling client writer");
+	debug(DBG_DBG, "signalling client writer");
 	pthread_cond_signal(&to->newrq_cond);
     }
     pthread_mutex_unlock(&to->newrq_mutex);
@@ -716,7 +716,7 @@ void sendreply(struct client *to, struct server *from, unsigned char *buf, struc
     replyq->count++;
 
     if (replyq->count == 1) {
-	debug(DBG_INFO, "signalling client writer");
+	debug(DBG_DBG, "signalling client writer");
 	pthread_cond_signal(&replyq->count_cond);
     }
     pthread_mutex_unlock(&replyq->count_mutex);
@@ -986,7 +986,7 @@ struct server *id2server(char *id, uint8_t len) {
 	for (realm = servers[i].realms; *realm; realm++) {
 	    if ((strlen(*realm) == 1 && **realm == '*') ||
 		(strlen(*realm) == len && !memcmp(idrealm, *realm, len))) {
-		debug(DBG_INFO, "found matching realm: %s, host %s", *realm, servers[i].peer.host);
+		debug(DBG_DBG, "found matching realm: %s, host %s", *realm, servers[i].peer.host);
 		return servers + i;
 	    }
 	}
@@ -1023,10 +1023,10 @@ struct server *radsrv(struct request *rq, unsigned char *buf, struct client *fro
     len = RADLEN(buf);
     auth = (uint8_t *)(buf + 4);
 
-    debug(DBG_INFO, "radsrv: code %d, id %d, length %d", code, id, len);
+    debug(DBG_DBG, "radsrv: code %d, id %d, length %d", code, id, len);
     
     if (code != RAD_Access_Request) {
-	debug(DBG_WARN, "radsrv: server currently accepts only access-requests, ignoring");
+	debug(DBG_INFO, "radsrv: server currently accepts only access-requests, ignoring");
 	return NULL;
     }
 
@@ -1069,16 +1069,16 @@ struct server *radsrv(struct request *rq, unsigned char *buf, struct client *fro
 	
     memcpy(attrstring, &usernameattr[RAD_Attr_Value], usernameattr[RAD_Attr_Length] - 2);
     attrstring[usernameattr[RAD_Attr_Length] - 2] = '\0';
-    debug(DBG_WARN, "Access Request with username: %s", attrstring);
+    debug(DBG_DBG, "Access Request with username: %s", attrstring);
     
     to = id2server((char *)&usernameattr[RAD_Attr_Value], usernameattr[RAD_Attr_Length] - 2);
     if (!to) {
-	debug(DBG_WARN, "radsrv: ignoring request, don't know where to send it");
+	debug(DBG_INFO, "radsrv: ignoring request, don't know where to send it");
 	return NULL;
     }
 
     if (rqinqueue(to, from, id)) {
-	debug(DBG_WARN, "radsrv: ignoring request from host %s with id %d, already got one", from->peer.host, id);
+	debug(DBG_INFO, "radsrv: ignoring request from host %s with id %d, already got one", from->peer.host, id);
 	return NULL;
     }
     
@@ -1099,7 +1099,7 @@ struct server *radsrv(struct request *rq, unsigned char *buf, struct client *fro
 #endif
     
     if (userpwdattr) {
-	debug(DBG_INFO, "radsrv: found userpwdattr of length %d", userpwdattr[RAD_Attr_Length]);
+	debug(DBG_DBG, "radsrv: found userpwdattr of length %d", userpwdattr[RAD_Attr_Length]);
 	attrvallen = userpwdattr[RAD_Attr_Length] - 2;
 	if (attrvallen < 16 || attrvallen > 128 || attrvallen % 16) {
 	    debug(DBG_WARN, "radsrv: invalid user password length");
@@ -1123,7 +1123,7 @@ struct server *radsrv(struct request *rq, unsigned char *buf, struct client *fro
     }
 
     if (tunnelpwdattr) {
-	debug(DBG_INFO, "radsrv: found tunnelpwdattr of length %d", tunnelpwdattr[RAD_Attr_Length]);
+	debug(DBG_DBG, "radsrv: found tunnelpwdattr of length %d", tunnelpwdattr[RAD_Attr_Length]);
 	attrvallen = tunnelpwdattr[RAD_Attr_Length] - 2;
 	if (attrvallen < 16 || attrvallen > 128 || attrvallen % 16) {
 	    debug(DBG_WARN, "radsrv: invalid user password length");
@@ -1183,29 +1183,29 @@ void *clientrd(void *arg) {
 
 	switch (*buf) {
 	case RAD_Access_Accept:
-	    debug(DBG_WARN, "got Access Accept with id %d", i);
+	    debug(DBG_DBG, "got Access Accept with id %d", i);
 	    break;
 	case RAD_Access_Reject:
-	    debug(DBG_WARN, "got Access Reject with id %d", i);
+	    debug(DBG_DBG, "got Access Reject with id %d", i);
 	    break;
 	case RAD_Access_Challenge:
-	    debug(DBG_WARN, "got Access Challenge with id %d", i);
+	    debug(DBG_DBG, "got Access Challenge with id %d", i);
 	    break;
 	default:
-	    debug(DBG_WARN, "clientrd: discarding, only accept access accept, access reject and access challenge messages");
+	    debug(DBG_INFO, "clientrd: discarding, only accept access accept, access reject and access challenge messages");
 	    continue;
 	}
 	
 	pthread_mutex_lock(&server->newrq_mutex);
 	if (!server->requests[i].buf || !server->requests[i].tries) {
 	    pthread_mutex_unlock(&server->newrq_mutex);
-	    debug(DBG_WARN, "clientrd: no matching request sent with this id, ignoring");
+	    debug(DBG_INFO, "clientrd: no matching request sent with this id, ignoring");
 	    continue;
 	}
 
 	if (server->requests[i].received) {
 	    pthread_mutex_unlock(&server->newrq_mutex);
-	    debug(DBG_WARN, "clientrd: already received, ignoring");
+	    debug(DBG_INFO, "clientrd: already received, ignoring");
 	    continue;
 	}
 	
@@ -1239,7 +1239,7 @@ void *clientrd(void *arg) {
 		    goto getnext;
 		}
 		memcpy(buf + 4, tmp, 16);
-		debug(DBG_INFO, "clientrd: message auth ok");
+		debug(DBG_DBG, "clientrd: message auth ok");
 		messageauthattr = attr;
 		break;
 	    }
@@ -1266,7 +1266,7 @@ void *clientrd(void *arg) {
 		    if (subattr[RAD_Attr_Type] != RAD_VS_ATTR_MS_MPPE_Send_Key &&
 			subattr[RAD_Attr_Type] != RAD_VS_ATTR_MS_MPPE_Recv_Key)
 			continue;
-		    debug(DBG_INFO, "clientrd: Got MS MPPE");
+		    debug(DBG_DBG, "clientrd: Got MS MPPE");
 		    if (subattr[RAD_Attr_Length] < 20)
 			continue;
 
@@ -1290,6 +1290,8 @@ void *clientrd(void *arg) {
 	    attr += attr[RAD_Attr_Length];
 	}
 
+	/* log DBG_INFO that received access accept/reject and username attr from original request */
+	/* TODO STIG */
 	/* once we set received = 1, requests[i] may be reused */
 	buf[1] = (char)server->requests[i].origid;
 	memcpy(buf + 4, server->requests[i].origauth, 16);
@@ -1299,7 +1301,7 @@ void *clientrd(void *arg) {
 	if (messageauthattr) {
 	    if (!createmessageauth(buf, &messageauthattr[RAD_Attr_Value], from->peer.secret))
 		continue;
-	    debug(DBG_INFO, "clientrd: computed messageauthattr");
+	    debug(DBG_DBG, "clientrd: computed messageauthattr");
 	}
 
 	if (from->peer.type == 'U')
@@ -1314,7 +1316,7 @@ void *clientrd(void *arg) {
 #ifdef DEBUG	
 	printauth("signedorigauth/buf+4", buf + 4);
 #endif	
-	debug(DBG_INFO, "clientrd: giving packet back to where it came from");
+	debug(DBG_DBG, "clientrd: giving packet back to where it came from");
 	sendreply(from, server, buf, from->peer.type == 'U' ? &fromsa : NULL);
     }
 }
@@ -1345,7 +1347,7 @@ void *clientwr(void *arg) {
 	if (!server->newrq) {
 	    gettimeofday(&now, NULL);
 	    if (timeout.tv_sec) {
-		debug(DBG_INFO, "clientwr: waiting up to %ld secs for new request", timeout.tv_sec - now.tv_sec);
+		debug(DBG_DBG, "clientwr: waiting up to %ld secs for new request", timeout.tv_sec - now.tv_sec);
 		pthread_cond_timedwait(&server->newrq_cond, &server->newrq_mutex, &timeout);
 		timeout.tv_sec = 0;
 	    } else if (options.statusserver) {
@@ -1356,15 +1358,15 @@ void *clientwr(void *arg) {
 		pthread_cond_timedwait(&server->newrq_cond, &server->newrq_mutex, &timeout);
 		timeout.tv_sec = 0;
 	    } else {
-		debug(DBG_INFO, "clientwr: waiting for new request");
+		debug(DBG_DBG, "clientwr: waiting for new request");
 		pthread_cond_wait(&server->newrq_cond, &server->newrq_mutex);
 	    }
 	}
 	if (server->newrq) {
-	    debug(DBG_INFO, "clientwr: got new request");
+	    debug(DBG_DBG, "clientwr: got new request");
 	    server->newrq = 0;
 	} else
-	    debug(DBG_INFO, "clientwr: request timer expired, processing request queue");
+	    debug(DBG_DBG, "clientwr: request timer expired, processing request queue");
 	pthread_mutex_unlock(&server->newrq_mutex);
 
 	for (i = 0; i < MAX_REQUESTS; i++) {
@@ -1378,7 +1380,7 @@ void *clientwr(void *arg) {
 	    rq = server->requests + i;
 
             if (rq->received) {
-		debug(DBG_INFO, "clientwr: removing received packet from queue");
+		debug(DBG_DBG, "clientwr: removing received packet from queue");
                 free(rq->buf);
                 /* setting this to NULL means that it can be reused */
                 rq->buf = NULL;
@@ -1395,7 +1397,7 @@ void *clientwr(void *arg) {
 	    }
 
 	    if (rq->tries == (server->peer.type == 'T' ? 1 : REQUEST_RETRIES)) {
-		debug(DBG_INFO, "clientwr: removing expired packet from queue");
+		debug(DBG_DBG, "clientwr: removing expired packet from queue");
 		free(rq->buf);
 		/* setting this to NULL means that it can be reused */
 		rq->buf = NULL;
@@ -1417,7 +1419,7 @@ void *clientwr(void *arg) {
 	    gettimeofday(&now, NULL);
 	    if (now.tv_sec - lastsend.tv_sec >= STATUS_SERVER_PERIOD) {
 		lastsend.tv_sec = now.tv_sec;
-		debug(DBG_INFO, "clientwr: should send status to %s here", server->peer.host);
+		debug(DBG_DBG, "clientwr: should send status to %s here", server->peer.host);
 	    }
 	}
     }
@@ -1430,9 +1432,9 @@ void *udpserverwr(void *arg) {
     pthread_mutex_lock(&replyq->count_mutex);
     for (;;) {
 	while (!replyq->count) {
-	    debug(DBG_INFO, "udp server writer, waiting for signal");
+	    debug(DBG_DBG, "udp server writer, waiting for signal");
 	    pthread_cond_wait(&replyq->count_cond, &replyq->count_mutex);
-	    debug(DBG_INFO, "udp server writer, got signal");
+	    debug(DBG_DBG, "udp server writer, got signal");
 	}
 	pthread_mutex_unlock(&replyq->count_mutex);
 	
@@ -1470,7 +1472,7 @@ void *udpserverrd(void *arg) {
 	buf = radudpget(udp_server_sock, &fr, NULL, &rq.fromsa);
 	to = radsrv(&rq, buf, fr);
 	if (!to) {
-	    debug(DBG_WARN, "udpserverrd: ignoring request, no place to send it");
+	    debug(DBG_INFO, "udpserverrd: ignoring request, no place to send it");
 	    continue;
 	}
 	sendrq(to, fr, &rq);
@@ -1483,27 +1485,27 @@ void *tlsserverwr(void *arg) {
     struct client *client = (struct client *)arg;
     struct replyq *replyq;
     
-    debug(DBG_INFO, "tlsserverwr starting for %s", client->peer.host);
+    debug(DBG_DBG, "tlsserverwr starting for %s", client->peer.host);
     replyq = client->replyq;
     pthread_mutex_lock(&replyq->count_mutex);
     for (;;) {
 	while (!replyq->count) {
 	    if (client->peer.ssl) {	    
-		debug(DBG_INFO, "tls server writer, waiting for signal");
+		debug(DBG_DBG, "tls server writer, waiting for signal");
 		pthread_cond_wait(&replyq->count_cond, &replyq->count_mutex);
-		debug(DBG_INFO, "tls server writer, got signal");
+		debug(DBG_DBG, "tls server writer, got signal");
 	    }
 	    if (!client->peer.ssl) {
 		/* ssl might have changed while waiting */
 		pthread_mutex_unlock(&replyq->count_mutex);
-		debug(DBG_INFO, "tlsserverwr: exiting as requested");
+		debug(DBG_DBG, "tlsserverwr: exiting as requested");
 		pthread_exit(NULL);
 	    }
 	}
 	pthread_mutex_unlock(&replyq->count_mutex);
 	cnt = SSL_write(client->peer.ssl, replyq->replies->buf, RADLEN(replyq->replies->buf));
 	if (cnt > 0)
-	    debug(DBG_INFO, "tlsserverwr: Sent %d bytes, Radius packet of length %d",
+	    debug(DBG_DBG, "tlsserverwr: Sent %d bytes, Radius packet of length %d",
 		  cnt, RADLEN(replyq->replies->buf));
 	else
 	    while ((error = ERR_get_error()))
@@ -1526,7 +1528,7 @@ void *tlsserverrd(void *arg) {
     pthread_t tlsserverwrth;
     SSL *ssl;
     
-    debug(DBG_INFO, "tlsserverrd starting for %s", client->peer.host);
+    debug(DBG_DBG, "tlsserverrd starting for %s", client->peer.host);
     ssl = client->peer.ssl;
 
     if (SSL_accept(ssl) <= 0) {
@@ -1544,11 +1546,11 @@ void *tlsserverrd(void *arg) {
 	    buf = radtlsget(client->peer.ssl);
 	    if (!buf)
 		break;
-	    debug(DBG_INFO, "tlsserverrd: got Radius message from %s", client->peer.host);
+	    debug(DBG_DBG, "tlsserverrd: got Radius message from %s", client->peer.host);
 	    memset(&rq, 0, sizeof(struct request));
 	    to = radsrv(&rq, buf, client);
 	    if (!to) {
-		debug(DBG_WARN, "tlsserverrd: ignoring request, no place to send it");
+		debug(DBG_INFO, "tlsserverrd: ignoring request, no place to send it");
 		continue;
 	    }
 	    sendrq(to, client, &rq);
@@ -1559,7 +1561,7 @@ void *tlsserverrd(void *arg) {
 	pthread_mutex_lock(&client->replyq->count_mutex);
 	pthread_cond_signal(&client->replyq->count_cond);
 	pthread_mutex_unlock(&client->replyq->count_mutex);
-	debug(DBG_INFO, "tlsserverrd: waiting for writer to end");
+	debug(DBG_DBG, "tlsserverrd: waiting for writer to end");
 	pthread_join(tlsserverwrth, NULL);
     }
     
@@ -1568,7 +1570,7 @@ void *tlsserverrd(void *arg) {
     SSL_free(ssl);
     shutdown(s, SHUT_RDWR);
     close(s);
-    debug(DBG_INFO, "tlsserverrd thread for %s exiting", client->peer.host);
+    debug(DBG_DBG, "tlsserverrd thread for %s exiting", client->peer.host);
     client->peer.ssl = NULL;
     pthread_exit(NULL);
 }
@@ -1694,7 +1696,7 @@ FILE *openconfigfile(const char *filename) {
     
     f = fopen(filename, "r");
     if (f) {
-	debug(DBG_INFO, "reading config file %s", filename);
+	debug(DBG_DBG, "reading config file %s", filename);
 	return f;
     }
 
@@ -1708,7 +1710,7 @@ FILE *openconfigfile(const char *filename) {
     if (!f)
 	debugx(1, DBG_ERR, "could not read config file %s nor %s\n%s", filename, base, strerror(errno));
     
-    debug(DBG_INFO, "reading config file %s", base);
+    debug(DBG_DBG, "reading config file %s", base);
     return f;
 }
 
@@ -1833,11 +1835,11 @@ void getconfig(const char *serverfile, const char *clientfile) {
 		pthread_cond_init(&client->replyq->count_cond, NULL);
 	    }
 	}
-	debug(DBG_INFO, "got type %c, host %s, port %s, secret %s", peer->type, peer->host, peer->port, peer->secret);
+	debug(DBG_DBG, "got type %c, host %s, port %s, secret %s", peer->type, peer->host, peer->port, peer->secret);
 	if (serverfile) {
-	    debug(DBG_INFO, "    with realms:");
+	    debug(DBG_DBG, "    with realms:");
 	    for (r = server->realms; *r; r++)
-		debug(DBG_INFO, "\t%s", *r);
+		debug(DBG_DBG, "\t%s", *r);
 	}
 	i++;
     }
@@ -1893,7 +1895,7 @@ void getmainconfig(const char *configfile) {
 		endval = p;
 	endopt[1] = '\0';
 	endval[1] = '\0';
-	debug(DBG_INFO, "getmainconfig: %s = %s", opt, val);
+	debug(DBG_DBG, "getmainconfig: %s = %s", opt, val);
 	
 	if (!strcasecmp(opt, "TLSCACertificateFile")) {
 	    options.tlscacertificatefile = stringcopy(val, 0);
@@ -1932,8 +1934,8 @@ void getmainconfig(const char *configfile) {
 	    continue;
 	}
 	if (!strcasecmp(opt, "LogLevel")) {
-	    if (strlen(val) != 1 || *val < '1' || *val > '3')
-		debugx(1, DBG_ERR, "error in %s, value of option %s is %s, must be 1, 2 or 3", configfile, opt, val);
+	    if (strlen(val) != 1 || *val < '1' || *val > '4')
+		debugx(1, DBG_ERR, "error in %s, value of option %s is %s, must be 1, 2, 3 or 4", configfile, opt, val);
 	    options.loglevel = *val - '0';
 	    continue;
 	}
@@ -1952,8 +1954,8 @@ void getargs(int argc, char **argv, uint8_t *foreground, uint8_t *loglevel) {
     while ((c = getopt(argc, argv, "d:f")) != -1) {
 	switch (c) {
 	case 'd':
-	    if (strlen(optarg) != 1 || *optarg < '1' || *optarg > '3')
-		debugx(1, DBG_ERR, "Debug level must be 1, 2 or 3, not %s", optarg);
+	    if (strlen(optarg) != 1 || *optarg < '1' || *optarg > '4')
+		debugx(1, DBG_ERR, "Debug level must be 1, 2, 3 or 4, not %s", optarg);
 	    *loglevel = *optarg - '0';
 	    break;
 	case 'f':
diff --git a/radsecproxy.conf-example b/radsecproxy.conf-example
index 7e9c93f..0953709 100644
--- a/radsecproxy.conf-example
+++ b/radsecproxy.conf-example
@@ -18,8 +18,8 @@ TLSCertificateKeyPassword	follow the white rabbit
 #listenUDP		localhost
 #listenTCP		10.10.10.10:2084
 #ListenTCP		[2001:700:1:7:215:f2ff:fe35:307d]:2084
-# Optional log level. 2 is default, 1 is less, 3 is more
-#LogLevel		2
+# Optional log level. 3 is default, 1 is less, 4 is more
+#LogLevel		3
 #Optional LogDestinatinon, else stderr used for logging
 # Logging to file
 #LogDestination		file:///tmp/rp.log
@@ -28,4 +28,3 @@ TLSCertificateKeyPassword	follow the white rabbit
 # LOG_LOCAL0, ..., LOG_LOCAL7
 #LogDestination         x-syslog://
 #LogDestination         x-syslog://log_local2
-
diff --git a/radsecproxy.h b/radsecproxy.h
index 0451407..d61478c 100644
--- a/radsecproxy.h
+++ b/radsecproxy.h
@@ -6,7 +6,7 @@
  * copyright notice and this permission notice appear in all copies.
  */
 
-#define DEBUG_LEVEL 2
+#define DEBUG_LEVEL 3
 
 #define CONFIG_MAIN "/etc/radsecproxy/radsecproxy.conf"
 #define CONFIG_SERVERS "/etc/radsecproxy/servers.conf"