log: implemented log_tcp logging target which sends logs to specified host over tcp/ip

radius: implemented accounting interim update timeout

11 files changed, 355 insertions, 17 deletions

diff --git a/accel-pptpd/accel-pptp.conf b/accel-pptpd/accel-pptp.conf
index 17f497b6..83b1b979 100644
--- a/accel-pptpd/accel-pptp.conf
+++ b/accel-pptpd/accel-pptp.conf
@@ -64,6 +64,9 @@ acct-server=127.0.0.1:1813,testing123
 dae-server=127.0.0.1:3799,testing123
 #dm_coa_secret=testing123 (deprecated)
 verbose=1
+#timeout=3
+#max-try=3
+#acct-timeout=120
 
 [client-ip-range]
 10.0.0.0/8
diff --git a/accel-pptpd/accel-pptp.conf.5 b/accel-pptpd/accel-pptp.conf.5
index 40901531..687ab599 100644
--- a/accel-pptpd/accel-pptp.conf.5
+++ b/accel-pptpd/accel-pptp.conf.5
@@ -29,6 +29,9 @@ containes list of modules to load
 .BI log_file
 This is logging target which logs messages to files. It support per-session/per-user features.
 .TP
+.BI log_tcp
+This is logging target which logs messages over TCP/IP.
+.TP
 .BI log_pgsql
 This is logging target which logs messages to PostgreSQL.
 .TP
@@ -238,6 +241,15 @@ If this option is given and
 .B n
 is greater of zero then radius module will produce verbose logging of interim radius packets.
 .TP
+.BI "timeout=" n
+Timeout to wait response from server (sec) 
+.TP
+.BI "max-try=" n
+Specifies number of tries to send Access-Request/Accounting-Request queries.
+.TP
+.BI "acct-timeout=" n
+Specifies timeout of accounting interim update.
+.TP
 .SH [log]
 .br
 Configuration of log and log_file modules.
@@ -248,6 +260,9 @@ Path to file to write general log.
 .BI "log-emerg=" file
 Path to file to write emergency messages.
 .TP
+.BI "log-tcp=" x.x.x.x:port
+Send logs to specified host.
+.TP
 .BI "copy=" n
 If this options is given and greater then zero logging engine will duplicate session log in general log.
 (Useful when per-session/per-user logs are not used)
diff --git a/accel-pptpd/log.c b/accel-pptpd/log.c
index 6fd60bc3..e8f47b6a 100644
--- a/accel-pptpd/log.c
+++ b/accel-pptpd/log.c
@@ -87,7 +87,7 @@ static void do_log(int level, const char *fmt, va_list ap, struct ppp_t *ppp)
 		m = clone_msg(cur_msg);
 		if (!m)
 			break;
-		t->log(m, ppp);
+		t->log(t, m, ppp);
 	}
 
 out:
diff --git a/accel-pptpd/log.h b/accel-pptpd/log.h
index 140dad1d..ac2b7991 100644
--- a/accel-pptpd/log.h
+++ b/accel-pptpd/log.h
@@ -39,7 +39,7 @@ struct log_target_t
 {
 	struct list_head entry;
 
-	void (*log)(struct log_msg_t *, struct ppp_t *ppp);
+	void (*log)(struct log_target_t *, struct log_msg_t *, struct ppp_t *ppp);
 	void (*reopen)(void);
 };
 
diff --git a/accel-pptpd/logs/CMakeLists.txt b/accel-pptpd/logs/CMakeLists.txt
index b2c432d0..ffcdc2f3 100644
--- a/accel-pptpd/logs/CMakeLists.txt
+++ b/accel-pptpd/logs/CMakeLists.txt
@@ -1,7 +1,9 @@
 ADD_LIBRARY(log_file SHARED log_file.c)
 TARGET_LINK_LIBRARIES(log_file rt)
 
-INSTALL(TARGETS log_file
+ADD_LIBRARY(log_tcp SHARED log_tcp.c)
+
+INSTALL(TARGETS log_file log_tcp
 	LIBRARY DESTINATION usr/lib/accel-pptp
 )
 
diff --git a/accel-pptpd/logs/log_file.c b/accel-pptpd/logs/log_file.c
index f343286b..db08aa25 100644
--- a/accel-pptpd/logs/log_file.c
+++ b/accel-pptpd/logs/log_file.c
@@ -261,7 +261,7 @@ static void set_hdr(struct log_msg_t *msg, struct ppp_t *ppp)
 	msg->hdr->len = strlen(msg->hdr->msg);
 }
 
-static void general_log(struct log_msg_t *msg, struct ppp_t *ppp)
+static void general_log(struct log_target_t *t, struct log_msg_t *msg, struct ppp_t *ppp)
 {
 	if (ppp && !conf_copy) {
 		log_free_msg(msg);
@@ -286,7 +286,7 @@ static struct log_file_pd_t *find_pd(struct ppp_t *ppp, void *pd_key)
 	return NULL;
 }
 
-static void per_user_log(struct log_msg_t *msg, struct ppp_t *ppp)
+static void per_user_log(struct log_target_t *t, struct log_msg_t *msg, struct ppp_t *ppp)
 {
 	struct log_file_pd_t *lpd;
 
@@ -306,7 +306,7 @@ static void per_user_log(struct log_msg_t *msg, struct ppp_t *ppp)
 	queue_log(&lpd->lf, msg);
 }
 
-static void per_session_log(struct log_msg_t *msg, struct ppp_t *ppp)
+static void per_session_log(struct log_target_t *t, struct log_msg_t *msg, struct ppp_t *ppp)
 {
 	struct log_file_pd_t *lpd;
 	
diff --git a/accel-pptpd/logs/log_pgsql.c b/accel-pptpd/logs/log_pgsql.c
index 0eed2431..99a0e82c 100644
--- a/accel-pptpd/logs/log_pgsql.c
+++ b/accel-pptpd/logs/log_pgsql.c
@@ -193,7 +193,7 @@ static void queue_log(struct log_msg_t *msg)
 }
 
 
-static void general_log(struct log_msg_t *msg, struct ppp_t *ppp)
+static void general_log(struct log_target_t *t, struct log_msg_t *msg, struct ppp_t *ppp)
 {
 	set_hdr(msg, ppp);
 	queue_log(msg);
diff --git a/accel-pptpd/logs/log_tcp.c b/accel-pptpd/logs/log_tcp.c
new file mode 100644
index 00000000..2579ac25
--- /dev/null
+++ b/accel-pptpd/logs/log_tcp.c
@@ -0,0 +1,291 @@
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <fcntl.h>
+#include <unistd.h>
+#include <errno.h>
+#include <sys/socket.h>
+#include <arpa/inet.h>
+#include <netinet/in.h>
+
+#include "log.h"
+#include "triton.h"
+#include "events.h"
+#include "ppp.h"
+#include "spinlock.h"
+#include "mempool.h"
+
+#include "memdebug.h"
+
+struct tcp_target_t
+{
+	struct log_target_t target;
+	struct list_head entry;
+	struct triton_md_handler_t hnd;
+	struct triton_timer_t conn_timer;
+  struct sockaddr_in addr;
+	char *buf;
+	int buf_size;
+	int buf_pos;
+	spinlock_t lock;
+	struct list_head queue;
+	int queue_len;
+	int connected:1;
+	int wait:1;
+};
+
+static int conf_connect_interval = 5;
+static int conf_queue_len = 1000;
+
+static struct triton_context_t tcp_ctx;
+
+static const char* level_name[]={"  msg", "error", " warn", " info", "debug"};
+
+static void start_connect(struct tcp_target_t *t);
+
+static void disconnect(struct tcp_target_t *t)
+{
+	triton_md_unregister_handler(&t->hnd);
+	close(t->hnd.fd);
+
+	start_connect(t);
+}
+
+static void unpack_msg(struct tcp_target_t *t, struct log_msg_t *msg)
+{
+	struct log_chunk_t *chunk;
+	int pos = strlen(msg->hdr->msg);
+
+	strcpy(t->buf, msg->hdr->msg);
+
+	list_for_each_entry(chunk, msg->chunks, entry) {
+		memcpy(t->buf + pos, chunk->msg, chunk->len);
+		pos += chunk->len;
+	}
+
+	t->buf_size = pos;
+	t->buf_pos = 0;
+}
+
+static int send_log(struct tcp_target_t *t)
+{
+	struct log_msg_t *msg;
+	int n;
+
+	while (1) {
+		spin_lock(&t->lock);
+		if (!t->queue_len) {
+			t->wait = 0;
+			spin_unlock(&t->lock);
+			return 0;
+		}
+		msg = list_entry(t->queue.next, typeof(*msg), entry);
+		list_del(&msg->entry);
+		t->queue_len--;
+		spin_unlock(&t->lock);
+
+		unpack_msg(t, msg);
+
+		log_free_msg(msg);
+
+		while (t->buf_pos != t->buf_size) {
+			n = write(t->hnd.fd, t->buf + t->buf_pos, t->buf_size - t->buf_pos);
+			if (n < 0) {
+				if (errno == EAGAIN)
+					return 1;
+				if (errno != EPIPE)
+					log_emerg("log-tcp: write: %s\n", strerror(errno));
+				disconnect(t);
+				return 0;
+			}
+			t->buf_pos += n;
+		}
+	}
+}
+
+static void queue_log(struct tcp_target_t *t, struct log_msg_t *msg)
+{
+	int r;
+
+	spin_lock(&t->lock);
+	if (t->queue_len == conf_queue_len) {
+		spin_unlock(&t->lock);
+		log_free_msg(msg);
+	}
+	list_add_tail(&msg->entry, &t->queue);
+	t->queue_len++;
+	if (t->connected) {
+		r = t->wait;
+		t->wait = 1;
+	} else
+		r = 1;
+	spin_unlock(&t->lock);
+
+	if (!r) {
+		if (send_log(t))
+			triton_md_enable_handler(&t->hnd, MD_MODE_WRITE);
+	}
+}
+
+static void set_hdr(struct log_msg_t *msg, struct ppp_t *ppp)
+{
+	struct tm tm;
+	char timestamp[32];
+
+	localtime_r(&msg->timestamp.tv_sec, &tm);
+
+	strftime(timestamp, sizeof(timestamp), "%Y-%m-%d %H:%M:%S", &tm);
+	sprintf(msg->hdr->msg, "[%s]: %s: %s: ", timestamp, level_name[msg->level],	ppp ? ppp->ifname : "");
+	msg->hdr->len = strlen(msg->hdr->msg);
+}
+
+static void general_log(struct log_target_t *lt, struct log_msg_t *msg, struct ppp_t *ppp)
+{
+	struct tcp_target_t *t = container_of(lt, typeof(*t), target);
+
+	set_hdr(msg, ppp);
+	queue_log(t, msg);
+}
+
+static int log_tcp_write(struct triton_md_handler_t *h)
+{
+	struct tcp_target_t *t = container_of(h, typeof(*t), hnd);
+
+	if (!send_log(t))
+		triton_md_disable_handler(h, MD_MODE_WRITE);
+
+	return 0;
+}
+
+static int log_tcp_connect(struct triton_md_handler_t *h)
+{
+	struct tcp_target_t *t = container_of(h, typeof(*t), hnd);
+
+	if (connect(t->hnd.fd, &t->addr, sizeof(t->addr))) {
+		if (errno == EAGAIN)
+			return 0;
+		if (errno == EINPROGRESS)
+			return 0;
+		log_emerg("log-tcp: connect: %s\n", strerror(errno));
+		triton_md_unregister_handler(&t->hnd);
+		close(t->hnd.fd);
+		triton_timer_add(&tcp_ctx, &t->conn_timer, 0);
+		return 0;
+	}
+
+	t->hnd.write = log_tcp_write;
+
+	triton_md_disable_handler(&t->hnd, MD_MODE_WRITE);
+
+	spin_lock(&t->lock);
+	t->connected = 1;
+	t->wait = 1;
+	spin_unlock(&t->lock);
+
+	send_log(t);
+
+	return 0;
+}
+
+static void connect_timer(struct triton_timer_t *timer)
+{
+	struct tcp_target_t *t = container_of(timer, typeof(*t), conn_timer);
+
+	triton_timer_del(timer);
+
+	start_connect(t);
+}
+
+static void start_connect(struct tcp_target_t *t)
+{
+	t->hnd.write = log_tcp_connect;
+	t->hnd.fd = socket(PF_INET, SOCK_STREAM, 0);
+
+	if (!t->hnd.fd) {
+		log_emerg("log-tcp: socket: %s\n", strerror(errno));
+		return;
+	}
+	
+	if (fcntl(t->hnd.fd, F_SETFL, O_NONBLOCK)) {
+    log_emerg("log-tcp: failed to set nonblocking mode: %s\n", strerror(errno));
+		close(t->hnd.fd);
+    return;
+	}
+
+	if (connect(t->hnd.fd, &t->addr, sizeof(t->addr))) {
+		if (errno != EINPROGRESS) {
+			log_emerg("log-tcp: connect: %s\n", strerror(errno));
+			close(t->hnd.fd);
+			return;
+		}
+	}
+
+	triton_md_register_handler(&tcp_ctx, &t->hnd);
+	triton_md_enable_handler(&t->hnd, MD_MODE_WRITE);
+}
+
+static int start_log(const char *_opt)
+{
+	struct tcp_target_t *t;
+	char *opt = strdup(_opt);
+	int port;
+	char *d;
+
+	d = strchr(opt, ':');
+	if (!d)
+		goto err;
+
+	*d = 0;
+
+	port = atoi(d + 1);
+	if (port <= 0)
+		goto err;
+
+	t = _malloc(sizeof(*t));
+	memset(t, 0, sizeof(*t));
+
+	t->buf = _malloc(LOG_MAX_SIZE + 64);
+
+	t->conn_timer.expire_tv.tv_sec = conf_connect_interval;
+	t->conn_timer.expire = connect_timer;
+
+	t->target.log = general_log;
+
+	memset(&t->addr, 0, sizeof(t->addr));
+  t->addr.sin_family = AF_INET;
+  t->addr.sin_port = htons(port);
+	t->addr.sin_addr.s_addr = inet_addr(opt);
+
+	INIT_LIST_HEAD(&t->queue);
+
+	start_connect(t);
+
+	log_register_target(&t->target);
+
+	return 0;
+
+err:
+	free(opt);
+	return -1;
+}
+
+static void __init init(void)
+{
+	struct conf_sect_t *s =	conf_get_section("log");
+	struct conf_option_t *opt;
+	
+	if (!s)
+		return;
+
+	triton_context_register(&tcp_ctx, NULL);
+
+	list_for_each_entry(opt, &s->items, entry) {
+		if (strcmp(opt->name, "log-tcp"))
+			continue;
+		if (!opt->val || start_log(opt->val))
+			log_emerg("log: log-tcp: invalid format: '%s'\n", opt->val);
+	}
+
+	triton_context_wakeup(&tcp_ctx);
+}
+
diff --git a/accel-pptpd/radius/acct.c b/accel-pptpd/radius/acct.c
index f8cfee7a..e0561822 100644
--- a/accel-pptpd/radius/acct.c
+++ b/accel-pptpd/radius/acct.c
@@ -112,11 +112,30 @@ static int rad_acct_read(struct triton_md_handler_t *h)
 static void rad_acct_timeout(struct triton_timer_t *t)
 {
 	struct rad_req_t *req = container_of(t, typeof(*req), timeout);
+	time_t ts, dt;
+
+	time(&ts);
+
+	dt = ts - req->rpd->acct_timestamp;
+
+	if (dt > conf_acct_timeout) {
+		log_ppp_warn("radius: acct: no response, terminating session...\n");
+		ppp_terminate(req->rpd->ppp, 0, TERM_NAS_ERROR);
+		return;
+	}
+	if (dt > conf_acct_timeout / 2) {
+		req->timeout.period += 1000;
+		triton_timer_mod(&req->timeout, 0);
+	} else if (dt > conf_acct_timeout / 3) {
+		if (req->timeout.period != conf_timeout * 2000) {
+			req->timeout.period = conf_timeout * 2000;
+			triton_timer_mod(&req->timeout, 0);
+		}
+	}
 
-	req->rpd->acct_delay_time += conf_timeout;
 	req->pack->id++;
 	
-	rad_packet_change_int(req->pack, "Acct-Delay-Time", req->rpd->acct_delay_time);
+	rad_packet_change_int(req->pack, "Acct-Delay-Time", dt);
 	req_set_RA(req, conf_acct_secret);
 	rad_req_send(req, conf_interim_verbose);
 }
@@ -132,7 +151,7 @@ static void rad_acct_interim_update(struct triton_timer_t *t)
 	if (!rpd->acct_interim_interval)
 		return;
 
-	rpd->acct_delay_time = 0;
+	time(&rpd->acct_timestamp);
 	rpd->acct_req->pack->id++;
 
 	rad_packet_change_val(rpd->acct_req->pack, "Acct-Status-Type", "Interim-Update");
@@ -146,6 +165,7 @@ static void rad_acct_interim_update(struct triton_timer_t *t)
 int rad_acct_start(struct radius_pd_t *rpd)
 {
 	int i;
+	time_t ts;
 
 	rpd->acct_req = rad_req_alloc(rpd, CODE_ACCOUNTING_REQUEST, rpd->ppp->username);
 	if (!rpd->acct_req) {
@@ -168,11 +188,11 @@ int rad_acct_start(struct radius_pd_t *rpd)
 		rpd->acct_req->reply = NULL;
 	}
 
-	rpd->acct_delay_time = 0;
+	time(&rpd->acct_timestamp);
 	
 	for (i = 0; i < conf_max_try; i++) {
-		rad_packet_change_int(rpd->acct_req->pack, "Acct-Delay-Time", rpd->acct_delay_time);
-		rpd->acct_delay_time += conf_timeout;
+		time(&ts);
+		rad_packet_change_int(rpd->acct_req->pack, "Acct-Delay-Time", ts - rpd->acct_timestamp);
 		if (req_set_RA(rpd->acct_req, conf_acct_secret))
 			goto out_err;
 		if (rad_req_send(rpd->acct_req, conf_verbose))
@@ -222,6 +242,7 @@ out_err:
 void rad_acct_stop(struct radius_pd_t *rpd)
 {
 	int i;
+	time_t ts;
 
 	if (rpd->acct_interim_timer.tpd)
 		triton_timer_del(&rpd->acct_interim_timer);
@@ -259,11 +280,11 @@ void rad_acct_stop(struct radius_pd_t *rpd)
 			rpd->acct_req->reply = NULL;
 		}
 	
-		rpd->acct_delay_time = 0;
+		time(&rpd->acct_timestamp);
 
 		for(i = 0; i < conf_max_try; i++) {
-			rad_packet_change_int(rpd->acct_req->pack, "Acct-Delay-Time", rpd->acct_delay_time);
-			rpd->acct_delay_time += conf_timeout;
+			time(&ts);
+			rad_packet_change_int(rpd->acct_req->pack, "Acct-Delay-Time", ts - rpd->acct_timestamp);
 			rpd->acct_req->pack->id++;
 			if (req_set_RA(rpd->acct_req, conf_acct_secret))
 				break;
diff --git a/accel-pptpd/radius/radius.c b/accel-pptpd/radius/radius.c
index 3c885d89..fd3cd1e1 100644
--- a/accel-pptpd/radius/radius.c
+++ b/accel-pptpd/radius/radius.c
@@ -24,6 +24,7 @@
 
 int conf_max_try = 3;
 int conf_timeout = 3;
+int conf_acct_timeout = 600;
 char *conf_nas_identifier = "accel-pptpd";
 in_addr_t conf_nas_ip_address;
 in_addr_t conf_gw_ip_address;
@@ -382,6 +383,10 @@ static void __init radius_init(void)
 	if (opt && atoi(opt) > 0)
 		conf_timeout = atoi(opt);
 
+	opt = conf_get_opt("radius", "acct-timeout");
+	if (opt && atoi(opt) > 0)
+		conf_acct_timeout = atoi(opt);
+
 	opt = conf_get_opt("radius", "verbose");
 	if (opt && atoi(opt) > 0)
 		conf_verbose = 1;
diff --git a/accel-pptpd/radius/radius_p.h b/accel-pptpd/radius/radius_p.h
index 6c4ef8f9..978431a7 100644
--- a/accel-pptpd/radius/radius_p.h
+++ b/accel-pptpd/radius/radius_p.h
@@ -31,7 +31,7 @@ struct radius_pd_t
 
 	struct ipdb_item_t ipaddr;
 	int acct_interim_interval;
-	int acct_delay_time;
+	time_t acct_timestamp;
 
 	uint8_t *attr_class;
 	int attr_class_len;
@@ -56,6 +56,7 @@ struct rad_req_t
 
 extern int conf_max_try;
 extern int conf_timeout;
+extern int conf_acct_timeout;
 extern int conf_verbose;
 extern int conf_interim_verbose;
 extern char *conf_nas_identifier;