j3d1/tinc
1
0
Fork 0
Code Issues 1 Pull requests Releases Wiki Activity

Allow log messages to be captured by tincctl.

Browse source 
This allows tincctl to receive log messages from a running tincd,
independent of what is logged to syslog or to file. Tincctl can receive
debug messages with an arbitrary level.
This commit is contained in:
Guus Sliepen 2012-02-26 18:37:36 +01:00
parent a1bd3a2913
commit 8ac096b5bf
47 changed files with 613 additions and 582 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

4
doc/tinc.texi
View file

@ -2023,6 +2023,10 @@ Purges all information remembered about unreachable nodes.
@item debug @var{level} @item debug @var{level}
Sets debug level to @var{level}. Sets debug level to @var{level}.
@item log [@var{level}]
Capture log messages from a running tinc daemon.
An optional debug level can be given that will be applied only for log messages sent to tincctl.
@item retry @item retry
Forces tinc to try to connect to all uplinks immediately. Forces tinc to try to connect to all uplinks immediately.
Usually tinc attempts to do this itself, Usually tinc attempts to do this itself,

4
doc/tincctl.8.in
View file

@ -93,6 +93,10 @@ Purges all information remembered about unreachable nodes.
.It debug Ar N .It debug Ar N
Sets debug level to Sets debug level to
.Ar N . .Ar N .
.It log Op Ar N
Capture log messages from a running tinc daemon.
An optional debug level can be given that will be applied only for log messages sent to
.Nm tincctl .
.It retry .It retry
Forces Forces
.Xr tincd 8 .Xr tincd 8

40
src/bsd/device.c
View file

@ -81,7 +81,7 @@ static bool setup_device(void) {
else if(!strcasecmp(type, "tap")) else if(!strcasecmp(type, "tap"))
device_type = DEVICE_TYPE_TAP; device_type = DEVICE_TYPE_TAP;
else { else {
logger(LOG_ERR, "Unknown device type %s!", type); logger(DEBUG_ALWAYS, LOG_ERR, "Unknown device type %s!", type);
return false; return false;
} }
} else { } else {
@ -102,7 +102,7 @@ static bool setup_device(void) {
} }
if(device_fd < 0) { if(device_fd < 0) {
logger(LOG_ERR, "Could not open %s: %s", device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open %s: %s", device, strerror(errno));
return false; return false;
} }
@ -118,7 +118,7 @@ static bool setup_device(void) {
{ {
const int zero = 0; const int zero = 0;
if(ioctl(device_fd, TUNSIFHEAD, &zero, sizeof zero) == -1) { if(ioctl(device_fd, TUNSIFHEAD, &zero, sizeof zero) == -1) {
logger(LOG_ERR, "System call `%s' failed: %s", "ioctl", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "ioctl", strerror(errno));
return false; return false;
} }
} }
@ -137,7 +137,7 @@ static bool setup_device(void) {
{ {
const int one = 1; const int one = 1;
if(ioctl(device_fd, TUNSIFHEAD, &one, sizeof one) == -1) { if(ioctl(device_fd, TUNSIFHEAD, &one, sizeof one) == -1) {
logger(LOG_ERR, "System call `%s' failed: %s", "ioctl", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "ioctl", strerror(errno));
return false; return false;
} }
} }
@ -174,7 +174,7 @@ static bool setup_device(void) {
#endif #endif
} }
logger(LOG_INFO, "%s is a %s", device, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s is a %s", device, device_info);
return true; return true;
} }
@ -208,7 +208,7 @@ static bool read_packet(vpn_packet_t *packet) {
inlen = read(device_fd, packet->data + 14, MTU - 14); inlen = read(device_fd, packet->data + 14, MTU - 14);
if(inlen <= 0) { if(inlen <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -223,7 +223,7 @@ static bool read_packet(vpn_packet_t *packet) {
packet->data[13] = 0xDD; packet->data[13] = 0xDD;
break; break;
default: default:
ifdebug(TRAFFIC) logger(LOG_ERR, logger(DEBUG_TRAFFIC, LOG_ERR,
"Unknown IP version %d while reading packet from %s %s", "Unknown IP version %d while reading packet from %s %s",
packet->data[14] >> 4, device_info, device); packet->data[14] >> 4, device_info, device);
return false; return false;
@ -237,7 +237,7 @@ static bool read_packet(vpn_packet_t *packet) {
struct iovec vector[2] = {{&type, sizeof type}, {packet->data + 14, MTU - 14}}; struct iovec vector[2] = {{&type, sizeof type}, {packet->data + 14, MTU - 14}};
if((inlen = readv(device_fd, vector, 2)) <= 0) { if((inlen = readv(device_fd, vector, 2)) <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -254,7 +254,7 @@ static bool read_packet(vpn_packet_t *packet) {
break; break;
default: default:
ifdebug(TRAFFIC) logger(LOG_ERR, logger(DEBUG_TRAFFIC, LOG_ERR,
"Unknown address family %x while reading packet from %s %s", "Unknown address family %x while reading packet from %s %s",
ntohl(type), device_info, device); ntohl(type), device_info, device);
return false; return false;
@ -266,7 +266,7 @@ static bool read_packet(vpn_packet_t *packet) {
case DEVICE_TYPE_TAP: case DEVICE_TYPE_TAP:
if((inlen = read(device_fd, packet->data, MTU)) <= 0) { if((inlen = read(device_fd, packet->data, MTU)) <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -280,20 +280,20 @@ static bool read_packet(vpn_packet_t *packet) {
device_total_in += packet->len; device_total_in += packet->len;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Read packet of %d bytes from %s", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Read packet of %d bytes from %s",
packet->len, device_info); packet->len, device_info);
return true; return true;
} }
static bool write_packet(vpn_packet_t *packet) { static bool write_packet(vpn_packet_t *packet) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Writing packet of %d bytes to %s", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Writing packet of %d bytes to %s",
packet->len, device_info); packet->len, device_info);
switch(device_type) { switch(device_type) {
case DEVICE_TYPE_TUN: case DEVICE_TYPE_TUN:
if(write(device_fd, packet->data + 14, packet->len - 14) < 0) { if(write(device_fd, packet->data + 14, packet->len - 14) < 0) {
logger(LOG_ERR, "Error while writing to %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while writing to %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -314,14 +314,14 @@ static bool write_packet(vpn_packet_t *packet) {
type = htonl(AF_INET6); type = htonl(AF_INET6);
break; break;
default: default:
ifdebug(TRAFFIC) logger(LOG_ERR, logger(DEBUG_TRAFFIC, LOG_ERR,
"Unknown address family %x while writing packet to %s %s", "Unknown address family %x while writing packet to %s %s",
af, device_info, device); af, device_info, device);
return false; return false;
} }
if(writev(device_fd, vector, 2) < 0) { if(writev(device_fd, vector, 2) < 0) {
logger(LOG_ERR, "Can't write to %s %s: %s", device_info, device, logger(DEBUG_ALWAYS, LOG_ERR, "Can't write to %s %s: %s", device_info, device,
strerror(errno)); strerror(errno));
return false; return false;
} }
@ -330,7 +330,7 @@ static bool write_packet(vpn_packet_t *packet) {
case DEVICE_TYPE_TAP: case DEVICE_TYPE_TAP:
if(write(device_fd, packet->data, packet->len) < 0) { if(write(device_fd, packet->data, packet->len) < 0) {
logger(LOG_ERR, "Error while writing to %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while writing to %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -339,7 +339,7 @@ static bool write_packet(vpn_packet_t *packet) {
#ifdef HAVE_TUNEMU #ifdef HAVE_TUNEMU
case DEVICE_TYPE_TUNEMU: case DEVICE_TYPE_TUNEMU:
if(tunemu_write(device_fd, packet->data + 14, packet->len - 14) < 0) { if(tunemu_write(device_fd, packet->data + 14, packet->len - 14) < 0) {
logger(LOG_ERR, "Error while writing to %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while writing to %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -356,9 +356,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out);
} }
const devops_t os_devops = { const devops_t os_devops = {

20
src/conf.c
View file

@ -141,7 +141,7 @@ bool get_config_bool(const config_t *cfg, bool *result) {
return true; return true;
} }
logger(LOG_ERR, "\"yes\" or \"no\" expected for configuration variable %s in %s line %d", logger(DEBUG_ALWAYS, LOG_ERR, "\"yes\" or \"no\" expected for configuration variable %s in %s line %d",
cfg->variable, cfg->file, cfg->line); cfg->variable, cfg->file, cfg->line);
return false; return false;
@ -154,7 +154,7 @@ bool get_config_int(const config_t *cfg, int *result) {
if(sscanf(cfg->value, "%d", result) == 1) if(sscanf(cfg->value, "%d", result) == 1)
return true; return true;
logger(LOG_ERR, "Integer expected for configuration variable %s in %s line %d", logger(DEBUG_ALWAYS, LOG_ERR, "Integer expected for configuration variable %s in %s line %d",
cfg->variable, cfg->file, cfg->line); cfg->variable, cfg->file, cfg->line);
return false; return false;
@ -182,7 +182,7 @@ bool get_config_address(const config_t *cfg, struct addrinfo **result) {
return true; return true;
} }
logger(LOG_ERR, "Hostname or IP address expected for configuration variable %s in %s line %d", logger(DEBUG_ALWAYS, LOG_ERR, "Hostname or IP address expected for configuration variable %s in %s line %d",
cfg->variable, cfg->file, cfg->line); cfg->variable, cfg->file, cfg->line);
return false; return false;
@ -195,7 +195,7 @@ bool get_config_subnet(const config_t *cfg, subnet_t ** result) {
return false; return false;
if(!str2net(&subnet, cfg->value)) { if(!str2net(&subnet, cfg->value)) {
logger(LOG_ERR, "Subnet expected for configuration variable %s in %s line %d", logger(DEBUG_ALWAYS, LOG_ERR, "Subnet expected for configuration variable %s in %s line %d",
cfg->variable, cfg->file, cfg->line); cfg->variable, cfg->file, cfg->line);
return false; return false;
} }
@ -206,7 +206,7 @@ bool get_config_subnet(const config_t *cfg, subnet_t ** result) {
&& !maskcheck(&subnet.net.ipv4.address, subnet.net.ipv4.prefixlength, sizeof subnet.net.ipv4.address)) && !maskcheck(&subnet.net.ipv4.address, subnet.net.ipv4.prefixlength, sizeof subnet.net.ipv4.address))
|| ((subnet.type == SUBNET_IPV6) || ((subnet.type == SUBNET_IPV6)
&& !maskcheck(&subnet.net.ipv6.address, subnet.net.ipv6.prefixlength, sizeof subnet.net.ipv6.address))) { && !maskcheck(&subnet.net.ipv6.address, subnet.net.ipv6.prefixlength, sizeof subnet.net.ipv6.address))) {
logger(LOG_ERR, "Network address and prefix length do not match for configuration variable %s in %s line %d", logger(DEBUG_ALWAYS, LOG_ERR, "Network address and prefix length do not match for configuration variable %s in %s line %d",
cfg->variable, cfg->file, cfg->line); cfg->variable, cfg->file, cfg->line);
return false; return false;
} }
@ -265,10 +265,10 @@ config_t *parse_config_line(char *line, const char *fname, int lineno) {
if(!*value) { if(!*value) {
const char err[] = "No value for variable"; const char err[] = "No value for variable";
if (fname) if (fname)
logger(LOG_ERR, "%s `%s' on line %d while reading config file %s", logger(DEBUG_ALWAYS, LOG_ERR, "%s `%s' on line %d while reading config file %s",
err, variable, lineno, fname); err, variable, lineno, fname);
else else
logger(LOG_ERR, "%s `%s' in command line option %d", logger(DEBUG_ALWAYS, LOG_ERR, "%s `%s' in command line option %d",
err, variable, lineno); err, variable, lineno);
return NULL; return NULL;
} }
@ -298,7 +298,7 @@ bool read_config_file(splay_tree_t *config_tree, const char *fname) {
fp = fopen(fname, "r"); fp = fopen(fname, "r");
if(!fp) { if(!fp) {
logger(LOG_ERR, "Cannot open config file %s: %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Cannot open config file %s: %s", fname, strerror(errno));
return false; return false;
} }
@ -379,7 +379,7 @@ bool read_server_config(void) {
x = read_config_file(config_tree, fname); x = read_config_file(config_tree, fname);
if(!x) { /* System error: complain */ if(!x) { /* System error: complain */
logger(LOG_ERR, "Failed to read `%s': %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Failed to read `%s': %s", fname, strerror(errno));
} }
free(fname); free(fname);
@ -407,7 +407,7 @@ bool append_config_file(const char *name, const char *key, const char *value) {
FILE *fp = fopen(fname, "a"); FILE *fp = fopen(fname, "a");
if(!fp) { if(!fp) {
logger(LOG_ERR, "Cannot open config file %s: %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Cannot open config file %s: %s", fname, strerror(errno));
} else { } else {
fprintf(fp, "\n# The following line was automatically added by tinc\n%s = %s\n", key, value); fprintf(fp, "\n# The following line was automatically added by tinc\n%s = %s\n", key, value);
fclose(fp); fclose(fp);

2
src/conf.h
View file

@ -62,8 +62,6 @@ extern void read_config_options(splay_tree_t *, const char *);
extern bool read_server_config(void); extern bool read_server_config(void);
extern bool read_connection_config(struct connection_t *); extern bool read_connection_config(struct connection_t *);
extern bool append_config_file(const char *, const char *, const char *); extern bool append_config_file(const char *, const char *, const char *);
extern FILE *ask_and_open(const char *, const char *, const char *);
extern bool is_safe_path(const char *);
extern bool disable_old_keys(FILE *); extern bool disable_old_keys(FILE *);
#endif /* __TINC_CONF_H__ */ #endif /* __TINC_CONF_H__ */

9
src/connection.h
View file

@ -1,6 +1,6 @@
/* /*
connection.h -- header for connection.c connection.h -- header for connection.c
Copyright (C) 2000-2010 Guus Sliepen <guus@tinc-vpn.org>, Copyright (C) 2000-2012 Guus Sliepen <guus@tinc-vpn.org>,
2000-2005 Ivo Timmermans 2000-2005 Ivo Timmermans
This program is free software; you can redistribute it and/or modify This program is free software; you can redistribute it and/or modify
@ -43,9 +43,10 @@ typedef struct connection_status_t {
unsigned int encryptout:1; /* 1 if we can encrypt outgoing traffic */ unsigned int encryptout:1; /* 1 if we can encrypt outgoing traffic */
unsigned int decryptin:1; /* 1 if we have to decrypt incoming traffic */ unsigned int decryptin:1; /* 1 if we have to decrypt incoming traffic */
unsigned int mst:1; /* 1 if this connection is part of a minimum spanning tree */ unsigned int mst:1; /* 1 if this connection is part of a minimum spanning tree */
unsigned int control:1; unsigned int control:1; /* 1 if this is a control connection */
unsigned int pcap:1; unsigned int pcap:1; /* 1 if this is a control connection requesting packet capture */
unsigned int unused:21; unsigned int log:1; /* 1 if this is a control connection requesting log dump */
unsigned int unused:20;
} connection_status_t; } connection_status_t;
#include "ecdh.h" #include "ecdh.h"

17
src/control.c
View file

@ -1,6 +1,6 @@
/* /*
control.c -- Control socket handling. control.c -- Control socket handling.
Copyright (C) 2007 Guus Sliepen <guus@tinc-vpn.org> Copyright (C) 2012 Guus Sliepen <guus@tinc-vpn.org>
This program is free software; you can redistribute it and/or modify This program is free software; you can redistribute it and/or modify
it under the terms of the GNU General Public License as published by it under the terms of the GNU General Public License as published by
@ -48,12 +48,12 @@ bool control_h(connection_t *c, char *request) {
int type; int type;
if(!c->status.control || c->allow_request != CONTROL) { if(!c->status.control || c->allow_request != CONTROL) {
logger(LOG_ERR, "Unauthorized control request from %s (%s)", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Unauthorized control request from %s (%s)", c->name, c->hostname);
return false; return false;
} }
if(sscanf(request, "%*d %d", &type) != 1) { if(sscanf(request, "%*d %d", &type) != 1) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "CONTROL", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "CONTROL", c->name, c->hostname);
return false; return false;
} }
@ -93,7 +93,7 @@ bool control_h(connection_t *c, char *request) {
return control_ok(c, REQ_RETRY); return control_ok(c, REQ_RETRY);
case REQ_RELOAD: case REQ_RELOAD:
logger(LOG_NOTICE, "Got '%s' command", "reload"); logger(DEBUG_ALWAYS, LOG_NOTICE, "Got '%s' command", "reload");
int result = reload_configuration(); int result = reload_configuration();
return control_return(c, REQ_RELOAD, result); return control_return(c, REQ_RELOAD, result);
@ -122,10 +122,17 @@ bool control_h(connection_t *c, char *request) {
return dump_traffic(c); return dump_traffic(c);
case REQ_PCAP: case REQ_PCAP:
sscanf(request, "%*d %*d %d", &c->outmaclength);
c->status.pcap = true; c->status.pcap = true;
pcap = true; pcap = true;
return true; return true;
case REQ_LOG:
sscanf(request, "%*d %*d %d", &c->outcompression);
c->status.log = true;
logcontrol = true;
return true;
default: default:
return send_request(c, "%d %d", CONTROL, REQ_INVALID); return send_request(c, "%d %d", CONTROL, REQ_INVALID);
} }
@ -137,7 +144,7 @@ bool init_control(void) {
FILE *f = fopen(pidfilename, "w"); FILE *f = fopen(pidfilename, "w");
if(!f) { if(!f) {
logger(LOG_ERR, "Cannot write control socket cookie file %s: %s", pidfilename, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Cannot write control socket cookie file %s: %s", pidfilename, strerror(errno));
return false; return false;
} }

1
src/control_common.h
View file

@ -39,6 +39,7 @@ enum request_type {
REQ_DISCONNECT, REQ_DISCONNECT,
REQ_DUMP_TRAFFIC, REQ_DUMP_TRAFFIC,
REQ_PCAP, REQ_PCAP,
REQ_LOG,
}; };
#define TINC_CTL_VERSION_CURRENT 0 #define TINC_CTL_VERSION_CURRENT 0

34
src/cygwin/device.c
View file

@ -64,7 +64,7 @@ static bool setup_device(void) {
/* Open registry and look for network adapters */ /* Open registry and look for network adapters */
if(RegOpenKeyEx(HKEY_LOCAL_MACHINE, NETWORK_CONNECTIONS_KEY, 0, KEY_READ, &key)) { if(RegOpenKeyEx(HKEY_LOCAL_MACHINE, NETWORK_CONNECTIONS_KEY, 0, KEY_READ, &key)) {
logger(LOG_ERR, "Unable to read registry: %s", winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to read registry: %s", winerror(GetLastError()));
return false; return false;
} }
@ -116,7 +116,7 @@ static bool setup_device(void) {
RegCloseKey(key); RegCloseKey(key);
if(!found) { if(!found) {
logger(LOG_ERR, "No Windows tap device found!"); logger(DEBUG_ALWAYS, LOG_ERR, "No Windows tap device found!");
return false; return false;
} }
@ -133,7 +133,7 @@ static bool setup_device(void) {
Furthermore I don't really know how to do it the "Windows" way. */ Furthermore I don't really know how to do it the "Windows" way. */
if(socketpair(AF_UNIX, SOCK_DGRAM, PF_UNIX, sp)) { if(socketpair(AF_UNIX, SOCK_DGRAM, PF_UNIX, sp)) {
logger(LOG_DEBUG, "System call `%s' failed: %s", "socketpair", strerror(errno)); logger(DEBUG_ALWAYS, LOG_DEBUG, "System call `%s' failed: %s", "socketpair", strerror(errno));
return false; return false;
} }
@ -142,7 +142,7 @@ static bool setup_device(void) {
device_handle = CreateFile(tapname, GENERIC_WRITE, FILE_SHARE_READ, 0, OPEN_EXISTING, FILE_ATTRIBUTE_SYSTEM , 0); device_handle = CreateFile(tapname, GENERIC_WRITE, FILE_SHARE_READ, 0, OPEN_EXISTING, FILE_ATTRIBUTE_SYSTEM , 0);
if(device_handle == INVALID_HANDLE_VALUE) { if(device_handle == INVALID_HANDLE_VALUE) {
logger(LOG_ERR, "Could not open Windows tap device %s (%s) for writing: %s", device, iface, winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open Windows tap device %s (%s) for writing: %s", device, iface, winerror(GetLastError()));
return false; return false;
} }
@ -151,7 +151,7 @@ static bool setup_device(void) {
/* Get MAC address from tap device */ /* Get MAC address from tap device */
if(!DeviceIoControl(device_handle, TAP_IOCTL_GET_MAC, mymac.x, sizeof mymac.x, mymac.x, sizeof mymac.x, &len, 0)) { if(!DeviceIoControl(device_handle, TAP_IOCTL_GET_MAC, mymac.x, sizeof mymac.x, mymac.x, sizeof mymac.x, &len, 0)) {
logger(LOG_ERR, "Could not get MAC address from Windows tap device %s (%s): %s", device, iface, winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Could not get MAC address from Windows tap device %s (%s): %s", device, iface, winerror(GetLastError()));
return false; return false;
} }
@ -164,7 +164,7 @@ static bool setup_device(void) {
reader_pid = fork(); reader_pid = fork();
if(reader_pid == -1) { if(reader_pid == -1) {
logger(LOG_DEBUG, "System call `%s' failed: %s", "fork", strerror(errno)); logger(DEBUG_ALWAYS, LOG_DEBUG, "System call `%s' failed: %s", "fork", strerror(errno));
return false; return false;
} }
@ -180,13 +180,13 @@ static bool setup_device(void) {
device_handle = CreateFile(tapname, GENERIC_READ, FILE_SHARE_WRITE, 0, OPEN_EXISTING, FILE_ATTRIBUTE_SYSTEM, 0); device_handle = CreateFile(tapname, GENERIC_READ, FILE_SHARE_WRITE, 0, OPEN_EXISTING, FILE_ATTRIBUTE_SYSTEM, 0);
if(device_handle == INVALID_HANDLE_VALUE) { if(device_handle == INVALID_HANDLE_VALUE) {
logger(LOG_ERR, "Could not open Windows tap device %s (%s) for reading: %s", device, iface, winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open Windows tap device %s (%s) for reading: %s", device, iface, winerror(GetLastError()));
buf[0] = 0; buf[0] = 0;
write(sp[1], buf, 1); write(sp[1], buf, 1);
exit(1); exit(1);
} }
logger(LOG_DEBUG, "Tap reader forked and running."); logger(DEBUG_ALWAYS, LOG_DEBUG, "Tap reader forked and running.");
/* Notify success */ /* Notify success */
@ -203,13 +203,13 @@ static bool setup_device(void) {
read(device_fd, &gelukt, 1); read(device_fd, &gelukt, 1);
if(gelukt != 1) { if(gelukt != 1) {
logger(LOG_DEBUG, "Tap reader failed!"); logger(DEBUG_ALWAYS, LOG_DEBUG, "Tap reader failed!");
return false; return false;
} }
device_info = "Windows tap device"; device_info = "Windows tap device";
logger(LOG_INFO, "%s (%s) is a %s", device, iface, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s (%s) is a %s", device, iface, device_info);
return true; return true;
} }
@ -229,7 +229,7 @@ static bool read_packet(vpn_packet_t *packet) {
int inlen; int inlen;
if((inlen = read(sp[0], packet->data, MTU)) <= 0) { if((inlen = read(sp[0], packet->data, MTU)) <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -238,7 +238,7 @@ static bool read_packet(vpn_packet_t *packet) {
device_total_in += packet->len; device_total_in += packet->len;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Read packet of %d bytes from %s", packet->len, logger(DEBUG_TRAFFIC, LOG_DEBUG, "Read packet of %d bytes from %s", packet->len,
device_info); device_info);
return true; return true;
@ -247,11 +247,11 @@ static bool read_packet(vpn_packet_t *packet) {
static bool write_packet(vpn_packet_t *packet) { static bool write_packet(vpn_packet_t *packet) {
long outlen; long outlen;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Writing packet of %d bytes to %s", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Writing packet of %d bytes to %s",
packet->len, device_info); packet->len, device_info);
if(!WriteFile (device_handle, packet->data, packet->len, &outlen, NULL)) { if(!WriteFile (device_handle, packet->data, packet->len, &outlen, NULL)) {
logger(LOG_ERR, "Error while writing to %s %s: %s", device_info, device, winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Error while writing to %s %s: %s", device_info, device, winerror(GetLastError()));
return false; return false;
} }
@ -261,9 +261,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out);
} }
const devops_t os_devops = { const devops_t os_devops = {

8
src/dummy_device.c
View file

@ -31,7 +31,7 @@ static uint64_t device_total_out = 0;
static bool setup_device(void) { static bool setup_device(void) {
device = "dummy"; device = "dummy";
iface = "dummy"; iface = "dummy";
logger(LOG_INFO, "%s (%s) is a %s", device, iface, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s (%s) is a %s", device, iface, device_info);
return true; return true;
} }
@ -48,9 +48,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out);
} }
const devops_t dummy_devops = { const devops_t dummy_devops = {

20
src/gcrypt/cipher.c
View file

@ -97,12 +97,12 @@ static bool cipher_open(cipher_t *cipher, int algo, int mode) {
gcry_error_t err; gcry_error_t err;
if(!ciphertonid(algo, mode, &cipher->nid)) { if(!ciphertonid(algo, mode, &cipher->nid)) {
logger(LOG_DEBUG, "Cipher %d mode %d has no corresponding nid!", algo, mode); logger(DEBUG_ALWAYS, LOG_DEBUG, "Cipher %d mode %d has no corresponding nid!", algo, mode);
return false; return false;
} }
if((err = gcry_cipher_open(&cipher->handle, algo, mode, 0))) { if((err = gcry_cipher_open(&cipher->handle, algo, mode, 0))) {
logger(LOG_DEBUG, "Unable to intialise cipher %d mode %d: %s", algo, mode, gcry_strerror(err)); logger(DEBUG_ALWAYS, LOG_DEBUG, "Unable to intialise cipher %d mode %d: %s", algo, mode, gcry_strerror(err));
return false; return false;
} }
@ -118,7 +118,7 @@ bool cipher_open_by_name(cipher_t *cipher, const char *name) {
int algo, mode; int algo, mode;
if(!nametocipher(name, &algo, &mode)) { if(!nametocipher(name, &algo, &mode)) {
logger(LOG_DEBUG, "Unknown cipher name '%s'!", name); logger(DEBUG_ALWAYS, LOG_DEBUG, "Unknown cipher name '%s'!", name);
return false; return false;
} }
@ -129,7 +129,7 @@ bool cipher_open_by_nid(cipher_t *cipher, int nid) {
int algo, mode; int algo, mode;
if(!nidtocipher(nid, &algo, &mode)) { if(!nidtocipher(nid, &algo, &mode)) {
logger(LOG_DEBUG, "Unknown cipher ID %d!", nid); logger(DEBUG_ALWAYS, LOG_DEBUG, "Unknown cipher ID %d!", nid);
return false; return false;
} }
@ -199,7 +199,7 @@ bool cipher_encrypt(cipher_t *cipher, const void *indata, size_t inlen, void *ou
size_t reqlen = ((inlen + cipher->blklen) / cipher->blklen) * cipher->blklen; size_t reqlen = ((inlen + cipher->blklen) / cipher->blklen) * cipher->blklen;
if(*outlen < reqlen) { if(*outlen < reqlen) {
logger(LOG_ERR, "Error while encrypting: not enough room for padding"); logger(DEBUG_ALWAYS, LOG_ERR, "Error while encrypting: not enough room for padding");
return false; return false;
} }
@ -217,13 +217,13 @@ bool cipher_encrypt(cipher_t *cipher, const void *indata, size_t inlen, void *ou
gcry_cipher_setiv(cipher->handle, cipher->key + cipher->keylen, cipher->blklen); gcry_cipher_setiv(cipher->handle, cipher->key + cipher->keylen, cipher->blklen);
if((err = gcry_cipher_encrypt(cipher->handle, outdata, *outlen, indata, inlen))) { if((err = gcry_cipher_encrypt(cipher->handle, outdata, *outlen, indata, inlen))) {
logger(LOG_ERR, "Error while encrypting: %s", gcry_strerror(err)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while encrypting: %s", gcry_strerror(err));
return false; return false;
} }
if(cipher->padding) { if(cipher->padding) {
if((err = gcry_cipher_encrypt(cipher->handle, outdata + inlen, cipher->blklen, pad, cipher->blklen))) { if((err = gcry_cipher_encrypt(cipher->handle, outdata + inlen, cipher->blklen, pad, cipher->blklen))) {
logger(LOG_ERR, "Error while encrypting: %s", gcry_strerror(err)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while encrypting: %s", gcry_strerror(err));
return false; return false;
} }
@ -241,7 +241,7 @@ bool cipher_decrypt(cipher_t *cipher, const void *indata, size_t inlen, void *ou
gcry_cipher_setiv(cipher->handle, cipher->key + cipher->keylen, cipher->blklen); gcry_cipher_setiv(cipher->handle, cipher->key + cipher->keylen, cipher->blklen);
if((err = gcry_cipher_decrypt(cipher->handle, outdata, *outlen, indata, inlen))) { if((err = gcry_cipher_decrypt(cipher->handle, outdata, *outlen, indata, inlen))) {
logger(LOG_ERR, "Error while decrypting: %s", gcry_strerror(err)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while decrypting: %s", gcry_strerror(err));
return false; return false;
} }
@ -252,7 +252,7 @@ bool cipher_decrypt(cipher_t *cipher, const void *indata, size_t inlen, void *ou
uint8_t padbyte = ((uint8_t *)outdata)[inlen - 1]; uint8_t padbyte = ((uint8_t *)outdata)[inlen - 1];
if(padbyte == 0 || padbyte > cipher->blklen || padbyte > inlen) { if(padbyte == 0 || padbyte > cipher->blklen || padbyte > inlen) {
logger(LOG_ERR, "Error while decrypting: invalid padding"); logger(DEBUG_ALWAYS, LOG_ERR, "Error while decrypting: invalid padding");
return false; return false;
} }
@ -260,7 +260,7 @@ bool cipher_decrypt(cipher_t *cipher, const void *indata, size_t inlen, void *ou
for(int i = inlen - 1; i >= origlen; i--) for(int i = inlen - 1; i >= origlen; i--)
if(((uint8_t *)outdata)[i] != padbyte) { if(((uint8_t *)outdata)[i] != padbyte) {
logger(LOG_ERR, "Error while decrypting: invalid padding"); logger(DEBUG_ALWAYS, LOG_ERR, "Error while decrypting: invalid padding");
return false; return false;
} }

6
src/gcrypt/digest.c
View file

@ -75,7 +75,7 @@ static bool digesttonid(int algo, int *nid) {
static bool digest_open(digest_t *digest, int algo, int maclength) { static bool digest_open(digest_t *digest, int algo, int maclength) {
if(!digesttonid(algo, &digest->nid)) { if(!digesttonid(algo, &digest->nid)) {
logger(LOG_DEBUG, "Digest %d has no corresponding nid!", algo); logger(DEBUG_ALWAYS, LOG_DEBUG, "Digest %d has no corresponding nid!", algo);
return false; return false;
} }
@ -96,7 +96,7 @@ bool digest_open_by_name(digest_t *digest, const char *name, int maclength) {
int algo; int algo;
if(!nametodigest(name, &algo)) { if(!nametodigest(name, &algo)) {
logger(LOG_DEBUG, "Unknown digest name '%s'!", name); logger(DEBUG_ALWAYS, LOG_DEBUG, "Unknown digest name '%s'!", name);
return false; return false;
} }
@ -107,7 +107,7 @@ bool digest_open_by_nid(digest_t *digest, int nid, int maclength) {
int algo; int algo;
if(!nidtodigest(nid, &algo)) { if(!nidtodigest(nid, &algo)) {
logger(LOG_DEBUG, "Unknown digest ID %d!", nid); logger(DEBUG_ALWAYS, LOG_DEBUG, "Unknown digest ID %d!", nid);
return false; return false;
} }

14
src/gcrypt/rsa.c
View file

@ -187,7 +187,7 @@ bool rsa_set_hex_public_key(rsa_t *rsa, char *n, char *e) {
?: gcry_mpi_scan(&rsa->e, GCRYMPI_FMT_HEX, e, 0, NULL); ?: gcry_mpi_scan(&rsa->e, GCRYMPI_FMT_HEX, e, 0, NULL);
if(err) { if(err) {
logger(LOG_ERR, "Error while reading RSA public key: %s", gcry_strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading RSA public key: %s", gcry_strerror(errno));
return false; return false;
} }
@ -202,7 +202,7 @@ bool rsa_set_hex_private_key(rsa_t *rsa, char *n, char *e, char *d) {
?: gcry_mpi_scan(&rsa->d, GCRYMPI_FMT_HEX, d, 0, NULL); ?: gcry_mpi_scan(&rsa->d, GCRYMPI_FMT_HEX, d, 0, NULL);
if(err) { if(err) {
logger(LOG_ERR, "Error while reading RSA public key: %s", gcry_strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading RSA public key: %s", gcry_strerror(errno));
return false; return false;
} }
@ -216,7 +216,7 @@ bool rsa_read_pem_public_key(rsa_t *rsa, FILE *fp) {
size_t derlen; size_t derlen;
if(!pem_decode(fp, "RSA PUBLIC KEY", derbuf, sizeof derbuf, &derlen)) { if(!pem_decode(fp, "RSA PUBLIC KEY", derbuf, sizeof derbuf, &derlen)) {
logger(LOG_ERR, "Unable to read RSA public key: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to read RSA public key: %s", strerror(errno));
return NULL; return NULL;
} }
@ -224,7 +224,7 @@ bool rsa_read_pem_public_key(rsa_t *rsa, FILE *fp) {
|| !ber_read_mpi(&derp, &derlen, &rsa->n) || !ber_read_mpi(&derp, &derlen, &rsa->n)
|| !ber_read_mpi(&derp, &derlen, &rsa->e) || !ber_read_mpi(&derp, &derlen, &rsa->e)
|| derlen) { || derlen) {
logger(LOG_ERR, "Error while decoding RSA public key"); logger(DEBUG_ALWAYS, LOG_ERR, "Error while decoding RSA public key");
return NULL; return NULL;
} }
@ -236,7 +236,7 @@ bool rsa_read_pem_private_key(rsa_t *rsa, FILE *fp) {
size_t derlen; size_t derlen;
if(!pem_decode(fp, "RSA PRIVATE KEY", derbuf, sizeof derbuf, &derlen)) { if(!pem_decode(fp, "RSA PRIVATE KEY", derbuf, sizeof derbuf, &derlen)) {
logger(LOG_ERR, "Unable to read RSA private key: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to read RSA private key: %s", strerror(errno));
return NULL; return NULL;
} }
@ -251,7 +251,7 @@ bool rsa_read_pem_private_key(rsa_t *rsa, FILE *fp) {
|| !ber_read_mpi(&derp, &derlen, NULL) || !ber_read_mpi(&derp, &derlen, NULL)
|| !ber_read_mpi(&derp, &derlen, NULL) // u || !ber_read_mpi(&derp, &derlen, NULL) // u
|| derlen) { || derlen) {
logger(LOG_ERR, "Error while decoding RSA private key"); logger(DEBUG_ALWAYS, LOG_ERR, "Error while decoding RSA private key");
return NULL; return NULL;
} }
@ -267,7 +267,7 @@ size_t rsa_size(rsa_t *rsa) {
*/ */
// TODO: get rid of this macro, properly clean up gcry_ structures after use // TODO: get rid of this macro, properly clean up gcry_ structures after use
#define check(foo) { gcry_error_t err = (foo); if(err) {logger(LOG_ERR, "gcrypt error %s/%s at %s:%d", gcry_strsource(err), gcry_strerror(err), __FILE__, __LINE__); return false; }} #define check(foo) { gcry_error_t err = (foo); if(err) {logger(DEBUG_ALWAYS, LOG_ERR, "gcrypt error %s/%s at %s:%d", gcry_strsource(err), gcry_strerror(err), __FILE__, __LINE__); return false; }}
bool rsa_public_encrypt(rsa_t *rsa, void *in, size_t len, void *out) { bool rsa_public_encrypt(rsa_t *rsa, void *in, size_t len, void *out) {
gcry_mpi_t inmpi; gcry_mpi_t inmpi;

8
src/gcrypt/rsagen.c
View file

@ -164,12 +164,12 @@ bool rsa_write_pem_public_key(rsa_t *rsa, FILE *fp) {
if(!ber_write_mpi(&derp1, &derlen1, &rsa->n) if(!ber_write_mpi(&derp1, &derlen1, &rsa->n)
|| !ber_write_mpi(&derp1, &derlen1, &rsa->e) || !ber_write_mpi(&derp1, &derlen1, &rsa->e)
|| !ber_write_sequence(&derp2, &derlen2, derbuf1, derlen1)) { || !ber_write_sequence(&derp2, &derlen2, derbuf1, derlen1)) {
logger(LOG_ERR, "Error while encoding RSA public key"); logger(DEBUG_ALWAYS, LOG_ERR, "Error while encoding RSA public key");
return false; return false;
} }
if(!pem_encode(fp, "RSA PUBLIC KEY", derbuf2, derlen2)) { if(!pem_encode(fp, "RSA PUBLIC KEY", derbuf2, derlen2)) {
logger(LOG_ERR, "Unable to write RSA public key: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to write RSA public key: %s", strerror(errno));
return false; return false;
} }
@ -193,12 +193,12 @@ bool rsa_write_pem_private_key(rsa_t *rsa, FILE *fp) {
|| ber_write_mpi(&derp1, &derlen1, &exp1) || ber_write_mpi(&derp1, &derlen1, &exp1)
|| ber_write_mpi(&derp1, &derlen1, &exp2) || ber_write_mpi(&derp1, &derlen1, &exp2)
|| ber_write_mpi(&derp1, &derlen1, &coeff)) || ber_write_mpi(&derp1, &derlen1, &coeff))
logger(LOG_ERR, "Error while encoding RSA private key"); logger(DEBUG_ALWAYS, LOG_ERR, "Error while encoding RSA private key");
return false; return false;
} }
if(!pem_encode(fp, "RSA PRIVATE KEY", derbuf2, derlen2)) { if(!pem_encode(fp, "RSA PRIVATE KEY", derbuf2, derlen2)) {
logger(LOG_ERR, "Unable to write RSA private key: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to write RSA private key: %s", strerror(errno));
return false; return false;
} }

12
src/graph.c
View file

@ -78,7 +78,7 @@ static void mst_kruskal(void) {
c->status.mst = false; c->status.mst = false;
} }
ifdebug(SCARY_THINGS) logger(LOG_DEBUG, "Running Kruskal's algorithm:"); logger(DEBUG_SCARY_THINGS, LOG_DEBUG, "Running Kruskal's algorithm:");
/* Clear visited status on nodes */ /* Clear visited status on nodes */
@ -105,7 +105,7 @@ static void mst_kruskal(void) {
if(e->reverse->connection) if(e->reverse->connection)
e->reverse->connection->status.mst = true; e->reverse->connection->status.mst = true;
ifdebug(SCARY_THINGS) logger(LOG_DEBUG, " Adding edge %s - %s weight %d", e->from->name, logger(DEBUG_SCARY_THINGS, LOG_DEBUG, " Adding edge %s - %s weight %d", e->from->name,
e->to->name, e->weight); e->to->name, e->weight);
} }
} }
@ -124,7 +124,7 @@ static void sssp_dijkstra(void) {
todo_list = list_alloc(NULL); todo_list = list_alloc(NULL);
ifdebug(SCARY_THINGS) logger(LOG_DEBUG, "Running Dijkstra's algorithm:"); logger(DEBUG_SCARY_THINGS, LOG_DEBUG, "Running Dijkstra's algorithm:");
/* Clear visited status on nodes */ /* Clear visited status on nodes */
@ -204,7 +204,7 @@ static void sssp_dijkstra(void) {
if(e->to->address.sa.sa_family == AF_UNSPEC && e->address.sa.sa_family != AF_UNKNOWN) if(e->to->address.sa.sa_family == AF_UNSPEC && e->address.sa.sa_family != AF_UNKNOWN)
update_node_udp(e->to, &e->address); update_node_udp(e->to, &e->address);
ifdebug(SCARY_THINGS) logger(LOG_DEBUG, " Updating edge %s - %s weight %d distance %d", e->from->name, logger(DEBUG_SCARY_THINGS, LOG_DEBUG, " Updating edge %s - %s weight %d distance %d", e->from->name,
e->to->name, e->weight, e->to->distance); e->to->name, e->weight, e->to->distance);
} }
} }
@ -315,10 +315,10 @@ static void check_reachability(void) {
n->status.reachable = !n->status.reachable; n->status.reachable = !n->status.reachable;
if(n->status.reachable) { if(n->status.reachable) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Node %s (%s) became reachable", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Node %s (%s) became reachable",
n->name, n->hostname); n->name, n->hostname);
} else { } else {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Node %s (%s) became unreachable", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Node %s (%s) became unreachable",
n->name, n->hostname); n->name, n->hostname);
} }

26
src/linux/device.c
View file

@ -64,7 +64,7 @@ static bool setup_device(void) {
device_fd = open(device, O_RDWR | O_NONBLOCK); device_fd = open(device, O_RDWR | O_NONBLOCK);
if(device_fd < 0) { if(device_fd < 0) {
logger(LOG_ERR, "Could not open %s: %s", device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open %s: %s", device, strerror(errno));
return false; return false;
} }
@ -77,7 +77,7 @@ static bool setup_device(void) {
get_config_string(lookup_config(config_tree, "DeviceType"), &type); get_config_string(lookup_config(config_tree, "DeviceType"), &type);
if(type && strcasecmp(type, "tun") && strcasecmp(type, "tap")) { if(type && strcasecmp(type, "tun") && strcasecmp(type, "tap")) {
logger(LOG_ERR, "Unknown device type %s!", type); logger(DEBUG_ALWAYS, LOG_ERR, "Unknown device type %s!", type);
return false; return false;
} }
@ -107,13 +107,13 @@ static bool setup_device(void) {
if(iface) free(iface); if(iface) free(iface);
iface = xstrdup(ifrname); iface = xstrdup(ifrname);
} else if(!ioctl(device_fd, (('T' << 8) | 202), &ifr)) { } else if(!ioctl(device_fd, (('T' << 8) | 202), &ifr)) {
logger(LOG_WARNING, "Old ioctl() request was needed for %s", device); logger(DEBUG_ALWAYS, LOG_WARNING, "Old ioctl() request was needed for %s", device);
strncpy(ifrname, ifr.ifr_name, IFNAMSIZ); strncpy(ifrname, ifr.ifr_name, IFNAMSIZ);
if(iface) free(iface); if(iface) free(iface);
iface = xstrdup(ifrname); iface = xstrdup(ifrname);
} }
logger(LOG_INFO, "%s is a %s", device, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s is a %s", device, device_info);
return true; return true;
} }
@ -134,7 +134,7 @@ static bool read_packet(vpn_packet_t *packet) {
inlen = read(device_fd, packet->data + 10, MTU - 10); inlen = read(device_fd, packet->data + 10, MTU - 10);
if(inlen <= 0) { if(inlen <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s",
device_info, device, strerror(errno)); device_info, device, strerror(errno));
return false; return false;
} }
@ -145,7 +145,7 @@ static bool read_packet(vpn_packet_t *packet) {
inlen = read(device_fd, packet->data, MTU); inlen = read(device_fd, packet->data, MTU);
if(inlen <= 0) { if(inlen <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s",
device_info, device, strerror(errno)); device_info, device, strerror(errno));
return false; return false;
} }
@ -159,28 +159,28 @@ static bool read_packet(vpn_packet_t *packet) {
device_in_packets++; device_in_packets++;
device_in_bytes += packet->len; device_in_bytes += packet->len;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Read packet of %d bytes from %s", packet->len, logger(DEBUG_TRAFFIC, LOG_DEBUG, "Read packet of %d bytes from %s", packet->len,
device_info); device_info);
return true; return true;
} }
static bool write_packet(vpn_packet_t *packet) { static bool write_packet(vpn_packet_t *packet) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Writing packet of %d bytes to %s", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Writing packet of %d bytes to %s",
packet->len, device_info); packet->len, device_info);
switch(device_type) { switch(device_type) {
case DEVICE_TYPE_TUN: case DEVICE_TYPE_TUN:
packet->data[10] = packet->data[11] = 0; packet->data[10] = packet->data[11] = 0;
if(write(device_fd, packet->data + 10, packet->len - 10) < 0) { if(write(device_fd, packet->data + 10, packet->len - 10) < 0) {
logger(LOG_ERR, "Can't write to %s %s: %s", device_info, device, logger(DEBUG_ALWAYS, LOG_ERR, "Can't write to %s %s: %s", device_info, device,
strerror(errno)); strerror(errno));
return false; return false;
} }
break; break;
case DEVICE_TYPE_TAP: case DEVICE_TYPE_TAP:
if(write(device_fd, packet->data, packet->len) < 0) { if(write(device_fd, packet->data, packet->len) < 0) {
logger(LOG_ERR, "Can't write to %s %s: %s", device_info, device, logger(DEBUG_ALWAYS, LOG_ERR, "Can't write to %s %s: %s", device_info, device,
strerror(errno)); strerror(errno));
return false; return false;
} }
@ -196,9 +196,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_in_bytes); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_in_bytes);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_out_bytes); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_out_bytes);
} }
const devops_t os_devops = { const devops_t os_devops = {

89
src/logger.c
View file

@ -21,7 +21,10 @@
#include "system.h" #include "system.h"
#include "conf.h" #include "conf.h"
#include "meta.h"
#include "logger.h" #include "logger.h"
#include "connection.h"
#include "control_common.h"
debug_t debug_level = DEBUG_NOTHING; debug_t debug_level = DEBUG_NOTHING;
static logmode_t logmode = LOGMODE_STDERR; static logmode_t logmode = LOGMODE_STDERR;
@ -32,6 +35,7 @@ static FILE *logfile = NULL;
static HANDLE loghandle = NULL; static HANDLE loghandle = NULL;
#endif #endif
static const char *logident = NULL; static const char *logident = NULL;
bool logcontrol = false;
void openlogger(const char *ident, logmode_t mode) { void openlogger(const char *ident, logmode_t mode) {
logident = ident; logident = ident;
@ -75,61 +79,76 @@ void reopenlogger() {
fflush(logfile); fflush(logfile);
FILE *newfile = fopen(logfilename, "a"); FILE *newfile = fopen(logfilename, "a");
if(!newfile) { if(!newfile) {
logger(LOG_ERR, "Unable to reopen log file %s: %s\n", logfilename, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to reopen log file %s: %s\n", logfilename, strerror(errno));
return; return;
} }
fclose(logfile); fclose(logfile);
logfile = newfile; logfile = newfile;
} }
void logger(int priority, const char *format, ...) { void logger(int level, int priority, const char *format, ...) {
va_list ap; va_list ap;
char timestr[32] = ""; char timestr[32] = "";
char message[1024] = "";
time_t now; time_t now;
static bool suppress = false;
// Bail out early if there is nothing to do.
if(suppress)
return;
if(!logcontrol && (level > debug_level || logmode == LOGMODE_NULL))
return;
va_start(ap, format); va_start(ap, format);
vsnprintf(message, sizeof message, format, ap);
va_end(ap);
switch(logmode) { if(level <= debug_level) {
case LOGMODE_STDERR: switch(logmode) {
vfprintf(stderr, format, ap); case LOGMODE_STDERR:
fprintf(stderr, "\n"); fprintf(stderr, "%s\n", message);
fflush(stderr); fflush(stderr);
break; break;
case LOGMODE_FILE: case LOGMODE_FILE:
now = time(NULL); now = time(NULL);
strftime(timestr, sizeof timestr, "%Y-%m-%d %H:%M:%S", localtime(&now)); strftime(timestr, sizeof timestr, "%Y-%m-%d %H:%M:%S", localtime(&now));
fprintf(logfile, "%s %s[%ld]: ", timestr, logident, (long)logpid); fprintf(logfile, "%s %s[%ld]: %s\n", timestr, logident, (long)logpid, message);
vfprintf(logfile, format, ap); fflush(logfile);
fprintf(logfile, "\n"); break;
fflush(logfile); case LOGMODE_SYSLOG:
break;
case LOGMODE_SYSLOG:
#ifdef HAVE_MINGW #ifdef HAVE_MINGW
{ {
char message[4096]; const char *messages[] = {message};
const char *messages[] = {message}; ReportEvent(loghandle, priority, 0, 0, NULL, 1, 0, messages, NULL);
vsnprintf(message, sizeof message, format, ap); }
ReportEvent(loghandle, priority, 0, 0, NULL, 1, 0, messages, NULL);
}
#else #else
#ifdef HAVE_SYSLOG_H #ifdef HAVE_SYSLOG_H
#ifdef HAVE_VSYSLOG
vsyslog(priority, format, ap);
#else
{
char message[4096];
vsnprintf(message, sizeof message, format, ap);
syslog(priority, "%s", message); syslog(priority, "%s", message);
}
#endif
break;
#endif #endif
#endif #endif
case LOGMODE_NULL: break;
break; case LOGMODE_NULL:
break;
}
} }
va_end(ap); if(logcontrol) {
suppress = true;
logcontrol = false;
for(splay_node_t *node = connection_tree->head; node; node = node->next) {
connection_t *c = node->data;
if(!c->status.log)
continue;
logcontrol = true;
if(level > (c->outcompression >= 0 ? c->outcompression : debug_level))
continue;
int len = strlen(message);
if(send_request(c, "%d %d %d", CONTROL, REQ_LOG, len))
send_meta(c, message, len);
}
suppress = false;
}
} }
void closelogger(void) { void closelogger(void) {

5
src/logger.h
View file

@ -46,11 +46,10 @@ enum {
#endif #endif
extern debug_t debug_level; extern debug_t debug_level;
extern bool logcontrol;
extern void openlogger(const char *, logmode_t); extern void openlogger(const char *, logmode_t);
extern void reopenlogger(void); extern void reopenlogger(void);
extern void logger(int, const char *, ...) __attribute__ ((__format__(printf, 2, 3))); extern void logger(int, int, const char *, ...) __attribute__ ((__format__(printf, 3, 4)));
extern void closelogger(void); extern void closelogger(void);
#define ifdebug(l) if(debug_level >= DEBUG_##l)
#endif /* __TINC_LOGGER_H__ */ #endif /* __TINC_LOGGER_H__ */

26
src/meta.c
View file

@ -35,11 +35,11 @@ bool send_meta_sptps(void *handle, const char *buffer, size_t length) {
connection_t *c = handle; connection_t *c = handle;
if(!c) { if(!c) {
logger(LOG_ERR, "send_meta_sptps() called with NULL pointer!"); logger(DEBUG_ALWAYS, LOG_ERR, "send_meta_sptps() called with NULL pointer!");
abort(); abort();
} }
logger(LOG_DEBUG, "send_meta_sptps(%s, %p, %zu)", c->name, buffer, length); logger(DEBUG_ALWAYS, LOG_DEBUG, "send_meta_sptps(%s, %p, %zu)", c->name, buffer, length);
buffer_add(&c->outbuf, buffer, length); buffer_add(&c->outbuf, buffer, length);
event_add(&c->outevent, NULL); event_add(&c->outevent, NULL);
@ -49,11 +49,11 @@ bool send_meta_sptps(void *handle, const char *buffer, size_t length) {
bool send_meta(connection_t *c, const char *buffer, int length) { bool send_meta(connection_t *c, const char *buffer, int length) {
if(!c) { if(!c) {
logger(LOG_ERR, "send_meta() called with NULL pointer!"); logger(DEBUG_ALWAYS, LOG_ERR, "send_meta() called with NULL pointer!");
abort(); abort();
} }
ifdebug(META) logger(LOG_DEBUG, "Sending %d bytes of metadata to %s (%s)", length, logger(DEBUG_META, LOG_DEBUG, "Sending %d bytes of metadata to %s (%s)", length,
c->name, c->hostname); c->name, c->hostname);
if(c->protocol_minor >= 2) if(c->protocol_minor >= 2)
@ -64,7 +64,7 @@ bool send_meta(connection_t *c, const char *buffer, int length) {
size_t outlen = length; size_t outlen = length;
if(!cipher_encrypt(&c->outcipher, buffer, length, buffer_prepare(&c->outbuf, length), &outlen, false) || outlen != length) { if(!cipher_encrypt(&c->outcipher, buffer, length, buffer_prepare(&c->outbuf, length), &outlen, false) || outlen != length) {
logger(LOG_ERR, "Error while encrypting metadata to %s (%s)", logger(DEBUG_ALWAYS, LOG_ERR, "Error while encrypting metadata to %s (%s)",
c->name, c->hostname); c->name, c->hostname);
return false; return false;
} }
@ -94,11 +94,11 @@ bool receive_meta_sptps(void *handle, uint8_t type, const char *data, uint16_t l
connection_t *c = handle; connection_t *c = handle;
if(!c) { if(!c) {
logger(LOG_ERR, "receive_meta_sptps() called with NULL pointer!"); logger(DEBUG_ALWAYS, LOG_ERR, "receive_meta_sptps() called with NULL pointer!");
abort(); abort();
} }
logger(LOG_DEBUG, "receive_meta_sptps(%s, %d, %p, %hu)", c->name, type, data, length); logger(DEBUG_ALWAYS, LOG_DEBUG, "receive_meta_sptps(%s, %d, %p, %hu)", c->name, type, data, length);
if(type == SPTPS_HANDSHAKE) { if(type == SPTPS_HANDSHAKE) {
if(c->allow_request == ACK) if(c->allow_request == ACK)
@ -142,7 +142,7 @@ bool receive_meta(connection_t *c) {
buffer_compact(&c->inbuf, MAXBUFSIZE); buffer_compact(&c->inbuf, MAXBUFSIZE);
if(sizeof inbuf <= c->inbuf.len) { if(sizeof inbuf <= c->inbuf.len) {
logger(LOG_ERR, "Input buffer full for %s (%s)", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Input buffer full for %s (%s)", c->name, c->hostname);
return false; return false;
} }
@ -150,19 +150,19 @@ bool receive_meta(connection_t *c) {
if(inlen <= 0) { if(inlen <= 0) {
if(!inlen || !errno) { if(!inlen || !errno) {
ifdebug(CONNECTIONS) logger(LOG_NOTICE, "Connection closed by %s (%s)", logger(DEBUG_CONNECTIONS, LOG_NOTICE, "Connection closed by %s (%s)",
c->name, c->hostname); c->name, c->hostname);
} else if(sockwouldblock(sockerrno)) } else if(sockwouldblock(sockerrno))
return true; return true;
else else
logger(LOG_ERR, "Metadata socket read error for %s (%s): %s", logger(DEBUG_ALWAYS, LOG_ERR, "Metadata socket read error for %s (%s): %s",
c->name, c->hostname, sockstrerror(sockerrno)); c->name, c->hostname, sockstrerror(sockerrno));
return false; return false;
} }
do { do {
if(c->protocol_minor >= 2) { if(c->protocol_minor >= 2) {
logger(LOG_DEBUG, "Receiving %d bytes of SPTPS data", inlen); logger(DEBUG_ALWAYS, LOG_DEBUG, "Receiving %d bytes of SPTPS data", inlen);
return sptps_receive_data(&c->sptps, bufp, inlen); return sptps_receive_data(&c->sptps, bufp, inlen);
} }
@ -179,10 +179,10 @@ bool receive_meta(connection_t *c) {
bufp = endp; bufp = endp;
} else { } else {
size_t outlen = inlen; size_t outlen = inlen;
ifdebug(META) logger(LOG_DEBUG, "Received encrypted %d bytes", inlen); logger(DEBUG_META, LOG_DEBUG, "Received encrypted %d bytes", inlen);
if(!cipher_decrypt(&c->incipher, bufp, inlen, buffer_prepare(&c->inbuf, inlen), &outlen, false) || inlen != outlen) { if(!cipher_decrypt(&c->incipher, bufp, inlen, buffer_prepare(&c->inbuf, inlen), &outlen, false) || inlen != outlen) {
logger(LOG_ERR, "Error while decrypting metadata from %s (%s)", logger(DEBUG_ALWAYS, LOG_ERR, "Error while decrypting metadata from %s (%s)",
c->name, c->hostname); c->name, c->hostname);
return false; return false;
} }

26
src/mingw/device.c
View file

@ -50,7 +50,7 @@ static DWORD WINAPI tapreader(void *bla) {
OVERLAPPED overlapped; OVERLAPPED overlapped;
vpn_packet_t packet; vpn_packet_t packet;
logger(LOG_DEBUG, "Tap reader running"); logger(DEBUG_ALWAYS, LOG_DEBUG, "Tap reader running");
/* Read from tap device and send to parent */ /* Read from tap device and send to parent */
@ -69,7 +69,7 @@ static DWORD WINAPI tapreader(void *bla) {
if(!GetOverlappedResult(device_handle, &overlapped, &len, FALSE)) if(!GetOverlappedResult(device_handle, &overlapped, &len, FALSE))
continue; continue;
} else { } else {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return -1; return -1;
} }
@ -105,7 +105,7 @@ static bool setup_device(void) {
/* Open registry and look for network adapters */ /* Open registry and look for network adapters */
if(RegOpenKeyEx(HKEY_LOCAL_MACHINE, NETWORK_CONNECTIONS_KEY, 0, KEY_READ, &key)) { if(RegOpenKeyEx(HKEY_LOCAL_MACHINE, NETWORK_CONNECTIONS_KEY, 0, KEY_READ, &key)) {
logger(LOG_ERR, "Unable to read registry: %s", winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to read registry: %s", winerror(GetLastError()));
return false; return false;
} }
@ -156,7 +156,7 @@ static bool setup_device(void) {
RegCloseKey(key); RegCloseKey(key);
if(!found) { if(!found) {
logger(LOG_ERR, "No Windows tap device found!"); logger(DEBUG_ALWAYS, LOG_ERR, "No Windows tap device found!");
return false; return false;
} }
@ -174,14 +174,14 @@ static bool setup_device(void) {
} }
if(device_handle == INVALID_HANDLE_VALUE) { if(device_handle == INVALID_HANDLE_VALUE) {
logger(LOG_ERR, "%s (%s) is not a usable Windows tap device: %s", device, iface, winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "%s (%s) is not a usable Windows tap device: %s", device, iface, winerror(GetLastError()));
return false; return false;
} }
/* Get MAC address from tap device */ /* Get MAC address from tap device */
if(!DeviceIoControl(device_handle, TAP_IOCTL_GET_MAC, mymac.x, sizeof mymac.x, mymac.x, sizeof mymac.x, &len, 0)) { if(!DeviceIoControl(device_handle, TAP_IOCTL_GET_MAC, mymac.x, sizeof mymac.x, mymac.x, sizeof mymac.x, &len, 0)) {
logger(LOG_ERR, "Could not get MAC address from Windows tap device %s (%s): %s", device, iface, winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Could not get MAC address from Windows tap device %s (%s): %s", device, iface, winerror(GetLastError()));
return false; return false;
} }
@ -194,7 +194,7 @@ static bool setup_device(void) {
thread = CreateThread(NULL, 0, tapreader, NULL, 0, NULL); thread = CreateThread(NULL, 0, tapreader, NULL, 0, NULL);
if(!thread) { if(!thread) {
logger(LOG_ERR, "System call `%s' failed: %s", "CreateThread", winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "CreateThread", winerror(GetLastError()));
return false; return false;
} }
@ -205,7 +205,7 @@ static bool setup_device(void) {
device_info = "Windows tap device"; device_info = "Windows tap device";
logger(LOG_INFO, "%s (%s) is a %s", device, iface, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s (%s) is a %s", device, iface, device_info);
return true; return true;
} }
@ -225,11 +225,11 @@ static bool write_packet(vpn_packet_t *packet) {
long outlen; long outlen;
OVERLAPPED overlapped = {0}; OVERLAPPED overlapped = {0};
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Writing packet of %d bytes to %s", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Writing packet of %d bytes to %s",
packet->len, device_info); packet->len, device_info);
if(!WriteFile(device_handle, packet->data, packet->len, &outlen, &overlapped)) { if(!WriteFile(device_handle, packet->data, packet->len, &outlen, &overlapped)) {
logger(LOG_ERR, "Error while writing to %s %s: %s", device_info, device, winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Error while writing to %s %s: %s", device_info, device, winerror(GetLastError()));
return false; return false;
} }
@ -239,9 +239,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out);
} }
const devops_t os_devops = { const devops_t os_devops = {

28
src/net.c
View file

@ -49,7 +49,7 @@ void purge(void) {
edge_t *e; edge_t *e;
subnet_t *s; subnet_t *s;
ifdebug(PROTOCOL) logger(LOG_DEBUG, "Purging unreachable nodes"); logger(DEBUG_PROTOCOL, LOG_DEBUG, "Purging unreachable nodes");
/* Remove all edges and subnets owned by unreachable nodes. */ /* Remove all edges and subnets owned by unreachable nodes. */
@ -58,8 +58,7 @@ void purge(void) {
n = nnode->data; n = nnode->data;
if(!n->status.reachable) { if(!n->status.reachable) {
ifdebug(SCARY_THINGS) logger(LOG_DEBUG, "Purging node %s (%s)", n->name, logger(DEBUG_SCARY_THINGS, LOG_DEBUG, "Purging node %s (%s)", n->name, n->hostname);
n->hostname);
for(snode = n->subnet_tree->head; snode; snode = snext) { for(snode = n->subnet_tree->head; snode; snode = snext) {
snext = snode->next; snext = snode->next;
@ -109,7 +108,7 @@ void purge(void) {
- Deactivate the host - Deactivate the host
*/ */
void terminate_connection(connection_t *c, bool report) { void terminate_connection(connection_t *c, bool report) {
ifdebug(CONNECTIONS) logger(LOG_NOTICE, "Closing connection with %s (%s)", logger(DEBUG_CONNECTIONS, LOG_NOTICE, "Closing connection with %s (%s)",
c->name, c->hostname); c->name, c->hostname);
c->status.active = false; c->status.active = false;
@ -171,7 +170,7 @@ static void timeout_handler(int fd, short events, void *event) {
if(c->last_ping_time + pingtimeout <= now) { if(c->last_ping_time + pingtimeout <= now) {
if(c->status.active) { if(c->status.active) {
if(c->status.pinged) { if(c->status.pinged) {
ifdebug(CONNECTIONS) logger(LOG_INFO, "%s (%s) didn't respond to PING in %ld seconds", logger(DEBUG_CONNECTIONS, LOG_INFO, "%s (%s) didn't respond to PING in %ld seconds",
c->name, c->hostname, now - c->last_ping_time); c->name, c->hostname, now - c->last_ping_time);
terminate_connection(c, true); terminate_connection(c, true);
continue; continue;
@ -180,13 +179,12 @@ static void timeout_handler(int fd, short events, void *event) {
} }
} else { } else {
if(c->status.connecting) { if(c->status.connecting) {
ifdebug(CONNECTIONS) logger(DEBUG_CONNECTIONS, LOG_WARNING, "Timeout while connecting to %s (%s)", c->name, c->hostname);
logger(LOG_WARNING, "Timeout while connecting to %s (%s)", c->name, c->hostname);
c->status.connecting = false; c->status.connecting = false;
closesocket(c->socket); closesocket(c->socket);
do_outgoing_connection(c); do_outgoing_connection(c);
} else { } else {
ifdebug(CONNECTIONS) logger(LOG_WARNING, "Timeout from %s (%s) during authentication", c->name, c->hostname); logger(DEBUG_CONNECTIONS, LOG_WARNING, "Timeout from %s (%s) during authentication", c->name, c->hostname);
terminate_connection(c, false); terminate_connection(c, false);
continue; continue;
} }
@ -195,7 +193,7 @@ static void timeout_handler(int fd, short events, void *event) {
} }
if(contradicting_del_edge > 100 && contradicting_add_edge > 100) { if(contradicting_del_edge > 100 && contradicting_add_edge > 100) {
logger(LOG_WARNING, "Possible node with same Name as us! Sleeping %d seconds.", sleeptime); logger(DEBUG_ALWAYS, LOG_WARNING, "Possible node with same Name as us! Sleeping %d seconds.", sleeptime);
usleep(sleeptime * 1000000LL); usleep(sleeptime * 1000000LL);
sleeptime *= 2; sleeptime *= 2;
if(sleeptime < 0) if(sleeptime < 0)
@ -225,7 +223,7 @@ void handle_meta_connection_data(int fd, short events, void *data) {
if(!result) if(!result)
finish_connecting(c); finish_connecting(c);
else { else {
ifdebug(CONNECTIONS) logger(LOG_DEBUG, logger(DEBUG_CONNECTIONS, LOG_DEBUG,
"Error while connecting to %s (%s): %s", "Error while connecting to %s (%s): %s",
c->name, c->hostname, sockstrerror(result)); c->name, c->hostname, sockstrerror(result));
closesocket(c->socket); closesocket(c->socket);
@ -241,18 +239,18 @@ void handle_meta_connection_data(int fd, short events, void *data) {
} }
static void sigterm_handler(int signal, short events, void *data) { static void sigterm_handler(int signal, short events, void *data) {
logger(LOG_NOTICE, "Got %s signal", strsignal(signal)); logger(DEBUG_ALWAYS, LOG_NOTICE, "Got %s signal", strsignal(signal));
event_loopexit(NULL); event_loopexit(NULL);
} }
static void sighup_handler(int signal, short events, void *data) { static void sighup_handler(int signal, short events, void *data) {
logger(LOG_NOTICE, "Got %s signal", strsignal(signal)); logger(DEBUG_ALWAYS, LOG_NOTICE, "Got %s signal", strsignal(signal));
reopenlogger(); reopenlogger();
reload_configuration(); reload_configuration();
} }
static void sigalrm_handler(int signal, short events, void *data) { static void sigalrm_handler(int signal, short events, void *data) {
logger(LOG_NOTICE, "Got %s signal", strsignal(signal)); logger(DEBUG_ALWAYS, LOG_NOTICE, "Got %s signal", strsignal(signal));
retry(); retry();
} }
@ -269,7 +267,7 @@ int reload_configuration(void) {
init_configuration(&config_tree); init_configuration(&config_tree);
if(!read_server_config()) { if(!read_server_config()) {
logger(LOG_ERR, "Unable to reread configuration file, exitting."); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to reread configuration file, exitting.");
event_loopexit(NULL); event_loopexit(NULL);
return EINVAL; return EINVAL;
} }
@ -381,7 +379,7 @@ int main_loop(void) {
#endif #endif
if(event_loop(0) < 0) { if(event_loop(0) < 0) {
logger(LOG_ERR, "Error while waiting for input: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while waiting for input: %s", strerror(errno));
return 1; return 1;
} }

60
src/net_packet.c
View file

@ -87,7 +87,7 @@ static void send_mtu_probe_handler(int fd, short events, void *data) {
n->mtuprobes++; n->mtuprobes++;
if(!n->status.reachable || !n->status.validkey) { if(!n->status.reachable || !n->status.validkey) {
ifdebug(TRAFFIC) logger(LOG_INFO, "Trying to send MTU probe to unreachable or rekeying node %s (%s)", n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_INFO, "Trying to send MTU probe to unreachable or rekeying node %s (%s)", n->name, n->hostname);
n->mtuprobes = 0; n->mtuprobes = 0;
return; return;
} }
@ -99,14 +99,14 @@ static void send_mtu_probe_handler(int fd, short events, void *data) {
goto end; goto end;
} }
ifdebug(TRAFFIC) logger(LOG_INFO, "%s (%s) did not respond to UDP ping, restarting PMTU discovery", n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_INFO, "%s (%s) did not respond to UDP ping, restarting PMTU discovery", n->name, n->hostname);
n->mtuprobes = 1; n->mtuprobes = 1;
n->minmtu = 0; n->minmtu = 0;
n->maxmtu = MTU; n->maxmtu = MTU;
} }
if(n->mtuprobes >= 10 && n->mtuprobes < 32 && !n->minmtu) { if(n->mtuprobes >= 10 && n->mtuprobes < 32 && !n->minmtu) {
ifdebug(TRAFFIC) logger(LOG_INFO, "No response to MTU probes from %s (%s)", n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_INFO, "No response to MTU probes from %s (%s)", n->name, n->hostname);
n->mtuprobes = 31; n->mtuprobes = 31;
} }
@ -116,7 +116,7 @@ static void send_mtu_probe_handler(int fd, short events, void *data) {
else else
n->maxmtu = n->minmtu; n->maxmtu = n->minmtu;
n->mtu = n->minmtu; n->mtu = n->minmtu;
ifdebug(TRAFFIC) logger(LOG_INFO, "Fixing MTU of %s (%s) to %d after %d probes", n->name, n->hostname, n->mtu, n->mtuprobes); logger(DEBUG_TRAFFIC, LOG_INFO, "Fixing MTU of %s (%s) to %d after %d probes", n->name, n->hostname, n->mtu, n->mtuprobes);
n->mtuprobes = 31; n->mtuprobes = 31;
} }
@ -144,7 +144,7 @@ static void send_mtu_probe_handler(int fd, short events, void *data) {
else else
packet.priority = 0; packet.priority = 0;
ifdebug(TRAFFIC) logger(LOG_INFO, "Sending MTU probe length %d to %s (%s)", len, n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_INFO, "Sending MTU probe length %d to %s (%s)", len, n->name, n->hostname);
send_udppacket(n, &packet); send_udppacket(n, &packet);
} }
@ -160,7 +160,7 @@ void send_mtu_probe(node_t *n) {
} }
static void mtu_probe_h(node_t *n, vpn_packet_t *packet, length_t len) { static void mtu_probe_h(node_t *n, vpn_packet_t *packet, length_t len) {
ifdebug(TRAFFIC) logger(LOG_INFO, "Got MTU probe length %d from %s (%s)", packet->len, n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_INFO, "Got MTU probe length %d from %s (%s)", packet->len, n->name, n->hostname);
if(!packet->data[0]) { if(!packet->data[0]) {
packet->data[0] = 1; packet->data[0] = 1;
@ -242,7 +242,7 @@ static length_t uncompress_packet(uint8_t *dest, const uint8_t *source, length_t
/* VPN packet I/O */ /* VPN packet I/O */
static void receive_packet(node_t *n, vpn_packet_t *packet) { static void receive_packet(node_t *n, vpn_packet_t *packet) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Received packet of %d bytes from %s (%s)", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Received packet of %d bytes from %s (%s)",
packet->len, n->name, n->hostname); packet->len, n->name, n->hostname);
n->in_packets++; n->in_packets++;
@ -266,7 +266,7 @@ static void receive_udppacket(node_t *n, vpn_packet_t *inpkt) {
size_t outlen; size_t outlen;
if(!cipher_active(&n->incipher)) { if(!cipher_active(&n->incipher)) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Got packet from %s (%s) but he hasn't got our key yet", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Got packet from %s (%s) but he hasn't got our key yet",
n->name, n->hostname); n->name, n->hostname);
return; return;
} }
@ -274,7 +274,7 @@ static void receive_udppacket(node_t *n, vpn_packet_t *inpkt) {
/* Check packet length */ /* Check packet length */
if(inpkt->len < sizeof inpkt->seqno + digest_length(&n->indigest)) { if(inpkt->len < sizeof inpkt->seqno + digest_length(&n->indigest)) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Got too short packet from %s (%s)", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Got too short packet from %s (%s)",
n->name, n->hostname); n->name, n->hostname);
return; return;
} }
@ -284,7 +284,7 @@ static void receive_udppacket(node_t *n, vpn_packet_t *inpkt) {
if(digest_active(&n->indigest)) { if(digest_active(&n->indigest)) {
inpkt->len -= n->indigest.maclength; inpkt->len -= n->indigest.maclength;
if(!digest_verify(&n->indigest, &inpkt->seqno, inpkt->len, (const char *)&inpkt->seqno + inpkt->len)) { if(!digest_verify(&n->indigest, &inpkt->seqno, inpkt->len, (const char *)&inpkt->seqno + inpkt->len)) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Got unauthenticated packet from %s (%s)", n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_DEBUG, "Got unauthenticated packet from %s (%s)", n->name, n->hostname);
return; return;
} }
} }
@ -295,7 +295,7 @@ static void receive_udppacket(node_t *n, vpn_packet_t *inpkt) {
outlen = MAXSIZE; outlen = MAXSIZE;
if(!cipher_decrypt(&n->incipher, &inpkt->seqno, inpkt->len, &outpkt->seqno, &outlen, true)) { if(!cipher_decrypt(&n->incipher, &inpkt->seqno, inpkt->len, &outpkt->seqno, &outlen, true)) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Error decrypting packet from %s (%s)", n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_DEBUG, "Error decrypting packet from %s (%s)", n->name, n->hostname);
return; return;
} }
@ -312,16 +312,16 @@ static void receive_udppacket(node_t *n, vpn_packet_t *inpkt) {
if(inpkt->seqno != n->received_seqno + 1) { if(inpkt->seqno != n->received_seqno + 1) {
if(inpkt->seqno >= n->received_seqno + replaywin * 8) { if(inpkt->seqno >= n->received_seqno + replaywin * 8) {
if(n->farfuture++ < replaywin >> 2) { if(n->farfuture++ < replaywin >> 2) {
logger(LOG_WARNING, "Packet from %s (%s) is %d seqs in the future, dropped (%u)", logger(DEBUG_ALWAYS, LOG_WARNING, "Packet from %s (%s) is %d seqs in the future, dropped (%u)",
n->name, n->hostname, inpkt->seqno - n->received_seqno - 1, n->farfuture); n->name, n->hostname, inpkt->seqno - n->received_seqno - 1, n->farfuture);
return; return;
} }
logger(LOG_WARNING, "Lost %d packets from %s (%s)", logger(DEBUG_ALWAYS, LOG_WARNING, "Lost %d packets from %s (%s)",
inpkt->seqno - n->received_seqno - 1, n->name, n->hostname); inpkt->seqno - n->received_seqno - 1, n->name, n->hostname);
memset(n->late, 0, replaywin); memset(n->late, 0, replaywin);
} else if (inpkt->seqno <= n->received_seqno) { } else if (inpkt->seqno <= n->received_seqno) {
if((n->received_seqno >= replaywin * 8 && inpkt->seqno <= n->received_seqno - replaywin * 8) || !(n->late[(inpkt->seqno / 8) % replaywin] & (1 << inpkt->seqno % 8))) { if((n->received_seqno >= replaywin * 8 && inpkt->seqno <= n->received_seqno - replaywin * 8) || !(n->late[(inpkt->seqno / 8) % replaywin] & (1 << inpkt->seqno % 8))) {
logger(LOG_WARNING, "Got late or replayed packet from %s (%s), seqno %d, last received %d", logger(DEBUG_ALWAYS, LOG_WARNING, "Got late or replayed packet from %s (%s), seqno %d, last received %d",
n->name, n->hostname, inpkt->seqno, n->received_seqno); n->name, n->hostname, inpkt->seqno, n->received_seqno);
return; return;
} }
@ -349,7 +349,7 @@ static void receive_udppacket(node_t *n, vpn_packet_t *inpkt) {
outpkt = pkt[nextpkt++]; outpkt = pkt[nextpkt++];
if((outpkt->len = uncompress_packet(outpkt->data, inpkt->data, inpkt->len, n->incompression)) < 0) { if((outpkt->len = uncompress_packet(outpkt->data, inpkt->data, inpkt->len, n->incompression)) < 0) {
ifdebug(TRAFFIC) logger(LOG_ERR, "Error while uncompressing packet from %s (%s)", logger(DEBUG_TRAFFIC, LOG_ERR, "Error while uncompressing packet from %s (%s)",
n->name, n->hostname); n->name, n->hostname);
return; return;
} }
@ -394,7 +394,7 @@ static void send_udppacket(node_t *n, vpn_packet_t *origpkt) {
#endif #endif
if(!n->status.reachable) { if(!n->status.reachable) {
ifdebug(TRAFFIC) logger(LOG_INFO, "Trying to send UDP packet to unreachable node %s (%s)", n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_INFO, "Trying to send UDP packet to unreachable node %s (%s)", n->name, n->hostname);
return; return;
} }
@ -403,7 +403,7 @@ static void send_udppacket(node_t *n, vpn_packet_t *origpkt) {
if(!n->status.validkey) { if(!n->status.validkey) {
time_t now = time(NULL); time_t now = time(NULL);
ifdebug(TRAFFIC) logger(LOG_INFO, logger(DEBUG_TRAFFIC, LOG_INFO,
"No valid key known yet for %s (%s), forwarding via TCP", "No valid key known yet for %s (%s), forwarding via TCP",
n->name, n->hostname); n->name, n->hostname);
@ -418,7 +418,7 @@ static void send_udppacket(node_t *n, vpn_packet_t *origpkt) {
} }
if(n->options & OPTION_PMTU_DISCOVERY && inpkt->len > n->minmtu && (inpkt->data[12] | inpkt->data[13])) { if(n->options & OPTION_PMTU_DISCOVERY && inpkt->len > n->minmtu && (inpkt->data[12] | inpkt->data[13])) {
ifdebug(TRAFFIC) logger(LOG_INFO, logger(DEBUG_TRAFFIC, LOG_INFO,
"Packet for %s (%s) larger than minimum MTU, forwarding via %s", "Packet for %s (%s) larger than minimum MTU, forwarding via %s",
n->name, n->hostname, n != n->nexthop ? n->nexthop->name : "TCP"); n->name, n->hostname, n != n->nexthop ? n->nexthop->name : "TCP");
@ -436,7 +436,7 @@ static void send_udppacket(node_t *n, vpn_packet_t *origpkt) {
outpkt = pkt[nextpkt++]; outpkt = pkt[nextpkt++];
if((outpkt->len = compress_packet(outpkt->data, inpkt->data, inpkt->len, n->outcompression)) < 0) { if((outpkt->len = compress_packet(outpkt->data, inpkt->data, inpkt->len, n->outcompression)) < 0) {
ifdebug(TRAFFIC) logger(LOG_ERR, "Error while compressing packet to %s (%s)", logger(DEBUG_TRAFFIC, LOG_ERR, "Error while compressing packet to %s (%s)",
n->name, n->hostname); n->name, n->hostname);
return; return;
} }
@ -456,7 +456,7 @@ static void send_udppacket(node_t *n, vpn_packet_t *origpkt) {
outlen = MAXSIZE; outlen = MAXSIZE;
if(!cipher_encrypt(&n->outcipher, &inpkt->seqno, inpkt->len, &outpkt->seqno, &outlen, true)) { if(!cipher_encrypt(&n->outcipher, &inpkt->seqno, inpkt->len, &outpkt->seqno, &outlen, true)) {
ifdebug(TRAFFIC) logger(LOG_ERR, "Error while encrypting packet to %s (%s)", n->name, n->hostname); logger(DEBUG_TRAFFIC, LOG_ERR, "Error while encrypting packet to %s (%s)", n->name, n->hostname);
goto end; goto end;
} }
@ -511,9 +511,9 @@ static void send_udppacket(node_t *n, vpn_packet_t *origpkt) {
if(priorityinheritance && origpriority != priority if(priorityinheritance && origpriority != priority
&& listen_socket[n->sock].sa.sa.sa_family == AF_INET) { && listen_socket[n->sock].sa.sa.sa_family == AF_INET) {
priority = origpriority; priority = origpriority;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Setting outgoing packet priority to %d", priority); logger(DEBUG_TRAFFIC, LOG_DEBUG, "Setting outgoing packet priority to %d", priority);
if(setsockopt(listen_socket[n->sock].udp, SOL_IP, IP_TOS, &priority, sizeof(priority))) /* SO_PRIORITY doesn't seem to work */ if(setsockopt(listen_socket[n->sock].udp, SOL_IP, IP_TOS, &priority, sizeof(priority))) /* SO_PRIORITY doesn't seem to work */
logger(LOG_ERR, "System call `%s' failed: %s", "setsockopt", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "setsockopt", strerror(errno));
} }
#endif #endif
@ -524,7 +524,7 @@ static void send_udppacket(node_t *n, vpn_packet_t *origpkt) {
if(n->mtu >= origlen) if(n->mtu >= origlen)
n->mtu = origlen - 1; n->mtu = origlen - 1;
} else } else
logger(LOG_ERR, "Error sending packet to %s (%s): %s", n->name, n->hostname, sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "Error sending packet to %s (%s): %s", n->name, n->hostname, sockstrerror(sockerrno));
} }
end: end:
@ -546,11 +546,11 @@ void send_packet(node_t *n, vpn_packet_t *packet) {
return; return;
} }
ifdebug(TRAFFIC) logger(LOG_ERR, "Sending packet of %d bytes to %s (%s)", logger(DEBUG_TRAFFIC, LOG_ERR, "Sending packet of %d bytes to %s (%s)",
packet->len, n->name, n->hostname); packet->len, n->name, n->hostname);
if(!n->status.reachable) { if(!n->status.reachable) {
ifdebug(TRAFFIC) logger(LOG_INFO, "Node %s (%s) is not reachable", logger(DEBUG_TRAFFIC, LOG_INFO, "Node %s (%s) is not reachable",
n->name, n->hostname); n->name, n->hostname);
return; return;
} }
@ -561,7 +561,7 @@ void send_packet(node_t *n, vpn_packet_t *packet) {
via = (packet->priority == -1 || n->via == myself) ? n->nexthop : n->via; via = (packet->priority == -1 || n->via == myself) ? n->nexthop : n->via;
if(via != n) if(via != n)
ifdebug(TRAFFIC) logger(LOG_INFO, "Sending packet to %s via %s (%s)", logger(DEBUG_TRAFFIC, LOG_INFO, "Sending packet to %s via %s (%s)",
n->name, via->name, n->via->hostname); n->name, via->name, n->via->hostname);
if(packet->priority == -1 || ((myself->options | via->options) & OPTION_TCPONLY)) { if(packet->priority == -1 || ((myself->options | via->options) & OPTION_TCPONLY)) {
@ -577,7 +577,7 @@ void broadcast_packet(const node_t *from, vpn_packet_t *packet) {
splay_node_t *node; splay_node_t *node;
connection_t *c; connection_t *c;
ifdebug(TRAFFIC) logger(LOG_INFO, "Broadcasting packet of %d bytes from %s (%s)", logger(DEBUG_TRAFFIC, LOG_INFO, "Broadcasting packet of %d bytes from %s (%s)",
packet->len, from->name, from->hostname); packet->len, from->name, from->hostname);
if(from != myself) { if(from != myself) {
@ -643,7 +643,7 @@ void handle_incoming_vpn_data(int sock, short events, void *data) {
if(len <= 0 || len > MAXSIZE) { if(len <= 0 || len > MAXSIZE) {
if(!sockwouldblock(sockerrno)) if(!sockwouldblock(sockerrno))
logger(LOG_ERR, "Receiving packet failed: %s", sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "Receiving packet failed: %s", sockstrerror(sockerrno));
return; return;
} }
@ -657,9 +657,9 @@ void handle_incoming_vpn_data(int sock, short events, void *data) {
n = try_harder(&from, &pkt); n = try_harder(&from, &pkt);
if(n) if(n)
update_node_udp(n, &from); update_node_udp(n, &from);
else ifdebug(PROTOCOL) { else if(debug_level >= DEBUG_PROTOCOL) {
hostname = sockaddr2hostname(&from); hostname = sockaddr2hostname(&from);
logger(LOG_WARNING, "Received UDP packet from unknown source %s", hostname); logger(DEBUG_PROTOCOL, LOG_WARNING, "Received UDP packet from unknown source %s", hostname);
free(hostname); free(hostname);
return; return;
} }

78
src/net_setup.c
View file

@ -80,7 +80,7 @@ bool node_read_ecdsa_public_key(node_t *n) {
fp = fopen(fname, "r"); fp = fopen(fname, "r");
if(!fp) { if(!fp) {
logger(LOG_ERR, "Error reading ECDSA public key file `%s': %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Error reading ECDSA public key file `%s': %s", fname, strerror(errno));
goto exit; goto exit;
} }
@ -115,7 +115,7 @@ bool read_ecdsa_public_key(connection_t *c) {
fp = fopen(fname, "r"); fp = fopen(fname, "r");
if(!fp) { if(!fp) {
logger(LOG_ERR, "Error reading ECDSA public key file `%s': %s", logger(DEBUG_ALWAYS, LOG_ERR, "Error reading ECDSA public key file `%s': %s",
fname, strerror(errno)); fname, strerror(errno));
free(fname); free(fname);
return false; return false;
@ -125,7 +125,7 @@ bool read_ecdsa_public_key(connection_t *c) {
fclose(fp); fclose(fp);
if(!result) if(!result)
logger(LOG_ERR, "Reading ECDSA public key file `%s' failed: %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Reading ECDSA public key file `%s' failed: %s", fname, strerror(errno));
free(fname); free(fname);
return result; return result;
} }
@ -152,7 +152,7 @@ bool read_rsa_public_key(connection_t *c) {
fp = fopen(fname, "r"); fp = fopen(fname, "r");
if(!fp) { if(!fp) {
logger(LOG_ERR, "Error reading RSA public key file `%s': %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Error reading RSA public key file `%s': %s", fname, strerror(errno));
free(fname); free(fname);
return false; return false;
} }
@ -161,7 +161,7 @@ bool read_rsa_public_key(connection_t *c) {
fclose(fp); fclose(fp);
if(!result) if(!result)
logger(LOG_ERR, "Reading RSA public key file `%s' failed: %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Reading RSA public key file `%s' failed: %s", fname, strerror(errno));
free(fname); free(fname);
return result; return result;
} }
@ -179,7 +179,7 @@ static bool read_ecdsa_private_key(void) {
fp = fopen(fname, "r"); fp = fopen(fname, "r");
if(!fp) { if(!fp) {
logger(LOG_ERR, "Error reading ECDSA private key file `%s': %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Error reading ECDSA private key file `%s': %s", fname, strerror(errno));
free(fname); free(fname);
return false; return false;
} }
@ -188,20 +188,20 @@ static bool read_ecdsa_private_key(void) {
struct stat s; struct stat s;
if(fstat(fileno(fp), &s)) { if(fstat(fileno(fp), &s)) {
logger(LOG_ERR, "Could not stat ECDSA private key file `%s': %s'", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not stat ECDSA private key file `%s': %s'", fname, strerror(errno));
free(fname); free(fname);
return false; return false;
} }
if(s.st_mode & ~0100700) if(s.st_mode & ~0100700)
logger(LOG_WARNING, "Warning: insecure file permissions for ECDSA private key file `%s'!", fname); logger(DEBUG_ALWAYS, LOG_WARNING, "Warning: insecure file permissions for ECDSA private key file `%s'!", fname);
#endif #endif
result = ecdsa_read_pem_private_key(&myself->connection->ecdsa, fp); result = ecdsa_read_pem_private_key(&myself->connection->ecdsa, fp);
fclose(fp); fclose(fp);
if(!result) if(!result)
logger(LOG_ERR, "Reading ECDSA private key file `%s' failed: %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Reading ECDSA private key file `%s' failed: %s", fname, strerror(errno));
free(fname); free(fname);
return result; return result;
} }
@ -216,7 +216,7 @@ static bool read_rsa_private_key(void) {
if(get_config_string(lookup_config(config_tree, "PrivateKey"), &d)) { if(get_config_string(lookup_config(config_tree, "PrivateKey"), &d)) {
if(!get_config_string(lookup_config(config_tree, "PublicKey"), &n)) { if(!get_config_string(lookup_config(config_tree, "PublicKey"), &n)) {
logger(LOG_ERR, "PrivateKey used but no PublicKey found!"); logger(DEBUG_ALWAYS, LOG_ERR, "PrivateKey used but no PublicKey found!");
free(d); free(d);
return false; return false;
} }
@ -234,7 +234,7 @@ static bool read_rsa_private_key(void) {
fp = fopen(fname, "r"); fp = fopen(fname, "r");
if(!fp) { if(!fp) {
logger(LOG_ERR, "Error reading RSA private key file `%s': %s", logger(DEBUG_ALWAYS, LOG_ERR, "Error reading RSA private key file `%s': %s",
fname, strerror(errno)); fname, strerror(errno));
free(fname); free(fname);
return false; return false;
@ -244,20 +244,20 @@ static bool read_rsa_private_key(void) {
struct stat s; struct stat s;
if(fstat(fileno(fp), &s)) { if(fstat(fileno(fp), &s)) {
logger(LOG_ERR, "Could not stat RSA private key file `%s': %s'", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not stat RSA private key file `%s': %s'", fname, strerror(errno));
free(fname); free(fname);
return false; return false;
} }
if(s.st_mode & ~0100700) if(s.st_mode & ~0100700)
logger(LOG_WARNING, "Warning: insecure file permissions for RSA private key file `%s'!", fname); logger(DEBUG_ALWAYS, LOG_WARNING, "Warning: insecure file permissions for RSA private key file `%s'!", fname);
#endif #endif
result = rsa_read_pem_private_key(&myself->connection->rsa, fp); result = rsa_read_pem_private_key(&myself->connection->rsa, fp);
fclose(fp); fclose(fp);
if(!result) if(!result)
logger(LOG_ERR, "Reading RSA private key file `%s' failed: %s", fname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Reading RSA private key file `%s' failed: %s", fname, strerror(errno));
free(fname); free(fname);
return result; return result;
} }
@ -270,7 +270,7 @@ static void keyexpire_handler(int fd, short events, void *data) {
void regenerate_key(void) { void regenerate_key(void) {
if(timeout_initialized(&keyexpire_event)) { if(timeout_initialized(&keyexpire_event)) {
ifdebug(STATUS) logger(LOG_INFO, "Expiring symmetric keys"); logger(DEBUG_STATUS, LOG_INFO, "Expiring symmetric keys");
event_del(&keyexpire_event); event_del(&keyexpire_event);
send_key_changed(); send_key_changed();
} else { } else {
@ -297,7 +297,7 @@ void load_all_subnets(void) {
xasprintf(&dname, "%s/hosts", confbase); xasprintf(&dname, "%s/hosts", confbase);
dir = opendir(dname); dir = opendir(dname);
if(!dir) { if(!dir) {
logger(LOG_ERR, "Could not open %s: %s", dname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open %s: %s", dname, strerror(errno));
free(dname); free(dname);
return; return;
} }
@ -368,12 +368,12 @@ static bool setup_myself(void) {
myself->connection->protocol_minor = PROT_MINOR; myself->connection->protocol_minor = PROT_MINOR;
if(!get_config_string(lookup_config(config_tree, "Name"), &name)) { /* Not acceptable */ if(!get_config_string(lookup_config(config_tree, "Name"), &name)) { /* Not acceptable */
logger(LOG_ERR, "Name for tinc daemon required!"); logger(DEBUG_ALWAYS, LOG_ERR, "Name for tinc daemon required!");
return false; return false;
} }
if(!check_id(name)) { if(!check_id(name)) {
logger(LOG_ERR, "Invalid name for myself!"); logger(DEBUG_ALWAYS, LOG_ERR, "Invalid name for myself!");
free(name); free(name);
return false; return false;
} }
@ -444,7 +444,7 @@ static bool setup_myself(void) {
else if(!strcasecmp(mode, "hub")) else if(!strcasecmp(mode, "hub"))
routing_mode = RMODE_HUB; routing_mode = RMODE_HUB;
else { else {
logger(LOG_ERR, "Invalid routing mode!"); logger(DEBUG_ALWAYS, LOG_ERR, "Invalid routing mode!");
return false; return false;
} }
free(mode); free(mode);
@ -458,7 +458,7 @@ static bool setup_myself(void) {
else if(!strcasecmp(mode, "kernel")) else if(!strcasecmp(mode, "kernel"))
forwarding_mode = FMODE_KERNEL; forwarding_mode = FMODE_KERNEL;
else { else {
logger(LOG_ERR, "Invalid forwarding mode!"); logger(DEBUG_ALWAYS, LOG_ERR, "Invalid forwarding mode!");
return false; return false;
} }
free(mode); free(mode);
@ -480,7 +480,7 @@ static bool setup_myself(void) {
#if !defined(SOL_IP) || !defined(IP_TOS) #if !defined(SOL_IP) || !defined(IP_TOS)
if(priorityinheritance) if(priorityinheritance)
logger(LOG_WARNING, "%s not supported on this platform", "PriorityInheritance"); logger(DEBUG_ALWAYS, LOG_WARNING, "%s not supported on this platform", "PriorityInheritance");
#endif #endif
if(!get_config_int(lookup_config(config_tree, "MACExpire"), &macexpire)) if(!get_config_int(lookup_config(config_tree, "MACExpire"), &macexpire))
@ -488,7 +488,7 @@ static bool setup_myself(void) {
if(get_config_int(lookup_config(config_tree, "MaxTimeout"), &maxtimeout)) { if(get_config_int(lookup_config(config_tree, "MaxTimeout"), &maxtimeout)) {
if(maxtimeout <= 0) { if(maxtimeout <= 0) {
logger(LOG_ERR, "Bogus maximum timeout!"); logger(DEBUG_ALWAYS, LOG_ERR, "Bogus maximum timeout!");
return false; return false;
} }
} else } else
@ -496,21 +496,21 @@ static bool setup_myself(void) {
if(get_config_int(lookup_config(config_tree, "UDPRcvBuf"), &udp_rcvbuf)) { if(get_config_int(lookup_config(config_tree, "UDPRcvBuf"), &udp_rcvbuf)) {
if(udp_rcvbuf <= 0) { if(udp_rcvbuf <= 0) {
logger(LOG_ERR, "UDPRcvBuf cannot be negative!"); logger(DEBUG_ALWAYS, LOG_ERR, "UDPRcvBuf cannot be negative!");
return false; return false;
} }
} }
if(get_config_int(lookup_config(config_tree, "UDPSndBuf"), &udp_sndbuf)) { if(get_config_int(lookup_config(config_tree, "UDPSndBuf"), &udp_sndbuf)) {
if(udp_sndbuf <= 0) { if(udp_sndbuf <= 0) {
logger(LOG_ERR, "UDPSndBuf cannot be negative!"); logger(DEBUG_ALWAYS, LOG_ERR, "UDPSndBuf cannot be negative!");
return false; return false;
} }
} }
if(get_config_int(lookup_config(config_tree, "ReplayWindow"), &replaywin_int)) { if(get_config_int(lookup_config(config_tree, "ReplayWindow"), &replaywin_int)) {
if(replaywin_int < 0) { if(replaywin_int < 0) {
logger(LOG_ERR, "ReplayWindow cannot be negative!"); logger(DEBUG_ALWAYS, LOG_ERR, "ReplayWindow cannot be negative!");
return false; return false;
} }
replaywin = (unsigned)replaywin_int; replaywin = (unsigned)replaywin_int;
@ -524,7 +524,7 @@ static bool setup_myself(void) {
else if(!strcasecmp(afname, "any")) else if(!strcasecmp(afname, "any"))
addressfamily = AF_UNSPEC; addressfamily = AF_UNSPEC;
else { else {
logger(LOG_ERR, "Invalid address family!"); logger(DEBUG_ALWAYS, LOG_ERR, "Invalid address family!");
return false; return false;
} }
free(afname); free(afname);
@ -538,7 +538,7 @@ static bool setup_myself(void) {
cipher = xstrdup("blowfish"); cipher = xstrdup("blowfish");
if(!cipher_open_by_name(&myself->incipher, cipher)) { if(!cipher_open_by_name(&myself->incipher, cipher)) {
logger(LOG_ERR, "Unrecognized cipher type!"); logger(DEBUG_ALWAYS, LOG_ERR, "Unrecognized cipher type!");
return false; return false;
} }
@ -553,7 +553,7 @@ static bool setup_myself(void) {
get_config_int(lookup_config(config_tree, "MACLength"), &maclength); get_config_int(lookup_config(config_tree, "MACLength"), &maclength);
if(maclength < 0) { if(maclength < 0) {
logger(LOG_ERR, "Bogus MAC length!"); logger(DEBUG_ALWAYS, LOG_ERR, "Bogus MAC length!");
return false; return false;
} }
@ -561,7 +561,7 @@ static bool setup_myself(void) {
digest = xstrdup("sha1"); digest = xstrdup("sha1");
if(!digest_open_by_name(&myself->indigest, digest, maclength)) { if(!digest_open_by_name(&myself->indigest, digest, maclength)) {
logger(LOG_ERR, "Unrecognized digest type!"); logger(DEBUG_ALWAYS, LOG_ERR, "Unrecognized digest type!");
return false; return false;
} }
@ -569,7 +569,7 @@ static bool setup_myself(void) {
if(get_config_int(lookup_config(config_tree, "Compression"), &myself->incompression)) { if(get_config_int(lookup_config(config_tree, "Compression"), &myself->incompression)) {
if(myself->incompression < 0 || myself->incompression > 11) { if(myself->incompression < 0 || myself->incompression > 11) {
logger(LOG_ERR, "Bogus compression level!"); logger(DEBUG_ALWAYS, LOG_ERR, "Bogus compression level!");
return false; return false;
} }
} else } else
@ -615,7 +615,7 @@ static bool setup_myself(void) {
event_set(&device_ev, device_fd, EV_READ|EV_PERSIST, handle_device_data, NULL); event_set(&device_ev, device_fd, EV_READ|EV_PERSIST, handle_device_data, NULL);
if (event_add(&device_ev, NULL) < 0) { if (event_add(&device_ev, NULL) < 0) {
logger(LOG_ERR, "event_add failed: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "event_add failed: %s", strerror(errno));
devops.close(); devops.close();
return false; return false;
} }
@ -656,14 +656,14 @@ static bool setup_myself(void) {
free(address); free(address);
if(err || !ai) { if(err || !ai) {
logger(LOG_ERR, "System call `%s' failed: %s", "getaddrinfo", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "getaddrinfo",
gai_strerror(err)); gai_strerror(err));
return false; return false;
} }
for(aip = ai; aip; aip = aip->ai_next) { for(aip = ai; aip; aip = aip->ai_next) {
if(listen_sockets >= MAXSOCKETS) { if(listen_sockets >= MAXSOCKETS) {
logger(LOG_ERR, "Too many listening sockets"); logger(DEBUG_ALWAYS, LOG_ERR, "Too many listening sockets");
return false; return false;
} }
@ -686,7 +686,7 @@ static bool setup_myself(void) {
EV_READ|EV_PERSIST, EV_READ|EV_PERSIST,
handle_new_meta_connection, NULL); handle_new_meta_connection, NULL);
if(event_add(&listen_socket[listen_sockets].ev_tcp, NULL) < 0) { if(event_add(&listen_socket[listen_sockets].ev_tcp, NULL) < 0) {
logger(LOG_ERR, "event_add failed: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "event_add failed: %s", strerror(errno));
abort(); abort();
} }
@ -695,13 +695,13 @@ static bool setup_myself(void) {
EV_READ|EV_PERSIST, EV_READ|EV_PERSIST,
handle_incoming_vpn_data, (void *)(intptr_t)listen_sockets); handle_incoming_vpn_data, (void *)(intptr_t)listen_sockets);
if(event_add(&listen_socket[listen_sockets].ev_udp, NULL) < 0) { if(event_add(&listen_socket[listen_sockets].ev_udp, NULL) < 0) {
logger(LOG_ERR, "event_add failed: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "event_add failed: %s", strerror(errno));
abort(); abort();
} }
ifdebug(CONNECTIONS) { if(debug_level >= DEBUG_CONNECTIONS) {
hostname = sockaddr2hostname((sockaddr_t *) aip->ai_addr); hostname = sockaddr2hostname((sockaddr_t *) aip->ai_addr);
logger(LOG_NOTICE, "Listening on %s", hostname); logger(DEBUG_CONNECTIONS, LOG_NOTICE, "Listening on %s", hostname);
free(hostname); free(hostname);
} }
@ -713,9 +713,9 @@ static bool setup_myself(void) {
} while(cfg); } while(cfg);
if(listen_sockets) if(listen_sockets)
logger(LOG_NOTICE, "Ready"); logger(DEBUG_ALWAYS, LOG_NOTICE, "Ready");
else { else {
logger(LOG_ERR, "Unable to create any listening socket!"); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to create any listening socket!");
return false; return false;
} }

58
src/net_socket.c
View file

@ -57,13 +57,13 @@ static void configure_tcp(connection_t *c) {
int flags = fcntl(c->socket, F_GETFL); int flags = fcntl(c->socket, F_GETFL);
if(fcntl(c->socket, F_SETFL, flags | O_NONBLOCK) < 0) { if(fcntl(c->socket, F_SETFL, flags | O_NONBLOCK) < 0) {
logger(LOG_ERR, "fcntl for %s: %s", c->hostname, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "fcntl for %s: %s", c->hostname, strerror(errno));
} }
#elif defined(WIN32) #elif defined(WIN32)
unsigned long arg = 1; unsigned long arg = 1;
if(ioctlsocket(c->socket, FIONBIO, &arg) != 0) { if(ioctlsocket(c->socket, FIONBIO, &arg) != 0) {
logger(LOG_ERR, "ioctlsocket for %s: %d", c->hostname, sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "ioctlsocket for %s: %d", c->hostname, sockstrerror(sockerrno));
} }
#endif #endif
@ -96,12 +96,12 @@ static bool bind_to_interface(int sd) {
status = setsockopt(sd, SOL_SOCKET, SO_BINDTODEVICE, (void *)&ifr, sizeof(ifr)); status = setsockopt(sd, SOL_SOCKET, SO_BINDTODEVICE, (void *)&ifr, sizeof(ifr));
if(status) { if(status) {
logger(LOG_ERR, "Can't bind to interface %s: %s", iface, logger(DEBUG_ALWAYS, LOG_ERR, "Can't bind to interface %s: %s", iface,
strerror(errno)); strerror(errno));
return false; return false;
} }
#else /* if !defined(SOL_SOCKET) || !defined(SO_BINDTODEVICE) */ #else /* if !defined(SOL_SOCKET) || !defined(SO_BINDTODEVICE) */
logger(LOG_WARNING, "%s not supported on this platform", "BindToInterface"); logger(DEBUG_ALWAYS, LOG_WARNING, "%s not supported on this platform", "BindToInterface");
#endif #endif
return true; return true;
@ -116,7 +116,7 @@ int setup_listen_socket(const sockaddr_t *sa) {
nfd = socket(sa->sa.sa_family, SOCK_STREAM, IPPROTO_TCP); nfd = socket(sa->sa.sa_family, SOCK_STREAM, IPPROTO_TCP);
if(nfd < 0) { if(nfd < 0) {
ifdebug(STATUS) logger(LOG_ERR, "Creating metasocket failed: %s", sockstrerror(sockerrno)); logger(DEBUG_STATUS, LOG_ERR, "Creating metasocket failed: %s", sockstrerror(sockerrno));
return -1; return -1;
} }
@ -144,26 +144,26 @@ int setup_listen_socket(const sockaddr_t *sa) {
if(setsockopt(nfd, SOL_SOCKET, SO_BINDTODEVICE, (void *)&ifr, sizeof ifr)) { if(setsockopt(nfd, SOL_SOCKET, SO_BINDTODEVICE, (void *)&ifr, sizeof ifr)) {
closesocket(nfd); closesocket(nfd);
logger(LOG_ERR, "Can't bind to interface %s: %s", iface, logger(DEBUG_ALWAYS, LOG_ERR, "Can't bind to interface %s: %s", iface,
strerror(sockerrno)); strerror(sockerrno));
return -1; return -1;
} }
#else #else
logger(LOG_WARNING, "%s not supported on this platform", "BindToInterface"); logger(DEBUG_ALWAYS, LOG_WARNING, "%s not supported on this platform", "BindToInterface");
#endif #endif
} }
if(bind(nfd, &sa->sa, SALEN(sa->sa))) { if(bind(nfd, &sa->sa, SALEN(sa->sa))) {
closesocket(nfd); closesocket(nfd);
addrstr = sockaddr2hostname(sa); addrstr = sockaddr2hostname(sa);
logger(LOG_ERR, "Can't bind to %s/tcp: %s", addrstr, sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "Can't bind to %s/tcp: %s", addrstr, sockstrerror(sockerrno));
free(addrstr); free(addrstr);
return -1; return -1;
} }
if(listen(nfd, 3)) { if(listen(nfd, 3)) {
closesocket(nfd); closesocket(nfd);
logger(LOG_ERR, "System call `%s' failed: %s", "listen", sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "listen", sockstrerror(sockerrno));
return -1; return -1;
} }
@ -178,7 +178,7 @@ int setup_vpn_in_socket(const sockaddr_t *sa) {
nfd = socket(sa->sa.sa_family, SOCK_DGRAM, IPPROTO_UDP); nfd = socket(sa->sa.sa_family, SOCK_DGRAM, IPPROTO_UDP);
if(nfd < 0) { if(nfd < 0) {
logger(LOG_ERR, "Creating UDP socket failed: %s", sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "Creating UDP socket failed: %s", sockstrerror(sockerrno));
return -1; return -1;
} }
@ -192,7 +192,7 @@ int setup_vpn_in_socket(const sockaddr_t *sa) {
if(fcntl(nfd, F_SETFL, flags | O_NONBLOCK) < 0) { if(fcntl(nfd, F_SETFL, flags | O_NONBLOCK) < 0) {
closesocket(nfd); closesocket(nfd);
logger(LOG_ERR, "System call `%s' failed: %s", "fcntl", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "fcntl",
strerror(errno)); strerror(errno));
return -1; return -1;
} }
@ -202,7 +202,7 @@ int setup_vpn_in_socket(const sockaddr_t *sa) {
unsigned long arg = 1; unsigned long arg = 1;
if(ioctlsocket(nfd, FIONBIO, &arg) != 0) { if(ioctlsocket(nfd, FIONBIO, &arg) != 0) {
closesocket(nfd); closesocket(nfd);
logger(LOG_ERR, "Call to `%s' failed: %s", "ioctlsocket", sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "Call to `%s' failed: %s", "ioctlsocket", sockstrerror(sockerrno));
return -1; return -1;
} }
} }
@ -213,10 +213,10 @@ int setup_vpn_in_socket(const sockaddr_t *sa) {
setsockopt(nfd, SOL_SOCKET, SO_BROADCAST, (void *)&option, sizeof option); setsockopt(nfd, SOL_SOCKET, SO_BROADCAST, (void *)&option, sizeof option);
if(udp_rcvbuf && setsockopt(nfd, SOL_SOCKET, SO_RCVBUF, (void *)&udp_rcvbuf, sizeof(udp_rcvbuf))) if(udp_rcvbuf && setsockopt(nfd, SOL_SOCKET, SO_RCVBUF, (void *)&udp_rcvbuf, sizeof(udp_rcvbuf)))
logger(LOG_WARNING, "Can't set UDP SO_RCVBUF to %i: %s", udp_rcvbuf, strerror(errno)); logger(DEBUG_ALWAYS, LOG_WARNING, "Can't set UDP SO_RCVBUF to %i: %s", udp_rcvbuf, strerror(errno));
if(udp_sndbuf && setsockopt(nfd, SOL_SOCKET, SO_SNDBUF, (void *)&udp_sndbuf, sizeof(udp_sndbuf))) if(udp_sndbuf && setsockopt(nfd, SOL_SOCKET, SO_SNDBUF, (void *)&udp_sndbuf, sizeof(udp_sndbuf)))
logger(LOG_WARNING, "Can't set UDP SO_SNDBUF to %i: %s", udp_sndbuf, strerror(errno)); logger(DEBUG_ALWAYS, LOG_WARNING, "Can't set UDP SO_SNDBUF to %i: %s", udp_sndbuf, strerror(errno));
#if defined(IPPROTO_IPV6) && defined(IPV6_V6ONLY) #if defined(IPPROTO_IPV6) && defined(IPV6_V6ONLY)
if(sa->sa.sa_family == AF_INET6) if(sa->sa.sa_family == AF_INET6)
@ -263,7 +263,7 @@ int setup_vpn_in_socket(const sockaddr_t *sa) {
if(bind(nfd, &sa->sa, SALEN(sa->sa))) { if(bind(nfd, &sa->sa, SALEN(sa->sa))) {
closesocket(nfd); closesocket(nfd);
addrstr = sockaddr2hostname(sa); addrstr = sockaddr2hostname(sa);
logger(LOG_ERR, "Can't bind to %s/udp: %s", addrstr, sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "Can't bind to %s/udp: %s", addrstr, sockstrerror(sockerrno));
free(addrstr); free(addrstr);
return -1; return -1;
} }
@ -284,13 +284,13 @@ void retry_outgoing(outgoing_t *outgoing) {
timeout_set(&outgoing->ev, retry_outgoing_handler, outgoing); timeout_set(&outgoing->ev, retry_outgoing_handler, outgoing);
event_add(&outgoing->ev, &(struct timeval){outgoing->timeout, 0}); event_add(&outgoing->ev, &(struct timeval){outgoing->timeout, 0});
ifdebug(CONNECTIONS) logger(LOG_NOTICE, logger(DEBUG_CONNECTIONS, LOG_NOTICE,
"Trying to re-establish outgoing connection in %d seconds", "Trying to re-establish outgoing connection in %d seconds",
outgoing->timeout); outgoing->timeout);
} }
void finish_connecting(connection_t *c) { void finish_connecting(connection_t *c) {
ifdebug(CONNECTIONS) logger(LOG_INFO, "Connected to %s (%s)", c->name, c->hostname); logger(DEBUG_CONNECTIONS, LOG_INFO, "Connected to %s (%s)", c->name, c->hostname);
configure_tcp(c); configure_tcp(c);
@ -305,14 +305,14 @@ bool do_outgoing_connection(connection_t *c) {
int result; int result;
if(!c->outgoing) { if(!c->outgoing) {
logger(LOG_ERR, "do_outgoing_connection() for %s called without c->outgoing", c->name); logger(DEBUG_ALWAYS, LOG_ERR, "do_outgoing_connection() for %s called without c->outgoing", c->name);
abort(); abort();
} }
begin: begin:
if(!c->outgoing->ai) { if(!c->outgoing->ai) {
if(!c->outgoing->cfg) { if(!c->outgoing->cfg) {
ifdebug(CONNECTIONS) logger(LOG_ERR, "Could not set up a meta connection to %s", logger(DEBUG_CONNECTIONS, LOG_ERR, "Could not set up a meta connection to %s",
c->name); c->name);
retry_outgoing(c->outgoing); retry_outgoing(c->outgoing);
c->outgoing = NULL; c->outgoing = NULL;
@ -354,7 +354,7 @@ begin:
c->hostname = sockaddr2hostname(&c->address); c->hostname = sockaddr2hostname(&c->address);
ifdebug(CONNECTIONS) logger(LOG_INFO, "Trying to connect to %s (%s)", c->name, logger(DEBUG_CONNECTIONS, LOG_INFO, "Trying to connect to %s (%s)", c->name,
c->hostname); c->hostname);
c->socket = socket(c->address.sa.sa_family, SOCK_STREAM, IPPROTO_TCP); c->socket = socket(c->address.sa.sa_family, SOCK_STREAM, IPPROTO_TCP);
@ -364,7 +364,7 @@ begin:
#endif #endif
if(c->socket == -1) { if(c->socket == -1) {
ifdebug(CONNECTIONS) logger(LOG_ERR, "Creating socket for %s failed: %s", c->hostname, sockstrerror(sockerrno)); logger(DEBUG_CONNECTIONS, LOG_ERR, "Creating socket for %s failed: %s", c->hostname, sockstrerror(sockerrno));
goto begin; goto begin;
} }
@ -392,7 +392,7 @@ begin:
closesocket(c->socket); closesocket(c->socket);
ifdebug(CONNECTIONS) logger(LOG_ERR, "%s: %s", c->hostname, sockstrerror(sockerrno)); logger(DEBUG_CONNECTIONS, LOG_ERR, "%s: %s", c->hostname, sockstrerror(sockerrno));
goto begin; goto begin;
} }
@ -403,13 +403,11 @@ begin:
} }
static void handle_meta_write(int sock, short events, void *data) { static void handle_meta_write(int sock, short events, void *data) {
ifdebug(META) logger(LOG_DEBUG, "handle_meta_write() called");
connection_t *c = data; connection_t *c = data;
ssize_t outlen = send(c->socket, c->outbuf.data + c->outbuf.offset, c->outbuf.len - c->outbuf.offset, 0); ssize_t outlen = send(c->socket, c->outbuf.data + c->outbuf.offset, c->outbuf.len - c->outbuf.offset, 0);
if(outlen <= 0) { if(outlen <= 0) {
logger(LOG_ERR, "Onoes, outlen = %d (%s)", (int)outlen, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Onoes, outlen = %d (%s)", (int)outlen, strerror(errno));
terminate_connection(c, c->status.active); terminate_connection(c, c->status.active);
return; return;
} }
@ -430,7 +428,7 @@ void setup_outgoing_connection(outgoing_t *outgoing) {
if(n) if(n)
if(n->connection) { if(n->connection) {
ifdebug(CONNECTIONS) logger(LOG_INFO, "Already connected to %s", outgoing->name); logger(DEBUG_CONNECTIONS, LOG_INFO, "Already connected to %s", outgoing->name);
n->connection->outgoing = outgoing; n->connection->outgoing = outgoing;
return; return;
@ -449,7 +447,7 @@ void setup_outgoing_connection(outgoing_t *outgoing) {
outgoing->cfg = lookup_config(c->config_tree, "Address"); outgoing->cfg = lookup_config(c->config_tree, "Address");
if(!outgoing->cfg) { if(!outgoing->cfg) {
logger(LOG_ERR, "No address specified for %s", c->name); logger(DEBUG_ALWAYS, LOG_ERR, "No address specified for %s", c->name);
free_connection(c); free_connection(c);
return; return;
} }
@ -479,7 +477,7 @@ void handle_new_meta_connection(int sock, short events, void *data) {
fd = accept(sock, &sa.sa, &len); fd = accept(sock, &sa.sa, &len);
if(fd < 0) { if(fd < 0) {
logger(LOG_ERR, "Accepting a new connection failed: %s", sockstrerror(sockerrno)); logger(DEBUG_ALWAYS, LOG_ERR, "Accepting a new connection failed: %s", sockstrerror(sockerrno));
return; return;
} }
@ -497,7 +495,7 @@ void handle_new_meta_connection(int sock, short events, void *data) {
c->socket = fd; c->socket = fd;
c->last_ping_time = time(NULL); c->last_ping_time = time(NULL);
ifdebug(CONNECTIONS) logger(LOG_NOTICE, "Connection from %s", c->hostname); logger(DEBUG_CONNECTIONS, LOG_NOTICE, "Connection from %s", c->hostname);
event_set(&c->inevent, c->socket, EV_READ | EV_PERSIST, handle_meta_connection_data, c); event_set(&c->inevent, c->socket, EV_READ | EV_PERSIST, handle_meta_connection_data, c);
event_set(&c->outevent, c->socket, EV_WRITE | EV_PERSIST, handle_meta_write, c); event_set(&c->outevent, c->socket, EV_WRITE | EV_PERSIST, handle_meta_write, c);
@ -532,7 +530,7 @@ void try_outgoing_connections(void) {
get_config_string(cfg, &name); get_config_string(cfg, &name);
if(!check_id(name)) { if(!check_id(name)) {
logger(LOG_ERR, logger(DEBUG_ALWAYS, LOG_ERR,
"Invalid name for outgoing connection in %s line %d", "Invalid name for outgoing connection in %s line %d",
cfg->file, cfg->line); cfg->file, cfg->line);
free(name); free(name);

13
src/netutl.c
View file

@ -42,7 +42,7 @@ struct addrinfo *str2addrinfo(const char *address, const char *service, int sock
err = getaddrinfo(address, service, &hint, &ai); err = getaddrinfo(address, service, &hint, &ai);
if(err) { if(err) {
logger(LOG_WARNING, "Error looking up %s port %s: %s", address, logger(DEBUG_ALWAYS, LOG_WARNING, "Error looking up %s port %s: %s", address,
service, gai_strerror(err)); service, gai_strerror(err));
return NULL; return NULL;
} }
@ -62,8 +62,7 @@ sockaddr_t str2sockaddr(const char *address, const char *port) {
err = getaddrinfo(address, port, &hint, &ai); err = getaddrinfo(address, port, &hint, &ai);
if(err || !ai) { if(err || !ai) {
ifdebug(SCARY_THINGS) logger(DEBUG_SCARY_THINGS, LOG_DEBUG, "Unknown type address %s port %s", address, port);
logger(LOG_DEBUG, "Unknown type address %s port %s", address, port);
result.sa.sa_family = AF_UNKNOWN; result.sa.sa_family = AF_UNKNOWN;
result.unknown.address = xstrdup(address); result.unknown.address = xstrdup(address);
result.unknown.port = xstrdup(port); result.unknown.port = xstrdup(port);
@ -91,7 +90,7 @@ void sockaddr2str(const sockaddr_t *sa, char **addrstr, char **portstr) {
err = getnameinfo(&sa->sa, SALEN(sa->sa), address, sizeof address, port, sizeof port, NI_NUMERICHOST | NI_NUMERICSERV); err = getnameinfo(&sa->sa, SALEN(sa->sa), address, sizeof address, port, sizeof port, NI_NUMERICHOST | NI_NUMERICSERV);
if(err) { if(err) {
logger(LOG_ERR, "Error while translating addresses: %s", logger(DEBUG_ALWAYS, LOG_ERR, "Error while translating addresses: %s",
gai_strerror(err)); gai_strerror(err));
abort(); abort();
} }
@ -121,7 +120,7 @@ char *sockaddr2hostname(const sockaddr_t *sa) {
err = getnameinfo(&sa->sa, SALEN(sa->sa), address, sizeof address, port, sizeof port, err = getnameinfo(&sa->sa, SALEN(sa->sa), address, sizeof address, port, sizeof port,
hostnames ? 0 : (NI_NUMERICHOST | NI_NUMERICSERV)); hostnames ? 0 : (NI_NUMERICHOST | NI_NUMERICSERV));
if(err) { if(err) {
logger(LOG_ERR, "Error while looking up hostname: %s", logger(DEBUG_ALWAYS, LOG_ERR, "Error while looking up hostname: %s",
gai_strerror(err)); gai_strerror(err));
} }
@ -152,7 +151,7 @@ int sockaddrcmp_noport(const sockaddr_t *a, const sockaddr_t *b) {
return memcmp(&a->in6.sin6_addr, &b->in6.sin6_addr, sizeof(a->in6.sin6_addr)); return memcmp(&a->in6.sin6_addr, &b->in6.sin6_addr, sizeof(a->in6.sin6_addr));
default: default:
logger(LOG_ERR, "sockaddrcmp() was called with unknown address family %d, exitting!", logger(DEBUG_ALWAYS, LOG_ERR, "sockaddrcmp() was called with unknown address family %d, exitting!",
a->sa.sa_family); a->sa.sa_family);
abort(); abort();
} }
@ -195,7 +194,7 @@ int sockaddrcmp(const sockaddr_t *a, const sockaddr_t *b) {
return memcmp(&a->in6.sin6_port, &b->in6.sin6_port, sizeof a->in6.sin6_port); return memcmp(&a->in6.sin6_port, &b->in6.sin6_port, sizeof a->in6.sin6_port);
default: default:
logger(LOG_ERR, "sockaddrcmp() was called with unknown address family %d, exitting!", logger(DEBUG_ALWAYS, LOG_ERR, "sockaddrcmp() was called with unknown address family %d, exitting!",
a->sa.sa_family); a->sa.sa_family);
abort(); abort();
} }

6
src/node.c
View file

@ -147,7 +147,7 @@ node_t *lookup_node_udp(const sockaddr_t *sa) {
void update_node_udp(node_t *n, const sockaddr_t *sa) { void update_node_udp(node_t *n, const sockaddr_t *sa) {
if(n == myself) { if(n == myself) {
logger(LOG_WARNING, "Trying to update UDP address of myself!"); logger(DEBUG_ALWAYS, LOG_WARNING, "Trying to update UDP address of myself!");
return; return;
} }
@ -160,11 +160,11 @@ void update_node_udp(node_t *n, const sockaddr_t *sa) {
n->address = *sa; n->address = *sa;
n->hostname = sockaddr2hostname(&n->address); n->hostname = sockaddr2hostname(&n->address);
splay_insert(node_udp_tree, n); splay_insert(node_udp_tree, n);
ifdebug(PROTOCOL) logger(LOG_DEBUG, "UDP address of %s set to %s", n->name, n->hostname); logger(DEBUG_PROTOCOL, LOG_DEBUG, "UDP address of %s set to %s", n->name, n->hostname);
} else { } else {
memset(&n->address, 0, sizeof n->address); memset(&n->address, 0, sizeof n->address);
n->hostname = NULL; n->hostname = NULL;
ifdebug(PROTOCOL) logger(LOG_DEBUG, "UDP address of %s cleared", n->name); logger(DEBUG_PROTOCOL, LOG_DEBUG, "UDP address of %s cleared", n->name);
} }
} }

18
src/openssl/cipher.c
View file

@ -44,7 +44,7 @@ bool cipher_open_by_name(cipher_t *cipher, const char *name) {
if(cipher->cipher) if(cipher->cipher)
return cipher_open(cipher); return cipher_open(cipher);
logger(LOG_ERR, "Unknown cipher name '%s'!", name); logger(DEBUG_ALWAYS, LOG_ERR, "Unknown cipher name '%s'!", name);
return false; return false;
} }
@ -54,7 +54,7 @@ bool cipher_open_by_nid(cipher_t *cipher, int nid) {
if(cipher->cipher) if(cipher->cipher)
return cipher_open(cipher); return cipher_open(cipher);
logger(LOG_ERR, "Unknown cipher nid %d!", nid); logger(DEBUG_ALWAYS, LOG_ERR, "Unknown cipher nid %d!", nid);
return false; return false;
} }
@ -86,7 +86,7 @@ bool cipher_set_key(cipher_t *cipher, void *key, bool encrypt) {
if(result) if(result)
return true; return true;
logger(LOG_ERR, "Error while setting key: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while setting key: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -101,14 +101,14 @@ bool cipher_set_key_from_rsa(cipher_t *cipher, void *key, size_t len, bool encry
if(result) if(result)
return true; return true;
logger(LOG_ERR, "Error while setting key: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while setting key: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
bool cipher_set_counter_key(cipher_t *cipher, void *key) { bool cipher_set_counter_key(cipher_t *cipher, void *key) {
int result = EVP_EncryptInit_ex(&cipher->ctx, cipher->cipher, NULL, (unsigned char *)key, NULL); int result = EVP_EncryptInit_ex(&cipher->ctx, cipher->cipher, NULL, (unsigned char *)key, NULL);
if(!result) { if(!result) {
logger(LOG_ERR, "Error while setting key: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while setting key: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -124,7 +124,7 @@ bool cipher_set_counter_key(cipher_t *cipher, void *key) {
bool cipher_counter_xor(cipher_t *cipher, const void *indata, size_t inlen, void *outdata) { bool cipher_counter_xor(cipher_t *cipher, const void *indata, size_t inlen, void *outdata) {
if(!cipher->counter) { if(!cipher->counter) {
logger(LOG_ERR, "Counter not initialized"); logger(DEBUG_ALWAYS, LOG_ERR, "Counter not initialized");
return false; return false;
} }
@ -136,7 +136,7 @@ bool cipher_counter_xor(cipher_t *cipher, const void *indata, size_t inlen, void
if(!cipher->counter->n) { if(!cipher->counter->n) {
int len; int len;
if(!EVP_EncryptUpdate(&cipher->ctx, cipher->counter->block, &len, cipher->counter->counter, cipher->cipher->block_size)) { if(!EVP_EncryptUpdate(&cipher->ctx, cipher->counter->block, &len, cipher->counter->counter, cipher->cipher->block_size)) {
logger(LOG_ERR, "Error while encrypting: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while encrypting: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -173,7 +173,7 @@ bool cipher_encrypt(cipher_t *cipher, const void *indata, size_t inlen, void *ou
} }
} }
logger(LOG_ERR, "Error while encrypting: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while encrypting: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -194,7 +194,7 @@ bool cipher_decrypt(cipher_t *cipher, const void *indata, size_t inlen, void *ou
} }
} }
logger(LOG_ERR, "Error while decrypting: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while decrypting: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }

6
src/openssl/digest.c
View file

@ -41,7 +41,7 @@ bool digest_open_by_name(digest_t *digest, const char *name, int maclength) {
digest->key = NULL; digest->key = NULL;
if(!digest->digest) { if(!digest->digest) {
logger(LOG_DEBUG, "Unknown digest name '%s'!", name); logger(DEBUG_ALWAYS, LOG_DEBUG, "Unknown digest name '%s'!", name);
return false; return false;
} }
@ -54,7 +54,7 @@ bool digest_open_by_nid(digest_t *digest, int nid, int maclength) {
digest->key = NULL; digest->key = NULL;
if(!digest->digest) { if(!digest->digest) {
logger(LOG_DEBUG, "Unknown digest nid %d!", nid); logger(DEBUG_ALWAYS, LOG_DEBUG, "Unknown digest nid %d!", nid);
return false; return false;
} }
@ -95,7 +95,7 @@ bool digest_create(digest_t *digest, const void *indata, size_t inlen, void *out
if(!EVP_DigestInit(&ctx, digest->digest) if(!EVP_DigestInit(&ctx, digest->digest)
|| !EVP_DigestUpdate(&ctx, indata, inlen) || !EVP_DigestUpdate(&ctx, indata, inlen)
|| !EVP_DigestFinal(&ctx, tmpdata, NULL)) { || !EVP_DigestFinal(&ctx, tmpdata, NULL)) {
logger(LOG_DEBUG, "Error creating digest: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_DEBUG, "Error creating digest: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
} }

12
src/openssl/ecdh.c
View file

@ -31,19 +31,19 @@
bool ecdh_generate_public(ecdh_t *ecdh, void *pubkey) { bool ecdh_generate_public(ecdh_t *ecdh, void *pubkey) {
*ecdh = EC_KEY_new_by_curve_name(NID_secp521r1); *ecdh = EC_KEY_new_by_curve_name(NID_secp521r1);
if(!EC_KEY_generate_key(*ecdh)) { if(!EC_KEY_generate_key(*ecdh)) {
logger(LOG_ERR, "Generating EC key failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Generating EC key failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
const EC_POINT *point = EC_KEY_get0_public_key(*ecdh); const EC_POINT *point = EC_KEY_get0_public_key(*ecdh);
if(!point) { if(!point) {
logger(LOG_ERR, "Getting public key failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Getting public key failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
size_t result = EC_POINT_point2oct(EC_KEY_get0_group(*ecdh), point, POINT_CONVERSION_COMPRESSED, pubkey, ECDH_SIZE, NULL); size_t result = EC_POINT_point2oct(EC_KEY_get0_group(*ecdh), point, POINT_CONVERSION_COMPRESSED, pubkey, ECDH_SIZE, NULL);
if(!result) { if(!result) {
logger(LOG_ERR, "Converting EC_POINT to binary failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Converting EC_POINT to binary failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -53,13 +53,13 @@ bool ecdh_generate_public(ecdh_t *ecdh, void *pubkey) {
bool ecdh_compute_shared(ecdh_t *ecdh, const void *pubkey, void *shared) { bool ecdh_compute_shared(ecdh_t *ecdh, const void *pubkey, void *shared) {
EC_POINT *point = EC_POINT_new(EC_KEY_get0_group(*ecdh)); EC_POINT *point = EC_POINT_new(EC_KEY_get0_group(*ecdh));
if(!point) { if(!point) {
logger(LOG_ERR, "EC_POINT_new() failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "EC_POINT_new() failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
int result = EC_POINT_oct2point(EC_KEY_get0_group(*ecdh), point, pubkey, ECDH_SIZE, NULL); int result = EC_POINT_oct2point(EC_KEY_get0_group(*ecdh), point, pubkey, ECDH_SIZE, NULL);
if(!result) { if(!result) {
logger(LOG_ERR, "Converting binary to EC_POINT failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Converting binary to EC_POINT failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -69,7 +69,7 @@ bool ecdh_compute_shared(ecdh_t *ecdh, const void *pubkey, void *shared) {
*ecdh = NULL; *ecdh = NULL;
if(!result) { if(!result) {
logger(LOG_ERR, "Computing Elliptic Curve Diffie-Hellman shared key failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Computing Elliptic Curve Diffie-Hellman shared key failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }

10
src/openssl/ecdsa.c
View file

@ -37,7 +37,7 @@ bool ecdsa_set_base64_public_key(ecdsa_t *ecdsa, const char *p) {
len = b64decode(p, (char *)pubkey, len); len = b64decode(p, (char *)pubkey, len);
if(!o2i_ECPublicKey(ecdsa, &ppubkey, len)) { if(!o2i_ECPublicKey(ecdsa, &ppubkey, len)) {
logger(LOG_DEBUG, "o2i_ECPublicKey failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_DEBUG, "o2i_ECPublicKey failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -64,7 +64,7 @@ bool ecdsa_read_pem_public_key(ecdsa_t *ecdsa, FILE *fp) {
if(*ecdsa) if(*ecdsa)
return true; return true;
logger(LOG_ERR, "Unable to read ECDSA public key: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to read ECDSA public key: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -74,7 +74,7 @@ bool ecdsa_read_pem_private_key(ecdsa_t *ecdsa, FILE *fp) {
if(*ecdsa) if(*ecdsa)
return true; return true;
logger(LOG_ERR, "Unable to read ECDSA private key: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to read ECDSA private key: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -93,7 +93,7 @@ bool ecdsa_sign(ecdsa_t *ecdsa, const void *in, size_t len, void *sig) {
memset(sig, 0, siglen); memset(sig, 0, siglen);
if(!ECDSA_sign(0, hash, sizeof hash, sig, &siglen, *ecdsa)) { if(!ECDSA_sign(0, hash, sizeof hash, sig, &siglen, *ecdsa)) {
logger(LOG_DEBUG, "ECDSA_sign() failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_DEBUG, "ECDSA_sign() failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -107,7 +107,7 @@ bool ecdsa_verify(ecdsa_t *ecdsa, const void *in, size_t len, const void *sig) {
SHA512(in, len, hash); SHA512(in, len, hash);
if(!ECDSA_verify(0, hash, sizeof hash, sig, siglen, *ecdsa)) { if(!ECDSA_verify(0, hash, sizeof hash, sig, siglen, *ecdsa)) {
logger(LOG_DEBUG, "ECDSA_verify() failed: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_DEBUG, "ECDSA_verify() failed: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }

8
src/openssl/rsa.c
View file

@ -55,7 +55,7 @@ bool rsa_read_pem_public_key(rsa_t *rsa, FILE *fp) {
if(*rsa) if(*rsa)
return true; return true;
logger(LOG_ERR, "Unable to read RSA public key: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to read RSA public key: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -65,7 +65,7 @@ bool rsa_read_pem_private_key(rsa_t *rsa, FILE *fp) {
if(*rsa) if(*rsa)
return true; return true;
logger(LOG_ERR, "Unable to read RSA private key: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to read RSA private key: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -77,7 +77,7 @@ bool rsa_public_encrypt(rsa_t *rsa, void *in, size_t len, void *out) {
if(RSA_public_encrypt(len, in, out, *rsa, RSA_NO_PADDING) == len) if(RSA_public_encrypt(len, in, out, *rsa, RSA_NO_PADDING) == len)
return true; return true;
logger(LOG_ERR, "Unable to perform RSA encryption: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to perform RSA encryption: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }
@ -85,7 +85,7 @@ bool rsa_private_decrypt(rsa_t *rsa, void *in, size_t len, void *out) {
if(RSA_private_decrypt(len, in, out, *rsa, RSA_NO_PADDING) == len) if(RSA_private_decrypt(len, in, out, *rsa, RSA_NO_PADDING) == len)
return true; return true;
logger(LOG_ERR, "Unable to perform RSA decryption: %s", ERR_error_string(ERR_get_error(), NULL)); logger(DEBUG_ALWAYS, LOG_ERR, "Unable to perform RSA decryption: %s", ERR_error_string(ERR_get_error(), NULL));
return false; return false;
} }

32
src/process.c
View file

@ -61,7 +61,7 @@ static bool install_service(void) {
manager = OpenSCManager(NULL, NULL, SC_MANAGER_ALL_ACCESS); manager = OpenSCManager(NULL, NULL, SC_MANAGER_ALL_ACCESS);
if(!manager) { if(!manager) {
logger(LOG_ERR, "Could not open service manager: %s", winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open service manager: %s", winerror(GetLastError()));
return false; return false;
} }
@ -93,22 +93,22 @@ static bool install_service(void) {
if(!service) { if(!service) {
DWORD lasterror = GetLastError(); DWORD lasterror = GetLastError();
logger(LOG_ERR, "Could not create %s service: %s", identname, winerror(lasterror)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not create %s service: %s", identname, winerror(lasterror));
if(lasterror != ERROR_SERVICE_EXISTS) if(lasterror != ERROR_SERVICE_EXISTS)
return false; return false;
} }
if(service) { if(service) {
ChangeServiceConfig2(service, SERVICE_CONFIG_DESCRIPTION, &description); ChangeServiceConfig2(service, SERVICE_CONFIG_DESCRIPTION, &description);
logger(LOG_INFO, "%s service installed", identname); logger(DEBUG_ALWAYS, LOG_INFO, "%s service installed", identname);
} else { } else {
service = OpenService(manager, identname, SERVICE_ALL_ACCESS); service = OpenService(manager, identname, SERVICE_ALL_ACCESS);
} }
if(!StartService(service, 0, NULL)) if(!StartService(service, 0, NULL))
logger(LOG_WARNING, "Could not start %s service: %s", identname, winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_WARNING, "Could not start %s service: %s", identname, winerror(GetLastError()));
else else
logger(LOG_INFO, "%s service started", identname); logger(DEBUG_ALWAYS, LOG_INFO, "%s service started", identname);
return true; return true;
} }
@ -119,13 +119,13 @@ DWORD WINAPI controlhandler(DWORD request, DWORD type, LPVOID boe, LPVOID bah) {
SetServiceStatus(statushandle, &status); SetServiceStatus(statushandle, &status);
return NO_ERROR; return NO_ERROR;
case SERVICE_CONTROL_STOP: case SERVICE_CONTROL_STOP:
logger(LOG_NOTICE, "Got %s request", "SERVICE_CONTROL_STOP"); logger(DEBUG_ALWAYS, LOG_NOTICE, "Got %s request", "SERVICE_CONTROL_STOP");
break; break;
case SERVICE_CONTROL_SHUTDOWN: case SERVICE_CONTROL_SHUTDOWN:
logger(LOG_NOTICE, "Got %s request", "SERVICE_CONTROL_SHUTDOWN"); logger(DEBUG_ALWAYS, LOG_NOTICE, "Got %s request", "SERVICE_CONTROL_SHUTDOWN");
break; break;
default: default:
logger(LOG_WARNING, "Got unexpected request %d", request); logger(DEBUG_ALWAYS, LOG_WARNING, "Got unexpected request %d", request);
return ERROR_CALL_NOT_IMPLEMENTED; return ERROR_CALL_NOT_IMPLEMENTED;
} }
@ -150,7 +150,7 @@ VOID WINAPI run_service(DWORD argc, LPTSTR* argv) {
statushandle = RegisterServiceCtrlHandlerEx(identname, controlhandler, NULL); statushandle = RegisterServiceCtrlHandlerEx(identname, controlhandler, NULL);
if (!statushandle) { if (!statushandle) {
logger(LOG_ERR, "System call `%s' failed: %s", "RegisterServiceCtrlHandlerEx", winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "RegisterServiceCtrlHandlerEx", winerror(GetLastError()));
err = 1; err = 1;
} else { } else {
status.dwWaitHint = 30000; status.dwWaitHint = 30000;
@ -183,7 +183,7 @@ bool init_service(void) {
return false; return false;
} }
else else
logger(LOG_ERR, "System call `%s' failed: %s", "StartServiceCtrlDispatcher", winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "StartServiceCtrlDispatcher", winerror(GetLastError()));
} }
return true; return true;
@ -218,7 +218,7 @@ bool detach(void) {
openlogger(identname, use_logfile?LOGMODE_FILE:(do_detach?LOGMODE_SYSLOG:LOGMODE_STDERR)); openlogger(identname, use_logfile?LOGMODE_FILE:(do_detach?LOGMODE_SYSLOG:LOGMODE_STDERR));
logger(LOG_NOTICE, "tincd %s (%s %s) starting, debug level %d", logger(DEBUG_ALWAYS, LOG_NOTICE, "tincd %s (%s %s) starting, debug level %d",
VERSION, __DATE__, __TIME__, debug_level); VERSION, __DATE__, __TIME__, debug_level);
return true; return true;
@ -249,7 +249,7 @@ bool execute_script(const char *name, char **envp) {
} }
#endif #endif
ifdebug(STATUS) logger(LOG_INFO, "Executing script %s", name); logger(DEBUG_STATUS, LOG_INFO, "Executing script %s", name);
#ifdef HAVE_PUTENV #ifdef HAVE_PUTENV
/* Set environment */ /* Set environment */
@ -279,20 +279,20 @@ bool execute_script(const char *name, char **envp) {
if(status != -1) { if(status != -1) {
if(WIFEXITED(status)) { /* Child exited by itself */ if(WIFEXITED(status)) { /* Child exited by itself */
if(WEXITSTATUS(status)) { if(WEXITSTATUS(status)) {
logger(LOG_ERR, "Script %s exited with non-zero status %d", logger(DEBUG_ALWAYS, LOG_ERR, "Script %s exited with non-zero status %d",
name, WEXITSTATUS(status)); name, WEXITSTATUS(status));
return false; return false;
} }
} else if(WIFSIGNALED(status)) { /* Child was killed by a signal */ } else if(WIFSIGNALED(status)) { /* Child was killed by a signal */
logger(LOG_ERR, "Script %s was killed by signal %d (%s)", logger(DEBUG_ALWAYS, LOG_ERR, "Script %s was killed by signal %d (%s)",
name, WTERMSIG(status), strsignal(WTERMSIG(status))); name, WTERMSIG(status), strsignal(WTERMSIG(status)));
return false; return false;
} else { /* Something strange happened */ } else { /* Something strange happened */
logger(LOG_ERR, "Script %s terminated abnormally", name); logger(DEBUG_ALWAYS, LOG_ERR, "Script %s terminated abnormally", name);
return false; return false;
} }
} else { } else {
logger(LOG_ERR, "System call `%s' failed: %s", "system", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "system", strerror(errno));
return false; return false;
} }
#endif #endif

50
src/protocol.c
View file

@ -80,19 +80,12 @@ bool send_request(connection_t *c, const char *format, ...) {
va_end(args); va_end(args);
if(len < 0 || len > MAXBUFSIZE - 1) { if(len < 0 || len > MAXBUFSIZE - 1) {
logger(LOG_ERR, "Output buffer overflow while sending request to %s (%s)", logger(DEBUG_ALWAYS, LOG_ERR, "Output buffer overflow while sending request to %s (%s)",
c->name, c->hostname); c->name, c->hostname);
return false; return false;
} }
ifdebug(PROTOCOL) { logger(DEBUG_META, LOG_DEBUG, "Sending %s to %s (%s): %s", request_name[atoi(request)], c->name, c->hostname, request);
ifdebug(META)
logger(LOG_DEBUG, "Sending %s to %s (%s): %s",
request_name[atoi(request)], c->name, c->hostname, request);
else
logger(LOG_DEBUG, "Sending %s to %s (%s)", request_name[atoi(request)],
c->name, c->hostname);
}
request[len++] = '\n'; request[len++] = '\n';
@ -105,14 +98,7 @@ bool send_request(connection_t *c, const char *format, ...) {
void forward_request(connection_t *from, char *request) { void forward_request(connection_t *from, char *request) {
/* Note: request is not zero terminated anymore after a call to this function! */ /* Note: request is not zero terminated anymore after a call to this function! */
ifdebug(PROTOCOL) { logger(DEBUG_META, LOG_DEBUG, "Forwarding %s from %s (%s): %s", request_name[atoi(request)], from->name, from->hostname, request);
ifdebug(META)
logger(LOG_DEBUG, "Forwarding %s from %s (%s): %s",
request_name[atoi(request)], from->name, from->hostname, request);
else
logger(LOG_DEBUG, "Forwarding %s from %s (%s)",
request_name[atoi(request)], from->name, from->hostname);
}
int len = strlen(request); int len = strlen(request);
request[len++] = '\n'; request[len++] = '\n';
@ -124,41 +110,25 @@ bool receive_request(connection_t *c, char *request) {
if(reqno || *request == '0') { if(reqno || *request == '0') {
if((reqno < 0) || (reqno >= LAST) || !request_handlers[reqno]) { if((reqno < 0) || (reqno >= LAST) || !request_handlers[reqno]) {
ifdebug(META) logger(DEBUG_META, LOG_DEBUG, "Unknown request from %s (%s): %s", c->name, c->hostname, request);
logger(LOG_DEBUG, "Unknown request from %s (%s): %s",
c->name, c->hostname, request);
else
logger(LOG_ERR, "Unknown request from %s (%s)",
c->name, c->hostname);
return false; return false;
} else { } else {
ifdebug(PROTOCOL) { logger(DEBUG_META, LOG_DEBUG, "Got %s from %s (%s): %s", request_name[reqno], c->name, c->hostname, request);
ifdebug(META)
logger(LOG_DEBUG, "Got %s from %s (%s): %s",
request_name[reqno], c->name, c->hostname, request);
else
logger(LOG_DEBUG, "Got %s from %s (%s)",
request_name[reqno], c->name, c->hostname);
}
} }
if((c->allow_request != ALL) && (c->allow_request != reqno)) { if((c->allow_request != ALL) && (c->allow_request != reqno)) {
logger(LOG_ERR, "Unauthorized request from %s (%s)", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Unauthorized request from %s (%s)", c->name, c->hostname);
c->hostname);
return false; return false;
} }
if(!request_handlers[reqno](c, request)) { if(!request_handlers[reqno](c, request)) {
/* Something went wrong. Probably scriptkiddies. Terminate. */ /* Something went wrong. Probably scriptkiddies. Terminate. */
logger(LOG_ERR, "Error while processing %s from %s (%s)", logger(DEBUG_ALWAYS, LOG_ERR, "Error while processing %s from %s (%s)", request_name[reqno], c->name, c->hostname);
request_name[reqno], c->name, c->hostname);
return false; return false;
} }
} else { } else {
logger(LOG_ERR, "Bogus data received from %s (%s)", logger(DEBUG_ALWAYS, LOG_ERR, "Bogus data received from %s (%s)", c->name, c->hostname);
c->name, c->hostname);
return false; return false;
} }
@ -184,7 +154,7 @@ bool seen_request(char *request) {
p.request = request; p.request = request;
if(splay_search(past_request_tree, &p)) { if(splay_search(past_request_tree, &p)) {
ifdebug(SCARY_THINGS) logger(LOG_DEBUG, "Already seen request"); logger(DEBUG_SCARY_THINGS, LOG_DEBUG, "Already seen request");
return true; return true;
} else { } else {
new = xmalloc(sizeof *new); new = xmalloc(sizeof *new);
@ -213,7 +183,7 @@ static void age_past_requests(int fd, short events, void *data) {
} }
if(left || deleted) if(left || deleted)
ifdebug(SCARY_THINGS) logger(LOG_DEBUG, "Aging past requests: deleted %d, left %d", logger(DEBUG_SCARY_THINGS, LOG_DEBUG, "Aging past requests: deleted %d, left %d",
deleted, left); deleted, left);
if(left) if(left)

54
src/protocol_auth.c
View file

@ -61,7 +61,7 @@ bool id_h(connection_t *c, char *request) {
char name[MAX_STRING_SIZE]; char name[MAX_STRING_SIZE];
if(sscanf(request, "%*d " MAX_STRING " %d.%d", name, &c->protocol_major, &c->protocol_minor) < 2) { if(sscanf(request, "%*d " MAX_STRING " %d.%d", name, &c->protocol_major, &c->protocol_minor) < 2) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "ID", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "ID", c->name,
c->hostname); c->hostname);
return false; return false;
} }
@ -78,7 +78,7 @@ bool id_h(connection_t *c, char *request) {
/* Check if identity is a valid name */ /* Check if identity is a valid name */
if(!check_id(name)) { if(!check_id(name)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "ID", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "ID", c->name,
c->hostname, "invalid name"); c->hostname, "invalid name");
return false; return false;
} }
@ -87,7 +87,7 @@ bool id_h(connection_t *c, char *request) {
if(c->outgoing) { if(c->outgoing) {
if(strcmp(c->name, name)) { if(strcmp(c->name, name)) {
logger(LOG_ERR, "Peer %s is %s instead of %s", c->hostname, name, logger(DEBUG_ALWAYS, LOG_ERR, "Peer %s is %s instead of %s", c->hostname, name,
c->name); c->name);
return false; return false;
} }
@ -100,7 +100,7 @@ bool id_h(connection_t *c, char *request) {
/* Check if version matches */ /* Check if version matches */
if(c->protocol_major != myself->connection->protocol_major) { if(c->protocol_major != myself->connection->protocol_major) {
logger(LOG_ERR, "Peer %s (%s) uses incompatible version %d.%d", logger(DEBUG_ALWAYS, LOG_ERR, "Peer %s (%s) uses incompatible version %d.%d",
c->name, c->hostname, c->protocol_major, c->protocol_minor); c->name, c->hostname, c->protocol_major, c->protocol_minor);
return false; return false;
} }
@ -119,7 +119,7 @@ bool id_h(connection_t *c, char *request) {
init_configuration(&c->config_tree); init_configuration(&c->config_tree);
if(!read_connection_config(c)) { if(!read_connection_config(c)) {
logger(LOG_ERR, "Peer %s had unknown identity (%s)", c->hostname, logger(DEBUG_ALWAYS, LOG_ERR, "Peer %s had unknown identity (%s)", c->hostname,
c->name); c->name);
return false; return false;
} }
@ -183,9 +183,9 @@ bool send_metakey(connection_t *c) {
cipher_set_key_from_rsa(&c->outcipher, key, len, true); cipher_set_key_from_rsa(&c->outcipher, key, len, true);
ifdebug(SCARY_THINGS) { if(debug_level >= DEBUG_SCARY_THINGS) {
bin2hex(key, hexkey, len); bin2hex(key, hexkey, len);
logger(LOG_DEBUG, "Generated random meta key (unencrypted): %s", hexkey); logger(DEBUG_SCARY_THINGS, LOG_DEBUG, "Generated random meta key (unencrypted): %s", hexkey);
} }
/* Encrypt the random data /* Encrypt the random data
@ -196,7 +196,7 @@ bool send_metakey(connection_t *c) {
*/ */
if(!rsa_public_encrypt(&c->rsa, key, len, enckey)) { if(!rsa_public_encrypt(&c->rsa, key, len, enckey)) {
logger(LOG_ERR, "Error during encryption of meta key for %s (%s)", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Error during encryption of meta key for %s (%s)", c->name, c->hostname);
return false; return false;
} }
@ -223,7 +223,7 @@ bool metakey_h(connection_t *c, char *request) {
char key[len]; char key[len];
if(sscanf(request, "%*d %d %d %d %d " MAX_STRING, &cipher, &digest, &maclength, &compression, hexkey) != 5) { if(sscanf(request, "%*d %d %d %d %d " MAX_STRING, &cipher, &digest, &maclength, &compression, hexkey) != 5) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "METAKEY", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "METAKEY", c->name, c->hostname);
return false; return false;
} }
@ -234,31 +234,31 @@ bool metakey_h(connection_t *c, char *request) {
/* Check if the length of the meta key is all right */ /* Check if the length of the meta key is all right */
if(inlen != len) { if(inlen != len) {
logger(LOG_ERR, "Possible intruder %s (%s): %s", c->name, c->hostname, "wrong keylength"); logger(DEBUG_ALWAYS, LOG_ERR, "Possible intruder %s (%s): %s", c->name, c->hostname, "wrong keylength");
return false; return false;
} }
/* Decrypt the meta key */ /* Decrypt the meta key */
if(!rsa_private_decrypt(&myself->connection->rsa, enckey, len, key)) { if(!rsa_private_decrypt(&myself->connection->rsa, enckey, len, key)) {
logger(LOG_ERR, "Error during decryption of meta key for %s (%s)", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Error during decryption of meta key for %s (%s)", c->name, c->hostname);
return false; return false;
} }
ifdebug(SCARY_THINGS) { if(debug_level >= DEBUG_SCARY_THINGS) {
bin2hex(key, hexkey, len); bin2hex(key, hexkey, len);
logger(LOG_DEBUG, "Received random meta key (unencrypted): %s", hexkey); logger(DEBUG_SCARY_THINGS, LOG_DEBUG, "Received random meta key (unencrypted): %s", hexkey);
} }
/* Check and lookup cipher and digest algorithms */ /* Check and lookup cipher and digest algorithms */
if(!cipher_open_by_nid(&c->incipher, cipher) || !cipher_set_key_from_rsa(&c->incipher, key, len, false)) { if(!cipher_open_by_nid(&c->incipher, cipher) || !cipher_set_key_from_rsa(&c->incipher, key, len, false)) {
logger(LOG_ERR, "Error during initialisation of cipher from %s (%s)", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Error during initialisation of cipher from %s (%s)", c->name, c->hostname);
return false; return false;
} }
if(!digest_open_by_nid(&c->indigest, digest, -1)) { if(!digest_open_by_nid(&c->indigest, digest, -1)) {
logger(LOG_ERR, "Error during initialisation of digest from %s (%s)", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Error during initialisation of digest from %s (%s)", c->name, c->hostname);
return false; return false;
} }
@ -296,7 +296,7 @@ bool challenge_h(connection_t *c, char *request) {
char digest[digestlen]; char digest[digestlen];
if(sscanf(request, "%*d " MAX_STRING, buffer) != 1) { if(sscanf(request, "%*d " MAX_STRING, buffer) != 1) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "CHALLENGE", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "CHALLENGE", c->name, c->hostname);
return false; return false;
} }
@ -307,7 +307,7 @@ bool challenge_h(connection_t *c, char *request) {
/* Check if the length of the challenge is all right */ /* Check if the length of the challenge is all right */
if(inlen != len) { if(inlen != len) {
logger(LOG_ERR, "Possible intruder %s (%s): %s", c->name, c->hostname, "wrong challenge length"); logger(DEBUG_ALWAYS, LOG_ERR, "Possible intruder %s (%s): %s", c->name, c->hostname, "wrong challenge length");
return false; return false;
} }
@ -330,7 +330,7 @@ bool chal_reply_h(connection_t *c, char *request) {
char hishash[MAX_STRING_SIZE]; char hishash[MAX_STRING_SIZE];
if(sscanf(request, "%*d " MAX_STRING, hishash) != 1) { if(sscanf(request, "%*d " MAX_STRING, hishash) != 1) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "CHAL_REPLY", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "CHAL_REPLY", c->name,
c->hostname); c->hostname);
return false; return false;
} }
@ -342,7 +342,7 @@ bool chal_reply_h(connection_t *c, char *request) {
/* Check if the length of the hash is all right */ /* Check if the length of the hash is all right */
if(inlen != digest_length(&c->outdigest)) { if(inlen != digest_length(&c->outdigest)) {
logger(LOG_ERR, "Possible intruder %s (%s): %s", c->name, c->hostname, "wrong challenge reply length"); logger(DEBUG_ALWAYS, LOG_ERR, "Possible intruder %s (%s): %s", c->name, c->hostname, "wrong challenge reply length");
return false; return false;
} }
@ -350,7 +350,7 @@ bool chal_reply_h(connection_t *c, char *request) {
/* Verify the hash */ /* Verify the hash */
if(!digest_verify(&c->outdigest, c->hischallenge, rsa_size(&c->rsa), hishash)) { if(!digest_verify(&c->outdigest, c->hischallenge, rsa_size(&c->rsa), hishash)) {
logger(LOG_ERR, "Possible intruder %s (%s): %s", c->name, c->hostname, "wrong challenge reply"); logger(DEBUG_ALWAYS, LOG_ERR, "Possible intruder %s (%s): %s", c->name, c->hostname, "wrong challenge reply");
return false; return false;
} }
@ -451,16 +451,16 @@ static bool upgrade_h(connection_t *c, char *request) {
char pubkey[MAX_STRING_SIZE]; char pubkey[MAX_STRING_SIZE];
if(sscanf(request, "%*d " MAX_STRING, pubkey) != 1) { if(sscanf(request, "%*d " MAX_STRING, pubkey) != 1) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "ACK", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "ACK", c->name, c->hostname);
return false; return false;
} }
if(ecdsa_active(&c->ecdsa) || read_ecdsa_public_key(c)) { if(ecdsa_active(&c->ecdsa) || read_ecdsa_public_key(c)) {
logger(LOG_INFO, "Already have ECDSA public key from %s (%s), not upgrading.", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_INFO, "Already have ECDSA public key from %s (%s), not upgrading.", c->name, c->hostname);
return false; return false;
} }
logger(LOG_INFO, "Got ECDSA public key from %s (%s), upgrading!", c->name, c->hostname); logger(DEBUG_ALWAYS, LOG_INFO, "Got ECDSA public key from %s (%s), upgrading!", c->name, c->hostname);
append_config_file(c->name, "ECDSAPublicKey", pubkey); append_config_file(c->name, "ECDSAPublicKey", pubkey);
c->allow_request = TERMREQ; c->allow_request = TERMREQ;
return send_termreq(c); return send_termreq(c);
@ -478,7 +478,7 @@ bool ack_h(connection_t *c, char *request) {
bool choice; bool choice;
if(sscanf(request, "%*d " MAX_STRING " %d %x", hisport, &weight, &options) != 3) { if(sscanf(request, "%*d " MAX_STRING " %d %x", hisport, &weight, &options) != 3) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "ACK", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "ACK", c->name,
c->hostname); c->hostname);
return false; return false;
} }
@ -494,11 +494,11 @@ bool ack_h(connection_t *c, char *request) {
} else { } else {
if(n->connection) { if(n->connection) {
/* Oh dear, we already have a connection to this node. */ /* Oh dear, we already have a connection to this node. */
ifdebug(CONNECTIONS) logger(LOG_DEBUG, "Established a second connection with %s (%s), closing old connection", n->connection->name, n->connection->hostname); logger(DEBUG_CONNECTIONS, LOG_DEBUG, "Established a second connection with %s (%s), closing old connection", n->connection->name, n->connection->hostname);
if(n->connection->outgoing) { if(n->connection->outgoing) {
if(c->outgoing) if(c->outgoing)
logger(LOG_WARNING, "Two outgoing connections to the same node!"); logger(DEBUG_ALWAYS, LOG_WARNING, "Two outgoing connections to the same node!");
else else
c->outgoing = n->connection->outgoing; c->outgoing = n->connection->outgoing;
@ -540,7 +540,7 @@ bool ack_h(connection_t *c, char *request) {
c->allow_request = ALL; c->allow_request = ALL;
c->status.active = true; c->status.active = true;
ifdebug(CONNECTIONS) logger(LOG_NOTICE, "Connection with %s (%s) activated", c->name, logger(DEBUG_CONNECTIONS, LOG_NOTICE, "Connection with %s (%s) activated", c->name,
c->hostname); c->hostname);
/* Send him everything we know */ /* Send him everything we know */

26
src/protocol_edge.c
View file

@ -63,7 +63,7 @@ bool add_edge_h(connection_t *c, char *request) {
if(sscanf(request, "%*d %*x "MAX_STRING" "MAX_STRING" "MAX_STRING" "MAX_STRING" %x %d", if(sscanf(request, "%*d %*x "MAX_STRING" "MAX_STRING" "MAX_STRING" "MAX_STRING" %x %d",
from_name, to_name, to_address, to_port, &options, &weight) != 6) { from_name, to_name, to_address, to_port, &options, &weight) != 6) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "ADD_EDGE", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "ADD_EDGE", c->name,
c->hostname); c->hostname);
return false; return false;
} }
@ -71,7 +71,7 @@ bool add_edge_h(connection_t *c, char *request) {
/* Check if names are valid */ /* Check if names are valid */
if(!check_id(from_name) || !check_id(to_name)) { if(!check_id(from_name) || !check_id(to_name)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "ADD_EDGE", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "ADD_EDGE", c->name,
c->hostname, "invalid name"); c->hostname, "invalid name");
return false; return false;
} }
@ -88,7 +88,7 @@ bool add_edge_h(connection_t *c, char *request) {
from != myself && from != c->node && from != myself && from != c->node &&
to != myself && to != c->node) { to != myself && to != c->node) {
/* ignore indirect edge registrations for tunnelserver */ /* ignore indirect edge registrations for tunnelserver */
ifdebug(PROTOCOL) logger(LOG_WARNING, logger(DEBUG_PROTOCOL, LOG_WARNING,
"Ignoring indirect %s from %s (%s)", "Ignoring indirect %s from %s (%s)",
"ADD_EDGE", c->name, c->hostname); "ADD_EDGE", c->name, c->hostname);
return true; return true;
@ -118,12 +118,12 @@ bool add_edge_h(connection_t *c, char *request) {
if(e) { if(e) {
if(e->weight != weight || e->options != options || sockaddrcmp(&e->address, &address)) { if(e->weight != weight || e->options != options || sockaddrcmp(&e->address, &address)) {
if(from == myself) { if(from == myself) {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) for ourself which does not match existing entry", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) for ourself which does not match existing entry",
"ADD_EDGE", c->name, c->hostname); "ADD_EDGE", c->name, c->hostname);
send_add_edge(c, e); send_add_edge(c, e);
return true; return true;
} else { } else {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) which does not match existing entry", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) which does not match existing entry",
"ADD_EDGE", c->name, c->hostname); "ADD_EDGE", c->name, c->hostname);
edge_del(e); edge_del(e);
graph(); graph();
@ -131,7 +131,7 @@ bool add_edge_h(connection_t *c, char *request) {
} else } else
return true; return true;
} else if(from == myself) { } else if(from == myself) {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) for ourself which does not exist", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) for ourself which does not exist",
"ADD_EDGE", c->name, c->hostname); "ADD_EDGE", c->name, c->hostname);
contradicting_add_edge++; contradicting_add_edge++;
e = new_edge(); e = new_edge();
@ -174,7 +174,7 @@ bool del_edge_h(connection_t *c, char *request) {
node_t *from, *to; node_t *from, *to;
if(sscanf(request, "%*d %*x "MAX_STRING" "MAX_STRING, from_name, to_name) != 2) { if(sscanf(request, "%*d %*x "MAX_STRING" "MAX_STRING, from_name, to_name) != 2) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "DEL_EDGE", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "DEL_EDGE", c->name,
c->hostname); c->hostname);
return false; return false;
} }
@ -182,7 +182,7 @@ bool del_edge_h(connection_t *c, char *request) {
/* Check if names are valid */ /* Check if names are valid */
if(!check_id(from_name) || !check_id(to_name)) { if(!check_id(from_name) || !check_id(to_name)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "DEL_EDGE", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "DEL_EDGE", c->name,
c->hostname, "invalid name"); c->hostname, "invalid name");
return false; return false;
} }
@ -199,20 +199,20 @@ bool del_edge_h(connection_t *c, char *request) {
from != myself && from != c->node && from != myself && from != c->node &&
to != myself && to != c->node) { to != myself && to != c->node) {
/* ignore indirect edge registrations for tunnelserver */ /* ignore indirect edge registrations for tunnelserver */
ifdebug(PROTOCOL) logger(LOG_WARNING, logger(DEBUG_PROTOCOL, LOG_WARNING,
"Ignoring indirect %s from %s (%s)", "Ignoring indirect %s from %s (%s)",
"DEL_EDGE", c->name, c->hostname); "DEL_EDGE", c->name, c->hostname);
return true; return true;
} }
if(!from) { if(!from) {
ifdebug(PROTOCOL) logger(LOG_ERR, "Got %s from %s (%s) which does not appear in the edge tree", logger(DEBUG_PROTOCOL, LOG_ERR, "Got %s from %s (%s) which does not appear in the edge tree",
"DEL_EDGE", c->name, c->hostname); "DEL_EDGE", c->name, c->hostname);
return true; return true;
} }
if(!to) { if(!to) {
ifdebug(PROTOCOL) logger(LOG_ERR, "Got %s from %s (%s) which does not appear in the edge tree", logger(DEBUG_PROTOCOL, LOG_ERR, "Got %s from %s (%s) which does not appear in the edge tree",
"DEL_EDGE", c->name, c->hostname); "DEL_EDGE", c->name, c->hostname);
return true; return true;
} }
@ -222,13 +222,13 @@ bool del_edge_h(connection_t *c, char *request) {
e = lookup_edge(from, to); e = lookup_edge(from, to);
if(!e) { if(!e) {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) which does not appear in the edge tree", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) which does not appear in the edge tree",
"DEL_EDGE", c->name, c->hostname); "DEL_EDGE", c->name, c->hostname);
return true; return true;
} }
if(e->from == myself) { if(e->from == myself) {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) for ourself", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) for ourself",
"DEL_EDGE", c->name, c->hostname); "DEL_EDGE", c->name, c->hostname);
contradicting_del_edge++; contradicting_del_edge++;
send_add_edge(c, e); /* Send back a correction */ send_add_edge(c, e); /* Send back a correction */

48
src/protocol_key.c
View file

@ -56,7 +56,7 @@ bool key_changed_h(connection_t *c, char *request) {
node_t *n; node_t *n;
if(sscanf(request, "%*d %*x " MAX_STRING, name) != 1) { if(sscanf(request, "%*d %*x " MAX_STRING, name) != 1) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "KEY_CHANGED", logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "KEY_CHANGED",
c->name, c->hostname); c->name, c->hostname);
return false; return false;
} }
@ -67,7 +67,7 @@ bool key_changed_h(connection_t *c, char *request) {
n = lookup_node(name); n = lookup_node(name);
if(!n) { if(!n) {
logger(LOG_ERR, "Got %s from %s (%s) origin %s which does not exist", logger(DEBUG_ALWAYS, LOG_ERR, "Got %s from %s (%s) origin %s which does not exist",
"KEY_CHANGED", c->name, c->hostname, name); "KEY_CHANGED", c->name, c->hostname, name);
return true; return true;
} }
@ -94,20 +94,20 @@ bool req_key_h(connection_t *c, char *request) {
int kx_version = 0; int kx_version = 0;
if(sscanf(request, "%*d " MAX_STRING " " MAX_STRING " %d", from_name, to_name, &kx_version) < 2) { if(sscanf(request, "%*d " MAX_STRING " " MAX_STRING " %d", from_name, to_name, &kx_version) < 2) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "REQ_KEY", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "REQ_KEY", c->name,
c->hostname); c->hostname);
return false; return false;
} }
if(!check_id(from_name) || !check_id(to_name)) { if(!check_id(from_name) || !check_id(to_name)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "REQ_KEY", c->name, c->hostname, "invalid name"); logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "REQ_KEY", c->name, c->hostname, "invalid name");
return false; return false;
} }
from = lookup_node(from_name); from = lookup_node(from_name);
if(!from) { if(!from) {
logger(LOG_ERR, "Got %s from %s (%s) origin %s which does not exist in our connection list", logger(DEBUG_ALWAYS, LOG_ERR, "Got %s from %s (%s) origin %s which does not exist in our connection list",
"REQ_KEY", c->name, c->hostname, from_name); "REQ_KEY", c->name, c->hostname, from_name);
return true; return true;
} }
@ -115,7 +115,7 @@ bool req_key_h(connection_t *c, char *request) {
to = lookup_node(to_name); to = lookup_node(to_name);
if(!to) { if(!to) {
logger(LOG_ERR, "Got %s from %s (%s) destination %s which does not exist in our connection list", logger(DEBUG_ALWAYS, LOG_ERR, "Got %s from %s (%s) destination %s which does not exist in our connection list",
"REQ_KEY", c->name, c->hostname, to_name); "REQ_KEY", c->name, c->hostname, to_name);
return true; return true;
} }
@ -124,7 +124,7 @@ bool req_key_h(connection_t *c, char *request) {
if(to == myself) { /* Yes, send our own key back */ if(to == myself) { /* Yes, send our own key back */
if(experimental && kx_version >= 1) { if(experimental && kx_version >= 1) {
logger(LOG_DEBUG, "Got ECDH key request from %s", from->name); logger(DEBUG_ALWAYS, LOG_DEBUG, "Got ECDH key request from %s", from->name);
from->status.ecdh = true; from->status.ecdh = true;
} }
send_ans_key(from); send_ans_key(from);
@ -133,7 +133,7 @@ bool req_key_h(connection_t *c, char *request) {
return true; return true;
if(!to->status.reachable) { if(!to->status.reachable) {
logger(LOG_WARNING, "Got %s from %s (%s) destination %s which is not reachable", logger(DEBUG_ALWAYS, LOG_WARNING, "Got %s from %s (%s) destination %s which is not reachable",
"REQ_KEY", c->name, c->hostname, to_name); "REQ_KEY", c->name, c->hostname, to_name);
return true; return true;
} }
@ -214,20 +214,20 @@ bool ans_key_h(connection_t *c, char *request) {
if(sscanf(request, "%*d "MAX_STRING" "MAX_STRING" "MAX_STRING" %d %d %d %d "MAX_STRING" "MAX_STRING, if(sscanf(request, "%*d "MAX_STRING" "MAX_STRING" "MAX_STRING" %d %d %d %d "MAX_STRING" "MAX_STRING,
from_name, to_name, key, &cipher, &digest, &maclength, from_name, to_name, key, &cipher, &digest, &maclength,
&compression, address, port) < 7) { &compression, address, port) < 7) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "ANS_KEY", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "ANS_KEY", c->name,
c->hostname); c->hostname);
return false; return false;
} }
if(!check_id(from_name) || !check_id(to_name)) { if(!check_id(from_name) || !check_id(to_name)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "ANS_KEY", c->name, c->hostname, "invalid name"); logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "ANS_KEY", c->name, c->hostname, "invalid name");
return false; return false;
} }
from = lookup_node(from_name); from = lookup_node(from_name);
if(!from) { if(!from) {
logger(LOG_ERR, "Got %s from %s (%s) origin %s which does not exist in our connection list", logger(DEBUG_ALWAYS, LOG_ERR, "Got %s from %s (%s) origin %s which does not exist in our connection list",
"ANS_KEY", c->name, c->hostname, from_name); "ANS_KEY", c->name, c->hostname, from_name);
return true; return true;
} }
@ -235,7 +235,7 @@ bool ans_key_h(connection_t *c, char *request) {
to = lookup_node(to_name); to = lookup_node(to_name);
if(!to) { if(!to) {
logger(LOG_ERR, "Got %s from %s (%s) destination %s which does not exist in our connection list", logger(DEBUG_ALWAYS, LOG_ERR, "Got %s from %s (%s) destination %s which does not exist in our connection list",
"ANS_KEY", c->name, c->hostname, to_name); "ANS_KEY", c->name, c->hostname, to_name);
return true; return true;
} }
@ -247,14 +247,14 @@ bool ans_key_h(connection_t *c, char *request) {
return true; return true;
if(!to->status.reachable) { if(!to->status.reachable) {
logger(LOG_WARNING, "Got %s from %s (%s) destination %s which is not reachable", logger(DEBUG_ALWAYS, LOG_WARNING, "Got %s from %s (%s) destination %s which is not reachable",
"ANS_KEY", c->name, c->hostname, to_name); "ANS_KEY", c->name, c->hostname, to_name);
return true; return true;
} }
if(!*address && from->address.sa.sa_family != AF_UNSPEC) { if(!*address && from->address.sa.sa_family != AF_UNSPEC) {
char *address, *port; char *address, *port;
ifdebug(PROTOCOL) logger(LOG_DEBUG, "Appending reflexive UDP address to ANS_KEY from %s to %s", from->name, to->name); logger(DEBUG_PROTOCOL, LOG_DEBUG, "Appending reflexive UDP address to ANS_KEY from %s to %s", from->name, to->name);
sockaddr2str(&from->address, &address, &port); sockaddr2str(&from->address, &address, &port);
send_request(to->nexthop->connection, "%s %s %s", request, address, port); send_request(to->nexthop->connection, "%s %s %s", request, address, port);
free(address); free(address);
@ -268,22 +268,22 @@ bool ans_key_h(connection_t *c, char *request) {
/* Check and lookup cipher and digest algorithms */ /* Check and lookup cipher and digest algorithms */
if(!cipher_open_by_nid(&from->outcipher, cipher)) { if(!cipher_open_by_nid(&from->outcipher, cipher)) {
logger(LOG_ERR, "Node %s (%s) uses unknown cipher!", from->name, from->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Node %s (%s) uses unknown cipher!", from->name, from->hostname);
return false; return false;
} }
if(!digest_open_by_nid(&from->outdigest, digest, maclength)) { if(!digest_open_by_nid(&from->outdigest, digest, maclength)) {
logger(LOG_ERR, "Node %s (%s) uses unknown digest!", from->name, from->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Node %s (%s) uses unknown digest!", from->name, from->hostname);
return false; return false;
} }
if(maclength != digest_length(&from->outdigest)) { if(maclength != digest_length(&from->outdigest)) {
logger(LOG_ERR, "Node %s (%s) uses bogus MAC length!", from->name, from->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Node %s (%s) uses bogus MAC length!", from->name, from->hostname);
return false; return false;
} }
if(compression < 0 || compression > 11) { if(compression < 0 || compression > 11) {
logger(LOG_ERR, "Node %s (%s) uses bogus compression level!", from->name, from->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Node %s (%s) uses bogus compression level!", from->name, from->hostname);
return true; return true;
} }
@ -301,7 +301,7 @@ bool ans_key_h(connection_t *c, char *request) {
if(!node_read_ecdsa_public_key(from)) { if(!node_read_ecdsa_public_key(from)) {
if(!pubkey) { if(!pubkey) {
logger(LOG_ERR, "No ECDSA public key known for %s (%s), cannot verify ECDH key exchange!", from->name, from->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "No ECDSA public key known for %s (%s), cannot verify ECDH key exchange!", from->name, from->hostname);
return true; return true;
} }
@ -315,17 +315,17 @@ bool ans_key_h(connection_t *c, char *request) {
int keylen = b64decode(key + 5, key + 5, sizeof key - 5); int keylen = b64decode(key + 5, key + 5, sizeof key - 5);
if(keylen != ECDH_SIZE + siglen) { if(keylen != ECDH_SIZE + siglen) {
logger(LOG_ERR, "Node %s (%s) uses wrong keylength! %d != %d", from->name, from->hostname, keylen, ECDH_SIZE + siglen); logger(DEBUG_ALWAYS, LOG_ERR, "Node %s (%s) uses wrong keylength! %d != %d", from->name, from->hostname, keylen, ECDH_SIZE + siglen);
return true; return true;
} }
if(ECDH_SHARED_SIZE < cipher_keylength(&from->outcipher)) { if(ECDH_SHARED_SIZE < cipher_keylength(&from->outcipher)) {
logger(LOG_ERR, "ECDH key too short for cipher of %s!", from->name); logger(DEBUG_ALWAYS, LOG_ERR, "ECDH key too short for cipher of %s!", from->name);
return true; return true;
} }
if(!ecdsa_verify(&from->ecdsa, key + 5, ECDH_SIZE, key + 5 + ECDH_SIZE)) { if(!ecdsa_verify(&from->ecdsa, key + 5, ECDH_SIZE, key + 5 + ECDH_SIZE)) {
logger(LOG_ERR, "Possible intruder %s (%s): %s", from->name, from->hostname, "invalid ECDSA signature"); logger(DEBUG_ALWAYS, LOG_ERR, "Possible intruder %s (%s): %s", from->name, from->hostname, "invalid ECDSA signature");
return true; return true;
} }
@ -386,7 +386,7 @@ bool ans_key_h(connection_t *c, char *request) {
keylen = hex2bin(key, key, sizeof key); keylen = hex2bin(key, key, sizeof key);
if(keylen != cipher_keylength(&from->outcipher)) { if(keylen != cipher_keylength(&from->outcipher)) {
logger(LOG_ERR, "Node %s (%s) uses wrong keylength!", from->name, from->hostname); logger(DEBUG_ALWAYS, LOG_ERR, "Node %s (%s) uses wrong keylength!", from->name, from->hostname);
return true; return true;
} }
@ -400,7 +400,7 @@ bool ans_key_h(connection_t *c, char *request) {
from->sent_seqno = 0; from->sent_seqno = 0;
if(*address && *port) { if(*address && *port) {
ifdebug(PROTOCOL) logger(LOG_DEBUG, "Using reflexive UDP address from %s: %s port %s", from->name, address, port); logger(DEBUG_PROTOCOL, LOG_DEBUG, "Using reflexive UDP address from %s: %s port %s", from->name, address, port);
sockaddr_t sa = str2sockaddr(address, port); sockaddr_t sa = str2sockaddr(address, port);
update_node_udp(from, &sa); update_node_udp(from, &sa);
} }

10
src/protocol_misc.c
View file

@ -45,12 +45,12 @@ bool status_h(connection_t *c, char *request) {
char statusstring[MAX_STRING_SIZE]; char statusstring[MAX_STRING_SIZE];
if(sscanf(request, "%*d %d " MAX_STRING, &statusno, statusstring) != 2) { if(sscanf(request, "%*d %d " MAX_STRING, &statusno, statusstring) != 2) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "STATUS", logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "STATUS",
c->name, c->hostname); c->name, c->hostname);
return false; return false;
} }
ifdebug(STATUS) logger(LOG_NOTICE, "Status message from %s (%s): %d: %s", logger(DEBUG_STATUS, LOG_NOTICE, "Status message from %s (%s): %d: %s",
c->name, c->hostname, statusno, statusstring); c->name, c->hostname, statusno, statusstring);
return true; return true;
@ -68,12 +68,12 @@ bool error_h(connection_t *c, char *request) {
char errorstring[MAX_STRING_SIZE]; char errorstring[MAX_STRING_SIZE];
if(sscanf(request, "%*d %d " MAX_STRING, &err, errorstring) != 2) { if(sscanf(request, "%*d %d " MAX_STRING, &err, errorstring) != 2) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "ERROR", logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "ERROR",
c->name, c->hostname); c->name, c->hostname);
return false; return false;
} }
ifdebug(ERROR) logger(LOG_NOTICE, "Error message from %s (%s): %d: %s", logger(DEBUG_ERROR, LOG_NOTICE, "Error message from %s (%s): %d: %s",
c->name, c->hostname, err, errorstring); c->name, c->hostname, err, errorstring);
return false; return false;
@ -132,7 +132,7 @@ bool tcppacket_h(connection_t *c, char *request) {
short int len; short int len;
if(sscanf(request, "%*d %hd", &len) != 1) { if(sscanf(request, "%*d %hd", &len) != 1) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "PACKET", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "PACKET", c->name,
c->hostname); c->hostname);
return false; return false;
} }

28
src/protocol_subnet.c
View file

@ -48,7 +48,7 @@ bool add_subnet_h(connection_t *c, char *request) {
subnet_t s = {NULL}, *new, *old; subnet_t s = {NULL}, *new, *old;
if(sscanf(request, "%*d %*x " MAX_STRING " " MAX_STRING, name, subnetstr) != 2) { if(sscanf(request, "%*d %*x " MAX_STRING " " MAX_STRING, name, subnetstr) != 2) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "ADD_SUBNET", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "ADD_SUBNET", c->name,
c->hostname); c->hostname);
return false; return false;
} }
@ -56,7 +56,7 @@ bool add_subnet_h(connection_t *c, char *request) {
/* Check if owner name is valid */ /* Check if owner name is valid */
if(!check_id(name)) { if(!check_id(name)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "ADD_SUBNET", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "ADD_SUBNET", c->name,
c->hostname, "invalid name"); c->hostname, "invalid name");
return false; return false;
} }
@ -64,7 +64,7 @@ bool add_subnet_h(connection_t *c, char *request) {
/* Check if subnet string is valid */ /* Check if subnet string is valid */
if(!str2net(&s, subnetstr)) { if(!str2net(&s, subnetstr)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "ADD_SUBNET", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "ADD_SUBNET", c->name,
c->hostname, "invalid subnet string"); c->hostname, "invalid subnet string");
return false; return false;
} }
@ -78,7 +78,7 @@ bool add_subnet_h(connection_t *c, char *request) {
if(tunnelserver && owner != myself && owner != c->node) { if(tunnelserver && owner != myself && owner != c->node) {
/* in case of tunnelserver, ignore indirect subnet registrations */ /* in case of tunnelserver, ignore indirect subnet registrations */
ifdebug(PROTOCOL) logger(LOG_WARNING, "Ignoring indirect %s from %s (%s) for %s", logger(DEBUG_PROTOCOL, LOG_WARNING, "Ignoring indirect %s from %s (%s) for %s",
"ADD_SUBNET", c->name, c->hostname, subnetstr); "ADD_SUBNET", c->name, c->hostname, subnetstr);
return true; return true;
} }
@ -97,7 +97,7 @@ bool add_subnet_h(connection_t *c, char *request) {
/* If we don't know this subnet, but we are the owner, retaliate with a DEL_SUBNET */ /* If we don't know this subnet, but we are the owner, retaliate with a DEL_SUBNET */
if(owner == myself) { if(owner == myself) {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) for ourself", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) for ourself",
"ADD_SUBNET", c->name, c->hostname); "ADD_SUBNET", c->name, c->hostname);
s.owner = myself; s.owner = myself;
send_del_subnet(c, &s); send_del_subnet(c, &s);
@ -107,7 +107,7 @@ bool add_subnet_h(connection_t *c, char *request) {
/* In tunnel server mode, we should already know all allowed subnets */ /* In tunnel server mode, we should already know all allowed subnets */
if(tunnelserver) { if(tunnelserver) {
logger(LOG_WARNING, "Ignoring unauthorized %s from %s (%s): %s", logger(DEBUG_ALWAYS, LOG_WARNING, "Ignoring unauthorized %s from %s (%s): %s",
"ADD_SUBNET", c->name, c->hostname, subnetstr); "ADD_SUBNET", c->name, c->hostname, subnetstr);
return true; return true;
} }
@ -115,7 +115,7 @@ bool add_subnet_h(connection_t *c, char *request) {
/* Ignore if strictsubnets is true, but forward it to others */ /* Ignore if strictsubnets is true, but forward it to others */
if(strictsubnets) { if(strictsubnets) {
logger(LOG_WARNING, "Ignoring unauthorized %s from %s (%s): %s", logger(DEBUG_ALWAYS, LOG_WARNING, "Ignoring unauthorized %s from %s (%s): %s",
"ADD_SUBNET", c->name, c->hostname, subnetstr); "ADD_SUBNET", c->name, c->hostname, subnetstr);
forward_request(c, request); forward_request(c, request);
return true; return true;
@ -158,7 +158,7 @@ bool del_subnet_h(connection_t *c, char *request) {
subnet_t s = {NULL}, *find; subnet_t s = {NULL}, *find;
if(sscanf(request, "%*d %*x " MAX_STRING " " MAX_STRING, name, subnetstr) != 2) { if(sscanf(request, "%*d %*x " MAX_STRING " " MAX_STRING, name, subnetstr) != 2) {
logger(LOG_ERR, "Got bad %s from %s (%s)", "DEL_SUBNET", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s)", "DEL_SUBNET", c->name,
c->hostname); c->hostname);
return false; return false;
} }
@ -166,7 +166,7 @@ bool del_subnet_h(connection_t *c, char *request) {
/* Check if owner name is valid */ /* Check if owner name is valid */
if(!check_id(name)) { if(!check_id(name)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "DEL_SUBNET", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "DEL_SUBNET", c->name,
c->hostname, "invalid name"); c->hostname, "invalid name");
return false; return false;
} }
@ -174,7 +174,7 @@ bool del_subnet_h(connection_t *c, char *request) {
/* Check if subnet string is valid */ /* Check if subnet string is valid */
if(!str2net(&s, subnetstr)) { if(!str2net(&s, subnetstr)) {
logger(LOG_ERR, "Got bad %s from %s (%s): %s", "DEL_SUBNET", c->name, logger(DEBUG_ALWAYS, LOG_ERR, "Got bad %s from %s (%s): %s", "DEL_SUBNET", c->name,
c->hostname, "invalid subnet string"); c->hostname, "invalid subnet string");
return false; return false;
} }
@ -188,13 +188,13 @@ bool del_subnet_h(connection_t *c, char *request) {
if(tunnelserver && owner != myself && owner != c->node) { if(tunnelserver && owner != myself && owner != c->node) {
/* in case of tunnelserver, ignore indirect subnet deletion */ /* in case of tunnelserver, ignore indirect subnet deletion */
ifdebug(PROTOCOL) logger(LOG_WARNING, "Ignoring indirect %s from %s (%s) for %s", logger(DEBUG_PROTOCOL, LOG_WARNING, "Ignoring indirect %s from %s (%s) for %s",
"DEL_SUBNET", c->name, c->hostname, subnetstr); "DEL_SUBNET", c->name, c->hostname, subnetstr);
return true; return true;
} }
if(!owner) { if(!owner) {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) for %s which is not in our node tree", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) for %s which is not in our node tree",
"DEL_SUBNET", c->name, c->hostname, name); "DEL_SUBNET", c->name, c->hostname, name);
return true; return true;
} }
@ -206,7 +206,7 @@ bool del_subnet_h(connection_t *c, char *request) {
find = lookup_subnet(owner, &s); find = lookup_subnet(owner, &s);
if(!find) { if(!find) {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) for %s which does not appear in his subnet tree", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) for %s which does not appear in his subnet tree",
"DEL_SUBNET", c->name, c->hostname, name); "DEL_SUBNET", c->name, c->hostname, name);
if(strictsubnets) if(strictsubnets)
forward_request(c, request); forward_request(c, request);
@ -216,7 +216,7 @@ bool del_subnet_h(connection_t *c, char *request) {
/* If we are the owner of this subnet, retaliate with an ADD_SUBNET */ /* If we are the owner of this subnet, retaliate with an ADD_SUBNET */
if(owner == myself) { if(owner == myself) {
ifdebug(PROTOCOL) logger(LOG_WARNING, "Got %s from %s (%s) for ourself", logger(DEBUG_PROTOCOL, LOG_WARNING, "Got %s from %s (%s) for ourself",
"DEL_SUBNET", c->name, c->hostname); "DEL_SUBNET", c->name, c->hostname);
send_add_subnet(c, find); send_add_subnet(c, find);
return true; return true;

24
src/raw_socket_device.c
View file

@ -51,7 +51,7 @@ static bool setup_device(void) {
device_info = "raw socket"; device_info = "raw socket";
if((device_fd = socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL))) < 0) { if((device_fd = socket(PF_PACKET, SOCK_RAW, htons(ETH_P_ALL))) < 0) {
logger(LOG_ERR, "Could not open %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Could not open %s: %s", device_info,
strerror(errno)); strerror(errno));
return false; return false;
} }
@ -65,7 +65,7 @@ static bool setup_device(void) {
strncpy(ifr.ifr_ifrn.ifrn_name, iface, IFNAMSIZ); strncpy(ifr.ifr_ifrn.ifrn_name, iface, IFNAMSIZ);
if(ioctl(device_fd, SIOCGIFINDEX, &ifr)) { if(ioctl(device_fd, SIOCGIFINDEX, &ifr)) {
close(device_fd); close(device_fd);
logger(LOG_ERR, "Can't find interface %s: %s", iface, logger(DEBUG_ALWAYS, LOG_ERR, "Can't find interface %s: %s", iface,
strerror(errno)); strerror(errno));
return false; return false;
} }
@ -76,11 +76,11 @@ static bool setup_device(void) {
sa.sll_ifindex = ifr.ifr_ifindex; sa.sll_ifindex = ifr.ifr_ifindex;
if(bind(device_fd, (struct sockaddr *) &sa, (socklen_t) sizeof sa)) { if(bind(device_fd, (struct sockaddr *) &sa, (socklen_t) sizeof sa)) {
logger(LOG_ERR, "Could not bind %s to %s: %s", device, iface, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not bind %s to %s: %s", device, iface, strerror(errno));
return false; return false;
} }
logger(LOG_INFO, "%s is a %s", device, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s is a %s", device, device_info);
return true; return true;
} }
@ -96,7 +96,7 @@ static bool read_packet(vpn_packet_t *packet) {
int inlen; int inlen;
if((inlen = read(device_fd, packet->data, MTU)) <= 0) { if((inlen = read(device_fd, packet->data, MTU)) <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -105,18 +105,18 @@ static bool read_packet(vpn_packet_t *packet) {
device_total_in += packet->len; device_total_in += packet->len;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Read packet of %d bytes from %s", packet->len, logger(DEBUG_TRAFFIC, LOG_DEBUG, "Read packet of %d bytes from %s", packet->len,
device_info); device_info);
return true; return true;
} }
static bool write_packet(vpn_packet_t *packet) { static bool write_packet(vpn_packet_t *packet) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Writing packet of %d bytes to %s", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Writing packet of %d bytes to %s",
packet->len, device_info); packet->len, device_info);
if(write(device_fd, packet->data, packet->len) < 0) { if(write(device_fd, packet->data, packet->len) < 0) {
logger(LOG_ERR, "Can't write to %s %s: %s", device_info, device, logger(DEBUG_ALWAYS, LOG_ERR, "Can't write to %s %s: %s", device_info, device,
strerror(errno)); strerror(errno));
return false; return false;
} }
@ -127,9 +127,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out);
} }
const devops_t raw_socket_devops = { const devops_t raw_socket_devops = {
@ -143,7 +143,7 @@ const devops_t raw_socket_devops = {
#else #else
static bool not_supported(void) { static bool not_supported(void) {
logger(LOG_ERR, "Raw socket device not supported on this platform"); logger(DEBUG_ALWAYS, LOG_ERR, "Raw socket device not supported on this platform");
return false; return false;
} }

62
src/route.c
View file

@ -101,7 +101,7 @@ static bool ratelimit(int frequency) {
static bool checklength(node_t *source, vpn_packet_t *packet, length_t length) { static bool checklength(node_t *source, vpn_packet_t *packet, length_t length) {
if(packet->len < length) { if(packet->len < length) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Got too short packet from %s (%s)", source->name, source->hostname); logger(DEBUG_TRAFFIC, LOG_WARNING, "Got too short packet from %s (%s)", source->name, source->hostname);
return false; return false;
} else } else
return true; return true;
@ -164,7 +164,7 @@ static void clamp_mss(const node_t *source, const node_t *via, vpn_packet_t *pac
if(oldmss <= newmss) if(oldmss <= newmss)
break; break;
ifdebug(TRAFFIC) logger(LOG_INFO, "Clamping MSS of packet from %s to %s to %d", source->name, via->name, newmss); logger(DEBUG_TRAFFIC, LOG_INFO, "Clamping MSS of packet from %s to %s to %d", source->name, via->name, newmss);
/* Update the MSS value and the checksum */ /* Update the MSS value and the checksum */
packet->data[start + 22 + i] = newmss >> 8; packet->data[start + 22 + i] = newmss >> 8;
@ -197,10 +197,10 @@ static void age_subnets(int fd, short events, void *data) {
next = node->next; next = node->next;
s = node->data; s = node->data;
if(s->expires && s->expires < now) { if(s->expires && s->expires < now) {
ifdebug(TRAFFIC) { if(debug_level >= DEBUG_TRAFFIC) {
char netstr[MAXNETSTR]; char netstr[MAXNETSTR];
if(net2str(netstr, sizeof netstr, s)) if(net2str(netstr, sizeof netstr, s))
logger(LOG_INFO, "Subnet %s expired", netstr); logger(DEBUG_TRAFFIC, LOG_INFO, "Subnet %s expired", netstr);
} }
for(node2 = connection_tree->head; node2; node2 = node2->next) { for(node2 = connection_tree->head; node2; node2 = node2->next) {
@ -230,7 +230,7 @@ static void learn_mac(mac_t *address) {
/* If we don't know this MAC address yet, store it */ /* If we don't know this MAC address yet, store it */
if(!subnet) { if(!subnet) {
ifdebug(TRAFFIC) logger(LOG_INFO, "Learned new MAC address %hx:%hx:%hx:%hx:%hx:%hx", logger(DEBUG_TRAFFIC, LOG_INFO, "Learned new MAC address %hx:%hx:%hx:%hx:%hx:%hx",
address->x[0], address->x[1], address->x[2], address->x[3], address->x[0], address->x[1], address->x[2], address->x[3],
address->x[4], address->x[5]); address->x[4], address->x[5]);
@ -350,11 +350,11 @@ static void fragment_ipv4_packet(node_t *dest, vpn_packet_t *packet) {
todo = ntohs(ip.ip_len) - ip_size; todo = ntohs(ip.ip_len) - ip_size;
if(ether_size + ip_size + todo != packet->len) { if(ether_size + ip_size + todo != packet->len) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Length of packet (%d) doesn't match length in IPv4 header (%d)", packet->len, (int)(ether_size + ip_size + todo)); logger(DEBUG_TRAFFIC, LOG_WARNING, "Length of packet (%d) doesn't match length in IPv4 header (%d)", packet->len, (int)(ether_size + ip_size + todo));
return; return;
} }
ifdebug(TRAFFIC) logger(LOG_INFO, "Fragmenting packet of %d bytes to %s (%s)", packet->len, dest->name, dest->hostname); logger(DEBUG_TRAFFIC, LOG_INFO, "Fragmenting packet of %d bytes to %s (%s)", packet->len, dest->name, dest->hostname);
offset = packet->data + ether_size + ip_size; offset = packet->data + ether_size + ip_size;
maxlen = (dest->mtu - ether_size - ip_size) & ~0x7; maxlen = (dest->mtu - ether_size - ip_size) & ~0x7;
@ -391,7 +391,7 @@ static void route_ipv4_unicast(node_t *source, vpn_packet_t *packet) {
subnet = lookup_subnet_ipv4(&dest); subnet = lookup_subnet_ipv4(&dest);
if(!subnet) { if(!subnet) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Cannot route packet from %s (%s): unknown IPv4 destination address %d.%d.%d.%d", logger(DEBUG_TRAFFIC, LOG_WARNING, "Cannot route packet from %s (%s): unknown IPv4 destination address %d.%d.%d.%d",
source->name, source->hostname, source->name, source->hostname,
dest.x[0], dest.x[0],
dest.x[1], dest.x[1],
@ -403,7 +403,7 @@ static void route_ipv4_unicast(node_t *source, vpn_packet_t *packet) {
} }
if(subnet->owner == source) { if(subnet->owner == source) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Packet looping back to %s (%s)!", source->name, source->hostname); logger(DEBUG_TRAFFIC, LOG_WARNING, "Packet looping back to %s (%s)!", source->name, source->hostname);
return; return;
} }
@ -419,7 +419,7 @@ static void route_ipv4_unicast(node_t *source, vpn_packet_t *packet) {
via = (subnet->owner->via == myself) ? subnet->owner->nexthop : subnet->owner->via; via = (subnet->owner->via == myself) ? subnet->owner->nexthop : subnet->owner->via;
if(via == source) { if(via == source) {
ifdebug(TRAFFIC) logger(LOG_ERR, "Routing loop for packet from %s (%s)!", source->name, source->hostname); logger(DEBUG_TRAFFIC, LOG_ERR, "Routing loop for packet from %s (%s)!", source->name, source->hostname);
return; return;
} }
@ -427,7 +427,7 @@ static void route_ipv4_unicast(node_t *source, vpn_packet_t *packet) {
return route_ipv4_unreachable(source, packet, ICMP_DEST_UNREACH, ICMP_NET_ANO); return route_ipv4_unreachable(source, packet, ICMP_DEST_UNREACH, ICMP_NET_ANO);
if(via && packet->len > MAX(via->mtu, 590) && via != myself) { if(via && packet->len > MAX(via->mtu, 590) && via != myself) {
ifdebug(TRAFFIC) logger(LOG_INFO, "Packet for %s (%s) length %d larger than MTU %d", subnet->owner->name, subnet->owner->hostname, packet->len, via->mtu); logger(DEBUG_TRAFFIC, LOG_INFO, "Packet for %s (%s) length %d larger than MTU %d", subnet->owner->name, subnet->owner->hostname, packet->len, via->mtu);
if(packet->data[20] & 0x40) { if(packet->data[20] & 0x40) {
packet->len = MAX(via->mtu, 590); packet->len = MAX(via->mtu, 590);
route_ipv4_unreachable(source, packet, ICMP_DEST_UNREACH, ICMP_FRAG_NEEDED); route_ipv4_unreachable(source, packet, ICMP_DEST_UNREACH, ICMP_FRAG_NEEDED);
@ -546,7 +546,7 @@ static void route_ipv6_unicast(node_t *source, vpn_packet_t *packet) {
subnet = lookup_subnet_ipv6(&dest); subnet = lookup_subnet_ipv6(&dest);
if(!subnet) { if(!subnet) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Cannot route packet from %s (%s): unknown IPv6 destination address %hx:%hx:%hx:%hx:%hx:%hx:%hx:%hx", logger(DEBUG_TRAFFIC, LOG_WARNING, "Cannot route packet from %s (%s): unknown IPv6 destination address %hx:%hx:%hx:%hx:%hx:%hx:%hx:%hx",
source->name, source->hostname, source->name, source->hostname,
ntohs(dest.x[0]), ntohs(dest.x[0]),
ntohs(dest.x[1]), ntohs(dest.x[1]),
@ -562,7 +562,7 @@ static void route_ipv6_unicast(node_t *source, vpn_packet_t *packet) {
} }
if(subnet->owner == source) { if(subnet->owner == source) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Packet looping back to %s (%s)!", source->name, source->hostname); logger(DEBUG_TRAFFIC, LOG_WARNING, "Packet looping back to %s (%s)!", source->name, source->hostname);
return; return;
} }
@ -575,7 +575,7 @@ static void route_ipv6_unicast(node_t *source, vpn_packet_t *packet) {
via = (subnet->owner->via == myself) ? subnet->owner->nexthop : subnet->owner->via; via = (subnet->owner->via == myself) ? subnet->owner->nexthop : subnet->owner->via;
if(via == source) { if(via == source) {
ifdebug(TRAFFIC) logger(LOG_ERR, "Routing loop for packet from %s (%s)!", source->name, source->hostname); logger(DEBUG_TRAFFIC, LOG_ERR, "Routing loop for packet from %s (%s)!", source->name, source->hostname);
return; return;
} }
@ -583,7 +583,7 @@ static void route_ipv6_unicast(node_t *source, vpn_packet_t *packet) {
return route_ipv6_unreachable(source, packet, ICMP6_DST_UNREACH, ICMP6_DST_UNREACH_ADMIN); return route_ipv6_unreachable(source, packet, ICMP6_DST_UNREACH, ICMP6_DST_UNREACH_ADMIN);
if(via && packet->len > MAX(via->mtu, 1294) && via != myself) { if(via && packet->len > MAX(via->mtu, 1294) && via != myself) {
ifdebug(TRAFFIC) logger(LOG_INFO, "Packet for %s (%s) length %d larger than MTU %d", subnet->owner->name, subnet->owner->hostname, packet->len, via->mtu); logger(DEBUG_TRAFFIC, LOG_INFO, "Packet for %s (%s) length %d larger than MTU %d", subnet->owner->name, subnet->owner->hostname, packet->len, via->mtu);
packet->len = MAX(via->mtu, 1294); packet->len = MAX(via->mtu, 1294);
route_ipv6_unreachable(source, packet, ICMP6_PACKET_TOO_BIG, 0); route_ipv6_unreachable(source, packet, ICMP6_PACKET_TOO_BIG, 0);
return; return;
@ -617,7 +617,7 @@ static void route_neighborsol(node_t *source, vpn_packet_t *packet) {
has_opt = packet->len >= ether_size + ip6_size + ns_size + opt_size + ETH_ALEN; has_opt = packet->len >= ether_size + ip6_size + ns_size + opt_size + ETH_ALEN;
if(source != myself) { if(source != myself) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Got neighbor solicitation request from %s (%s) while in router mode!", source->name, source->hostname); logger(DEBUG_TRAFFIC, LOG_WARNING, "Got neighbor solicitation request from %s (%s) while in router mode!", source->name, source->hostname);
return; return;
} }
@ -637,7 +637,7 @@ static void route_neighborsol(node_t *source, vpn_packet_t *packet) {
if(ns.nd_ns_hdr.icmp6_type != ND_NEIGHBOR_SOLICIT || if(ns.nd_ns_hdr.icmp6_type != ND_NEIGHBOR_SOLICIT ||
(has_opt && opt.nd_opt_type != ND_OPT_SOURCE_LINKADDR)) { (has_opt && opt.nd_opt_type != ND_OPT_SOURCE_LINKADDR)) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Cannot route packet: received unknown type neighbor solicitation request"); logger(DEBUG_TRAFFIC, LOG_WARNING, "Cannot route packet: received unknown type neighbor solicitation request");
return; return;
} }
@ -661,7 +661,7 @@ static void route_neighborsol(node_t *source, vpn_packet_t *packet) {
} }
if(checksum) { if(checksum) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Cannot route packet: checksum error for neighbor solicitation request"); logger(DEBUG_TRAFFIC, LOG_WARNING, "Cannot route packet: checksum error for neighbor solicitation request");
return; return;
} }
@ -670,7 +670,7 @@ static void route_neighborsol(node_t *source, vpn_packet_t *packet) {
subnet = lookup_subnet_ipv6((ipv6_t *) &ns.nd_ns_target); subnet = lookup_subnet_ipv6((ipv6_t *) &ns.nd_ns_target);
if(!subnet) { if(!subnet) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Cannot route packet: neighbor solicitation request for unknown address %hx:%hx:%hx:%hx:%hx:%hx:%hx:%hx", logger(DEBUG_TRAFFIC, LOG_WARNING, "Cannot route packet: neighbor solicitation request for unknown address %hx:%hx:%hx:%hx:%hx:%hx:%hx:%hx",
ntohs(((uint16_t *) &ns.nd_ns_target)[0]), ntohs(((uint16_t *) &ns.nd_ns_target)[0]),
ntohs(((uint16_t *) &ns.nd_ns_target)[1]), ntohs(((uint16_t *) &ns.nd_ns_target)[1]),
ntohs(((uint16_t *) &ns.nd_ns_target)[2]), ntohs(((uint16_t *) &ns.nd_ns_target)[2]),
@ -761,7 +761,7 @@ static void route_arp(node_t *source, vpn_packet_t *packet) {
return; return;
if(source != myself) { if(source != myself) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Got ARP request from %s (%s) while in router mode!", source->name, source->hostname); logger(DEBUG_TRAFFIC, LOG_WARNING, "Got ARP request from %s (%s) while in router mode!", source->name, source->hostname);
return; return;
} }
@ -778,7 +778,7 @@ static void route_arp(node_t *source, vpn_packet_t *packet) {
if(ntohs(arp.arp_hrd) != ARPHRD_ETHER || ntohs(arp.arp_pro) != ETH_P_IP || if(ntohs(arp.arp_hrd) != ARPHRD_ETHER || ntohs(arp.arp_pro) != ETH_P_IP ||
arp.arp_hln != ETH_ALEN || arp.arp_pln != sizeof addr || ntohs(arp.arp_op) != ARPOP_REQUEST) { arp.arp_hln != ETH_ALEN || arp.arp_pln != sizeof addr || ntohs(arp.arp_op) != ARPOP_REQUEST) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Cannot route packet: received unknown type ARP request"); logger(DEBUG_TRAFFIC, LOG_WARNING, "Cannot route packet: received unknown type ARP request");
return; return;
} }
@ -787,7 +787,7 @@ static void route_arp(node_t *source, vpn_packet_t *packet) {
subnet = lookup_subnet_ipv4((ipv4_t *) &arp.arp_tpa); subnet = lookup_subnet_ipv4((ipv4_t *) &arp.arp_tpa);
if(!subnet) { if(!subnet) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Cannot route packet: ARP request for unknown address %d.%d.%d.%d", logger(DEBUG_TRAFFIC, LOG_WARNING, "Cannot route packet: ARP request for unknown address %d.%d.%d.%d",
arp.arp_tpa[0], arp.arp_tpa[1], arp.arp_tpa[2], arp.arp_tpa[0], arp.arp_tpa[1], arp.arp_tpa[2],
arp.arp_tpa[3]); arp.arp_tpa[3]);
return; return;
@ -840,7 +840,7 @@ static void route_mac(node_t *source, vpn_packet_t *packet) {
} }
if(subnet->owner == source) { if(subnet->owner == source) {
ifdebug(TRAFFIC) logger(LOG_WARNING, "Packet looping back to %s (%s)!", source->name, source->hostname); logger(DEBUG_TRAFFIC, LOG_WARNING, "Packet looping back to %s (%s)!", source->name, source->hostname);
return; return;
} }
@ -855,7 +855,7 @@ static void route_mac(node_t *source, vpn_packet_t *packet) {
return; return;
if(via && packet->len > via->mtu && via != myself) { if(via && packet->len > via->mtu && via != myself) {
ifdebug(TRAFFIC) logger(LOG_INFO, "Packet for %s (%s) length %d larger than MTU %d", subnet->owner->name, subnet->owner->hostname, packet->len, via->mtu); logger(DEBUG_TRAFFIC, LOG_INFO, "Packet for %s (%s) length %d larger than MTU %d", subnet->owner->name, subnet->owner->hostname, packet->len, via->mtu);
uint16_t type = packet->data[12] << 8 | packet->data[13]; uint16_t type = packet->data[12] << 8 | packet->data[13];
if(type == ETH_P_IP && packet->len > 590) { if(type == ETH_P_IP && packet->len > 590) {
if(packet->data[20] & 0x40) { if(packet->data[20] & 0x40) {
@ -883,10 +883,14 @@ static void send_pcap(vpn_packet_t *packet) {
connection_t *c = node->data; connection_t *c = node->data;
if(!c->status.pcap) if(!c->status.pcap)
continue; continue;
else
pcap = true; pcap = true;
if(send_request(c, "%d %d %d", CONTROL, REQ_PCAP, packet->len)) int len = packet->len;
send_meta(c, (char *)packet->data, packet->len); if(c->outmaclength && c->outmaclength < len)
len = c->outmaclength;
if(send_request(c, "%d %d %d", CONTROL, REQ_PCAP, len))
send_meta(c, (char *)packet->data, len);
} }
} }
@ -971,7 +975,7 @@ void route(node_t *source, vpn_packet_t *packet) {
break; break;
default: default:
ifdebug(TRAFFIC) logger(LOG_WARNING, "Cannot route packet from %s (%s): unknown type %hx", source->name, source->hostname, type); logger(DEBUG_TRAFFIC, LOG_WARNING, "Cannot route packet from %s (%s): unknown type %hx", source->name, source->hostname, type);
break; break;
} }
} }

32
src/solaris/device.c
View file

@ -51,7 +51,7 @@ static bool setup_device(void) {
device = xstrdup(DEFAULT_DEVICE); device = xstrdup(DEFAULT_DEVICE);
if((device_fd = open(device, O_RDWR | O_NONBLOCK)) < 0) { if((device_fd = open(device, O_RDWR | O_NONBLOCK)) < 0) {
logger(LOG_ERR, "Could not open %s: %s", device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open %s: %s", device, strerror(errno));
return false; return false;
} }
@ -67,7 +67,7 @@ static bool setup_device(void) {
ppa = atoi(ptr); ppa = atoi(ptr);
if((ip_fd = open("/dev/ip", O_RDWR, 0)) < 0) { if((ip_fd = open("/dev/ip", O_RDWR, 0)) < 0) {
logger(LOG_ERR, "Could not open /dev/ip: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open /dev/ip: %s", strerror(errno));
return false; return false;
} }
@ -77,12 +77,12 @@ static bool setup_device(void) {
/* Assign a new PPA and get its unit number. */ /* Assign a new PPA and get its unit number. */
if((ppa = ioctl(device_fd, TUNNEWPPA, ppa)) < 0) { if((ppa = ioctl(device_fd, TUNNEWPPA, ppa)) < 0) {
logger(LOG_ERR, "Can't assign new interface: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Can't assign new interface: %s", strerror(errno));
return false; return false;
} }
if((if_fd = open(device, O_RDWR, 0)) < 0) { if((if_fd = open(device, O_RDWR, 0)) < 0) {
logger(LOG_ERR, "Could not open %s twice: %s", device, logger(DEBUG_ALWAYS, LOG_ERR, "Could not open %s twice: %s", device,
strerror(errno)); strerror(errno));
return false; return false;
} }
@ -92,18 +92,18 @@ static bool setup_device(void) {
#endif #endif
if(ioctl(if_fd, I_PUSH, "ip") < 0) { if(ioctl(if_fd, I_PUSH, "ip") < 0) {
logger(LOG_ERR, "Can't push IP module: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Can't push IP module: %s", strerror(errno));
return false; return false;
} }
/* Assign ppa according to the unit number returned by tun device */ /* Assign ppa according to the unit number returned by tun device */
if(ioctl(if_fd, IF_UNITSEL, (char *) &ppa) < 0) { if(ioctl(if_fd, IF_UNITSEL, (char *) &ppa) < 0) {
logger(LOG_ERR, "Can't set PPA %d: %s", ppa, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Can't set PPA %d: %s", ppa, strerror(errno));
return false; return false;
} }
if(ioctl(ip_fd, I_LINK, if_fd) < 0) { if(ioctl(ip_fd, I_LINK, if_fd) < 0) {
logger(LOG_ERR, "Can't link TUN device to IP: %s", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Can't link TUN device to IP: %s", strerror(errno));
return false; return false;
} }
@ -112,7 +112,7 @@ static bool setup_device(void) {
device_info = "Solaris tun device"; device_info = "Solaris tun device";
logger(LOG_INFO, "%s is a %s", device, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s is a %s", device, device_info);
return true; return true;
} }
@ -130,7 +130,7 @@ static bool read_packet(vpn_packet_t *packet) {
int inlen; int inlen;
if((inlen = read(device_fd, packet->data + 14, MTU - 14)) <= 0) { if((inlen = read(device_fd, packet->data + 14, MTU - 14)) <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -145,7 +145,7 @@ static bool read_packet(vpn_packet_t *packet) {
packet->data[13] = 0xDD; packet->data[13] = 0xDD;
break; break;
default: default:
ifdebug(TRAFFIC) logger(LOG_ERR, logger(DEBUG_TRAFFIC, LOG_ERR,
"Unknown IP version %d while reading packet from %s %s", "Unknown IP version %d while reading packet from %s %s",
packet->data[14] >> 4, device_info, device); packet->data[14] >> 4, device_info, device);
return false; return false;
@ -155,18 +155,18 @@ static bool read_packet(vpn_packet_t *packet) {
device_total_in += packet->len; device_total_in += packet->len;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Read packet of %d bytes from %s", packet->len, logger(DEBUG_TRAFFIC, LOG_DEBUG, "Read packet of %d bytes from %s", packet->len,
device_info); device_info);
return true; return true;
} }
static bool write_packet(vpn_packet_t *packet) { static bool write_packet(vpn_packet_t *packet) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Writing packet of %d bytes to %s", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Writing packet of %d bytes to %s",
packet->len, device_info); packet->len, device_info);
if(write(device_fd, packet->data + 14, packet->len - 14) < 0) { if(write(device_fd, packet->data + 14, packet->len - 14) < 0) {
logger(LOG_ERR, "Can't write to %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Can't write to %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
return false; return false;
} }
@ -177,9 +177,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out);
} }
const devops_t os_devops = { const devops_t os_devops = {

5
src/sptps_test.c
View file

@ -25,7 +25,12 @@
#include "sptps.h" #include "sptps.h"
#include "utils.h" #include "utils.h"
// Symbols necessary to link with logger.o
char *logfilename; char *logfilename;
char *connection_tree;
char *send_request;
char *send_meta;
ecdsa_t mykey, hiskey; ecdsa_t mykey, hiskey;
static bool send_data(void *handle, const char *data, size_t len) { static bool send_data(void *handle, const char *data, size_t len) {

6
src/subnet.c
View file

@ -135,7 +135,7 @@ int subnet_compare(const subnet_t *a, const subnet_t *b) {
case SUBNET_IPV6: case SUBNET_IPV6:
return subnet_compare_ipv6(a, b); return subnet_compare_ipv6(a, b);
default: default:
logger(LOG_ERR, "subnet_compare() was called with unknown subnet type %d, exitting!", logger(DEBUG_ALWAYS, LOG_ERR, "subnet_compare() was called with unknown subnet type %d, exitting!",
a->type); a->type);
exit(0); exit(0);
} }
@ -274,7 +274,7 @@ bool str2net(subnet_t *subnet, const char *subnetstr) {
bool net2str(char *netstr, int len, const subnet_t *subnet) { bool net2str(char *netstr, int len, const subnet_t *subnet) {
if(!netstr || !subnet) { if(!netstr || !subnet) {
logger(LOG_ERR, "net2str() was called with netstr=%p, subnet=%p!", netstr, subnet); logger(DEBUG_ALWAYS, LOG_ERR, "net2str() was called with netstr=%p, subnet=%p!", netstr, subnet);
return false; return false;
} }
@ -315,7 +315,7 @@ bool net2str(char *netstr, int len, const subnet_t *subnet) {
break; break;
default: default:
logger(LOG_ERR, logger(DEBUG_ALWAYS, LOG_ERR,
"net2str() was called with unknown subnet type %d, exiting!", "net2str() was called with unknown subnet type %d, exiting!",
subnet->type); subnet->type);
exit(0); exit(0);

46
src/tincctl.c
View file

@ -1,6 +1,6 @@
/* /*
tincctl.c -- Controlling a running tincd tincctl.c -- Controlling a running tincd
Copyright (C) 2007-2011 Guus Sliepen <guus@tinc-vpn.org> Copyright (C) 2007-2012 Guus Sliepen <guus@tinc-vpn.org>
This program is free software; you can redistribute it and/or modify This program is free software; you can redistribute it and/or modify
it under the terms of the GNU General Public License as published by it under the terms of the GNU General Public License as published by
@ -94,7 +94,8 @@ static void usage(bool status) {
#ifdef HAVE_CURSES #ifdef HAVE_CURSES
" top Show real-time statistics\n" " top Show real-time statistics\n"
#endif #endif
" pcap Dump traffic in pcap format\n" " pcap [snaplen] Dump traffic in pcap format [up to snaplen bytes per packet]\n"
" log [level] Dump log output [up to the specified level]\n"
"\n"); "\n");
printf("Report bugs to tinc@tinc-vpn.org.\n"); printf("Report bugs to tinc@tinc-vpn.org.\n");
} }
@ -147,7 +148,7 @@ static bool parse_options(int argc, char **argv) {
return true; return true;
} }
FILE *ask_and_open(const char *filename, const char *what, const char *mode) { static FILE *ask_and_open(const char *filename, const char *what, const char *mode) {
FILE *r; FILE *r;
char *directory; char *directory;
char buf[PATH_MAX]; char buf[PATH_MAX];
@ -390,7 +391,7 @@ bool recvline(int fd, char *line, size_t len) {
return true; return true;
} }
bool recvdata(int fd, char *data, size_t len) { static bool recvdata(int fd, char *data, size_t len) {
while(blen < len) { while(blen < len) {
int result = recv(fd, buffer + blen, sizeof buffer - blen, 0); int result = recv(fd, buffer + blen, sizeof buffer - blen, 0);
if(result == -1 && errno == EINTR) if(result == -1 && errno == EINTR)
@ -436,8 +437,8 @@ bool sendline(int fd, char *format, ...) {
return true; return true;
} }
void pcap(int fd, FILE *out) { static void pcap(int fd, FILE *out, int snaplen) {
sendline(fd, "%d %d", CONTROL, REQ_PCAP); sendline(fd, "%d %d %d", CONTROL, REQ_PCAP, snaplen);
char data[9018]; char data[9018];
struct { struct {
@ -452,7 +453,7 @@ void pcap(int fd, FILE *out) {
0xa1b2c3d4, 0xa1b2c3d4,
2, 4, 2, 4,
0, 0, 0, 0,
sizeof data, snaplen ?: sizeof data,
1, 1,
}; };
@ -487,6 +488,24 @@ void pcap(int fd, FILE *out) {
} }
} }
static void logcontrol(int fd, FILE *out, int level) {
sendline(fd, "%d %d %d", CONTROL, REQ_LOG, level);
char data[1024];
char line[32];
while(recvline(fd, line, sizeof line)) {
int code, req, len;
int n = sscanf(line, "%d %d %d", &code, &req, &len);
if(n != 3 || code != CONTROL || req != REQ_LOG || len < 0 || len > sizeof data)
break;
if(!recvdata(fd, data, len))
break;
fwrite(data, len, 1, out);
fputc('\n', out);
fflush(out);
}
}
#ifdef HAVE_MINGW #ifdef HAVE_MINGW
static bool remove_service(void) { static bool remove_service(void) {
SC_HANDLE manager = NULL; SC_HANDLE manager = NULL;
@ -539,7 +558,7 @@ int main(int argc, char *argv[]) {
if(show_version) { if(show_version) {
printf("%s version %s (built %s %s, protocol %d.%d)\n", PACKAGE, printf("%s version %s (built %s %s, protocol %d.%d)\n", PACKAGE,
VERSION, __DATE__, __TIME__, PROT_MAJOR, PROT_MINOR); VERSION, __DATE__, __TIME__, PROT_MAJOR, PROT_MINOR);
printf("Copyright (C) 1998-2009 Ivo Timmermans, Guus Sliepen and others.\n" printf("Copyright (C) 1998-2012 Ivo Timmermans, Guus Sliepen and others.\n"
"See the AUTHORS file for a complete list.\n\n" "See the AUTHORS file for a complete list.\n\n"
"tinc comes with ABSOLUTELY NO WARRANTY. This is free software,\n" "tinc comes with ABSOLUTELY NO WARRANTY. This is free software,\n"
"and you are welcome to redistribute it under certain conditions;\n" "and you are welcome to redistribute it under certain conditions;\n"
@ -562,7 +581,7 @@ int main(int argc, char *argv[]) {
// First handle commands that don't involve connecting to a running tinc daemon. // First handle commands that don't involve connecting to a running tinc daemon.
if(!strcasecmp(argv[optind], "generate-rsa-keys")) { if(!strcasecmp(argv[optind], "generate-rsa-keys")) {
return !rsa_keygen(optind > argc ? atoi(argv[optind + 1]) : 2048); return !rsa_keygen(optind < argc - 1 ? atoi(argv[optind + 1]) : 2048);
} }
if(!strcasecmp(argv[optind], "generate-ecdsa-keys")) { if(!strcasecmp(argv[optind], "generate-ecdsa-keys")) {
@ -570,7 +589,7 @@ int main(int argc, char *argv[]) {
} }
if(!strcasecmp(argv[optind], "generate-keys")) { if(!strcasecmp(argv[optind], "generate-keys")) {
return !(rsa_keygen(optind > argc ? atoi(argv[optind + 1]) : 2048) && ecdsa_keygen()); return !(rsa_keygen(optind < argc - 1 ? atoi(argv[optind + 1]) : 2048) && ecdsa_keygen());
} }
if(!strcasecmp(argv[optind], "start")) { if(!strcasecmp(argv[optind], "start")) {
@ -842,7 +861,12 @@ int main(int argc, char *argv[]) {
#endif #endif
if(!strcasecmp(argv[optind], "pcap")) { if(!strcasecmp(argv[optind], "pcap")) {
pcap(fd, stdout); pcap(fd, stdout, optind < argc - 1 ? atoi(argv[optind + 1]) : 0);
return 0;
}
if(!strcasecmp(argv[optind], "log")) {
logcontrol(fd, stdout, optind < argc - 1 ? atoi(argv[optind + 1]) : -1);
return 0; return 0;
} }

36
src/tincd.c
View file

@ -162,7 +162,7 @@ static bool parse_options(int argc, char **argv) {
case 'L': /* no detach */ case 'L': /* no detach */
#ifndef HAVE_MLOCKALL #ifndef HAVE_MLOCKALL
logger(LOG_ERR, "%s not supported on this platform", "mlockall()"); logger(DEBUG_ALWAYS, LOG_ERR, "%s not supported on this platform", "mlockall()");
return false; return false;
#else #else
do_mlock = true; do_mlock = true;
@ -276,7 +276,7 @@ static void make_names(void) {
if(!confbase) if(!confbase)
xasprintf(&confbase, CONFDIR "/tinc/%s", netname); xasprintf(&confbase, CONFDIR "/tinc/%s", netname);
else else
logger(LOG_INFO, "Both netname and configuration directory given, using the latter..."); logger(DEBUG_ALWAYS, LOG_INFO, "Both netname and configuration directory given, using the latter...");
} else { } else {
if(!confbase) if(!confbase)
xasprintf(&confbase, CONFDIR "/tinc"); xasprintf(&confbase, CONFDIR "/tinc");
@ -294,11 +294,11 @@ static void free_names(void) {
static bool drop_privs(void) { static bool drop_privs(void) {
#ifdef HAVE_MINGW #ifdef HAVE_MINGW
if (switchuser) { if (switchuser) {
logger(LOG_ERR, "%s not supported on this platform", "-U"); logger(DEBUG_ALWAYS, LOG_ERR, "%s not supported on this platform", "-U");
return false; return false;
} }
if (do_chroot) { if (do_chroot) {
logger(LOG_ERR, "%s not supported on this platform", "-R"); logger(DEBUG_ALWAYS, LOG_ERR, "%s not supported on this platform", "-R");
return false; return false;
} }
#else #else
@ -306,13 +306,13 @@ static bool drop_privs(void) {
if (switchuser) { if (switchuser) {
struct passwd *pw = getpwnam(switchuser); struct passwd *pw = getpwnam(switchuser);
if (!pw) { if (!pw) {
logger(LOG_ERR, "unknown user `%s'", switchuser); logger(DEBUG_ALWAYS, LOG_ERR, "unknown user `%s'", switchuser);
return false; return false;
} }
uid = pw->pw_uid; uid = pw->pw_uid;
if (initgroups(switchuser, pw->pw_gid) != 0 || if (initgroups(switchuser, pw->pw_gid) != 0 ||
setgid(pw->pw_gid) != 0) { setgid(pw->pw_gid) != 0) {
logger(LOG_ERR, "System call `%s' failed: %s", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s",
"initgroups", strerror(errno)); "initgroups", strerror(errno));
return false; return false;
} }
@ -322,7 +322,7 @@ static bool drop_privs(void) {
if (do_chroot) { if (do_chroot) {
tzset(); /* for proper timestamps in logs */ tzset(); /* for proper timestamps in logs */
if (chroot(confbase) != 0 || chdir("/") != 0) { if (chroot(confbase) != 0 || chdir("/") != 0) {
logger(LOG_ERR, "System call `%s' failed: %s", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s",
"chroot", strerror(errno)); "chroot", strerror(errno));
return false; return false;
} }
@ -331,7 +331,7 @@ static bool drop_privs(void) {
} }
if (switchuser) if (switchuser)
if (setuid(uid) != 0) { if (setuid(uid) != 0) {
logger(LOG_ERR, "System call `%s' failed: %s", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s",
"setuid", strerror(errno)); "setuid", strerror(errno));
return false; return false;
} }
@ -375,7 +375,7 @@ int main(int argc, char **argv) {
#ifdef HAVE_MINGW #ifdef HAVE_MINGW
if(WSAStartup(MAKEWORD(2, 2), &wsa_state)) { if(WSAStartup(MAKEWORD(2, 2), &wsa_state)) {
logger(LOG_ERR, "System call `%s' failed: %s", "WSAStartup", winerror(GetLastError())); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "WSAStartup", winerror(GetLastError()));
return 1; return 1;
} }
#endif #endif
@ -383,7 +383,7 @@ int main(int argc, char **argv) {
openlogger("tinc", use_logfile?LOGMODE_FILE:LOGMODE_STDERR); openlogger("tinc", use_logfile?LOGMODE_FILE:LOGMODE_STDERR);
if(!event_init()) { if(!event_init()) {
logger(LOG_ERR, "Error initializing libevent!"); logger(DEBUG_ALWAYS, LOG_ERR, "Error initializing libevent!");
return 1; return 1;
} }
@ -401,7 +401,7 @@ int main(int argc, char **argv) {
#ifdef HAVE_LZO #ifdef HAVE_LZO
if(lzo_init() != LZO_E_OK) { if(lzo_init() != LZO_E_OK) {
logger(LOG_ERR, "Error initializing LZO compressor!"); logger(DEBUG_ALWAYS, LOG_ERR, "Error initializing LZO compressor!");
return 1; return 1;
} }
#endif #endif
@ -427,7 +427,7 @@ int main2(int argc, char **argv) {
* This has to be done after daemon()/fork() so it works for child. * This has to be done after daemon()/fork() so it works for child.
* No need to do that in parent as it's very short-lived. */ * No need to do that in parent as it's very short-lived. */
if(do_mlock && mlockall(MCL_CURRENT | MCL_FUTURE) != 0) { if(do_mlock && mlockall(MCL_CURRENT | MCL_FUTURE) != 0) {
logger(LOG_ERR, "System call `%s' failed: %s", "mlockall", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "mlockall",
strerror(errno)); strerror(errno));
return 1; return 1;
} }
@ -450,24 +450,24 @@ int main2(int argc, char **argv) {
if(get_config_string(lookup_config(config_tree, "ProcessPriority"), &priority)) { if(get_config_string(lookup_config(config_tree, "ProcessPriority"), &priority)) {
if(!strcasecmp(priority, "Normal")) { if(!strcasecmp(priority, "Normal")) {
if (setpriority(NORMAL_PRIORITY_CLASS) != 0) { if (setpriority(NORMAL_PRIORITY_CLASS) != 0) {
logger(LOG_ERR, "System call `%s' failed: %s", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s",
"setpriority", strerror(errno)); "setpriority", strerror(errno));
goto end; goto end;
} }
} else if(!strcasecmp(priority, "Low")) { } else if(!strcasecmp(priority, "Low")) {
if (setpriority(BELOW_NORMAL_PRIORITY_CLASS) != 0) { if (setpriority(BELOW_NORMAL_PRIORITY_CLASS) != 0) {
logger(LOG_ERR, "System call `%s' failed: %s", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s",
"setpriority", strerror(errno)); "setpriority", strerror(errno));
goto end; goto end;
} }
} else if(!strcasecmp(priority, "High")) { } else if(!strcasecmp(priority, "High")) {
if (setpriority(HIGH_PRIORITY_CLASS) != 0) { if (setpriority(HIGH_PRIORITY_CLASS) != 0) {
logger(LOG_ERR, "System call `%s' failed: %s", logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s",
"setpriority", strerror(errno)); "setpriority", strerror(errno));
goto end; goto end;
} }
} else { } else {
logger(LOG_ERR, "Invalid priority `%s`!", priority); logger(DEBUG_ALWAYS, LOG_ERR, "Invalid priority `%s`!", priority);
goto end; goto end;
} }
} }
@ -482,7 +482,7 @@ int main2(int argc, char **argv) {
/* Shutdown properly. */ /* Shutdown properly. */
ifdebug(CONNECTIONS) if(debug_level >= DEBUG_CONNECTIONS)
devops.dump_stats(); devops.dump_stats();
close_network_connections(); close_network_connections();
@ -491,7 +491,7 @@ end:
exit_control(); exit_control();
end_nonet: end_nonet:
logger(LOG_NOTICE, "Terminating"); logger(DEBUG_ALWAYS, LOG_NOTICE, "Terminating");
free(priority); free(priority);

50
src/uml_device.c
View file

@ -72,7 +72,7 @@ static bool setup_device(void) {
device_info = "UML network socket"; device_info = "UML network socket";
if((write_fd = socket(PF_UNIX, SOCK_DGRAM, 0)) < 0) { if((write_fd = socket(PF_UNIX, SOCK_DGRAM, 0)) < 0) {
logger(LOG_ERR, "Could not open write %s: %s", device_info, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open write %s: %s", device_info, strerror(errno));
running = false; running = false;
return false; return false;
} }
@ -84,13 +84,13 @@ static bool setup_device(void) {
setsockopt(write_fd, SOL_SOCKET, SO_REUSEADDR, &one, sizeof one); setsockopt(write_fd, SOL_SOCKET, SO_REUSEADDR, &one, sizeof one);
if(fcntl(write_fd, F_SETFL, O_NONBLOCK) < 0) { if(fcntl(write_fd, F_SETFL, O_NONBLOCK) < 0) {
logger(LOG_ERR, "System call `%s' failed: %s", "fcntl", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "fcntl", strerror(errno));
running = false; running = false;
return false; return false;
} }
if((data_fd = socket(PF_UNIX, SOCK_DGRAM, 0)) < 0) { if((data_fd = socket(PF_UNIX, SOCK_DGRAM, 0)) < 0) {
logger(LOG_ERR, "Could not open data %s: %s", device_info, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open data %s: %s", device_info, strerror(errno));
running = false; running = false;
return false; return false;
} }
@ -102,7 +102,7 @@ static bool setup_device(void) {
setsockopt(data_fd, SOL_SOCKET, SO_REUSEADDR, &one, sizeof one); setsockopt(data_fd, SOL_SOCKET, SO_REUSEADDR, &one, sizeof one);
if(fcntl(data_fd, F_SETFL, O_NONBLOCK) < 0) { if(fcntl(data_fd, F_SETFL, O_NONBLOCK) < 0) {
logger(LOG_ERR, "System call `%s' failed: %s", "fcntl", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "fcntl", strerror(errno));
running = false; running = false;
return false; return false;
} }
@ -115,13 +115,13 @@ static bool setup_device(void) {
memcpy(&data_sun.sun_path, &name, sizeof name); memcpy(&data_sun.sun_path, &name, sizeof name);
if(bind(data_fd, (struct sockaddr *)&data_sun, sizeof data_sun) < 0) { if(bind(data_fd, (struct sockaddr *)&data_sun, sizeof data_sun) < 0) {
logger(LOG_ERR, "Could not bind data %s: %s", device_info, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not bind data %s: %s", device_info, strerror(errno));
running = false; running = false;
return false; return false;
} }
if((listen_fd = socket(PF_UNIX, SOCK_STREAM, 0)) < 0) { if((listen_fd = socket(PF_UNIX, SOCK_STREAM, 0)) < 0) {
logger(LOG_ERR, "Could not open %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Could not open %s: %s", device_info,
strerror(errno)); strerror(errno));
return false; return false;
} }
@ -133,26 +133,26 @@ static bool setup_device(void) {
setsockopt(listen_fd, SOL_SOCKET, SO_REUSEADDR, &one, sizeof one); setsockopt(listen_fd, SOL_SOCKET, SO_REUSEADDR, &one, sizeof one);
if(fcntl(listen_fd, F_SETFL, O_NONBLOCK) < 0) { if(fcntl(listen_fd, F_SETFL, O_NONBLOCK) < 0) {
logger(LOG_ERR, "System call `%s' failed: %s", "fcntl", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "fcntl", strerror(errno));
return false; return false;
} }
listen_sun.sun_family = AF_UNIX; listen_sun.sun_family = AF_UNIX;
strncpy(listen_sun.sun_path, device, sizeof listen_sun.sun_path); strncpy(listen_sun.sun_path, device, sizeof listen_sun.sun_path);
if(bind(listen_fd, (struct sockaddr *)&listen_sun, sizeof listen_sun) < 0) { if(bind(listen_fd, (struct sockaddr *)&listen_sun, sizeof listen_sun) < 0) {
logger(LOG_ERR, "Could not bind %s to %s: %s", device_info, device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not bind %s to %s: %s", device_info, device, strerror(errno));
return false; return false;
} }
if(listen(listen_fd, 1) < 0) { if(listen(listen_fd, 1) < 0) {
logger(LOG_ERR, "Could not listen on %s %s: %s", device_info, device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not listen on %s %s: %s", device_info, device, strerror(errno));
return false; return false;
} }
device_fd = listen_fd; device_fd = listen_fd;
state = 0; state = 0;
logger(LOG_INFO, "%s is a %s", device, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s is a %s", device, device_info);
if(routing_mode == RMODE_ROUTER) if(routing_mode == RMODE_ROUTER)
overwrite_mac = true; overwrite_mac = true;
@ -189,7 +189,7 @@ static bool read_packet(vpn_packet_t *packet) {
request_fd = accept(listen_fd, &sa, &salen); request_fd = accept(listen_fd, &sa, &salen);
if(request_fd < 0) { if(request_fd < 0) {
logger(LOG_ERR, "Could not accept connection to %s %s: %s", device_info, device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not accept connection to %s %s: %s", device_info, device, strerror(errno));
return false; return false;
} }
@ -198,7 +198,7 @@ static bool read_packet(vpn_packet_t *packet) {
#endif #endif
if(fcntl(listen_fd, F_SETFL, O_NONBLOCK) < 0) { if(fcntl(listen_fd, F_SETFL, O_NONBLOCK) < 0) {
logger(LOG_ERR, "System call `%s' failed: %s", "fcntl", strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "System call `%s' failed: %s", "fcntl", strerror(errno));
running = false; running = false;
return false; return false;
} }
@ -213,21 +213,21 @@ static bool read_packet(vpn_packet_t *packet) {
case 1: { case 1: {
if((inlen = read(request_fd, &request, sizeof request)) != sizeof request) { if((inlen = read(request_fd, &request, sizeof request)) != sizeof request) {
logger(LOG_ERR, "Error while reading request from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading request from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
running = false; running = false;
return false; return false;
} }
if(request.magic != 0xfeedface || request.version != 3 || request.type != REQ_NEW_CONTROL) { if(request.magic != 0xfeedface || request.version != 3 || request.type != REQ_NEW_CONTROL) {
logger(LOG_ERR, "Unknown magic %x, version %d, request type %d from %s %s", logger(DEBUG_ALWAYS, LOG_ERR, "Unknown magic %x, version %d, request type %d from %s %s",
request.magic, request.version, request.type, device_info, device); request.magic, request.version, request.type, device_info, device);
running = false; running = false;
return false; return false;
} }
if(connect(write_fd, &request.sock, sizeof request.sock) < 0) { if(connect(write_fd, &request.sock, sizeof request.sock) < 0) {
logger(LOG_ERR, "Could not bind write %s: %s", device_info, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Could not bind write %s: %s", device_info, strerror(errno));
running = false; running = false;
return false; return false;
} }
@ -235,7 +235,7 @@ static bool read_packet(vpn_packet_t *packet) {
write(request_fd, &data_sun, sizeof data_sun); write(request_fd, &data_sun, sizeof data_sun);
device_fd = data_fd; device_fd = data_fd;
logger(LOG_INFO, "Connection with UML established"); logger(DEBUG_ALWAYS, LOG_INFO, "Connection with UML established");
state = 2; state = 2;
return false; return false;
@ -243,7 +243,7 @@ static bool read_packet(vpn_packet_t *packet) {
case 2: { case 2: {
if((inlen = read(data_fd, packet->data, MTU)) <= 0) { if((inlen = read(data_fd, packet->data, MTU)) <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info,
device, strerror(errno)); device, strerror(errno));
running = false; running = false;
return false; return false;
@ -253,31 +253,31 @@ static bool read_packet(vpn_packet_t *packet) {
device_total_in += packet->len; device_total_in += packet->len;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Read packet of %d bytes from %s", packet->len, logger(DEBUG_TRAFFIC, LOG_DEBUG, "Read packet of %d bytes from %s", packet->len,
device_info); device_info);
return true; return true;
} }
default: default:
logger(LOG_ERR, "Invalid value for state variable in " __FILE__); logger(DEBUG_ALWAYS, LOG_ERR, "Invalid value for state variable in " __FILE__);
abort(); abort();
} }
} }
static bool write_packet(vpn_packet_t *packet) { static bool write_packet(vpn_packet_t *packet) {
if(state != 2) { if(state != 2) {
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Dropping packet of %d bytes to %s: not connected to UML yet", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Dropping packet of %d bytes to %s: not connected to UML yet",
packet->len, device_info); packet->len, device_info);
return false; return false;
} }
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Writing packet of %d bytes to %s", logger(DEBUG_TRAFFIC, LOG_DEBUG, "Writing packet of %d bytes to %s",
packet->len, device_info); packet->len, device_info);
if(write(write_fd, packet->data, packet->len) < 0) { if(write(write_fd, packet->data, packet->len) < 0) {
if(errno != EINTR && errno != EAGAIN) { if(errno != EINTR && errno != EAGAIN) {
logger(LOG_ERR, "Can't write to %s %s: %s", device_info, device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Can't write to %s %s: %s", device_info, device, strerror(errno));
running = false; running = false;
} }
@ -290,9 +290,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out);
} }
const devops_t uml_devops = { const devops_t uml_devops = {

18
src/vde_device.c
View file

@ -45,7 +45,7 @@ static bool setup_device(void) {
libvdeplug_dynopen(plug); libvdeplug_dynopen(plug);
if(!plug.dl_handle) { if(!plug.dl_handle) {
logger(LOG_ERR, "Could not open libvdeplug library!"); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open libvdeplug library!");
return false; return false;
} }
@ -68,7 +68,7 @@ static bool setup_device(void) {
conn = plug.vde_open(device, identname, &args); conn = plug.vde_open(device, identname, &args);
if(!conn) { if(!conn) {
logger(LOG_ERR, "Could not open VDE socket %s", device); logger(DEBUG_ALWAYS, LOG_ERR, "Could not open VDE socket %s", device);
return false; return false;
} }
@ -78,7 +78,7 @@ static bool setup_device(void) {
fcntl(device_fd, F_SETFD, FD_CLOEXEC); fcntl(device_fd, F_SETFD, FD_CLOEXEC);
#endif #endif
logger(LOG_INFO, "%s is a %s", device, device_info); logger(DEBUG_ALWAYS, LOG_INFO, "%s is a %s", device, device_info);
if(routing_mode == RMODE_ROUTER) if(routing_mode == RMODE_ROUTER)
overwrite_mac = true; overwrite_mac = true;
@ -101,14 +101,14 @@ static void close_device(void) {
static bool read_packet(vpn_packet_t *packet) { static bool read_packet(vpn_packet_t *packet) {
int lenin = plug.vde_recv(conn, packet->data, MTU, 0); int lenin = plug.vde_recv(conn, packet->data, MTU, 0);
if(lenin <= 0) { if(lenin <= 0) {
logger(LOG_ERR, "Error while reading from %s %s: %s", device_info, device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Error while reading from %s %s: %s", device_info, device, strerror(errno));
running = false; running = false;
return false; return false;
} }
packet->len = lenin; packet->len = lenin;
device_total_in += packet->len; device_total_in += packet->len;
ifdebug(TRAFFIC) logger(LOG_DEBUG, "Read packet of %d bytes from %s", packet->len, device_info); logger(DEBUG_TRAFFIC, LOG_DEBUG, "Read packet of %d bytes from %s", packet->len, device_info);
return true; return true;
} }
@ -116,7 +116,7 @@ static bool read_packet(vpn_packet_t *packet) {
static bool write_packet(vpn_packet_t *packet) { static bool write_packet(vpn_packet_t *packet) {
if(plug.vde_send(conn, packet->data, packet->len, 0) < 0) { if(plug.vde_send(conn, packet->data, packet->len, 0) < 0) {
if(errno != EINTR && errno != EAGAIN) { if(errno != EINTR && errno != EAGAIN) {
logger(LOG_ERR, "Can't write to %s %s: %s", device_info, device, strerror(errno)); logger(DEBUG_ALWAYS, LOG_ERR, "Can't write to %s %s: %s", device_info, device, strerror(errno));
running = false; running = false;
} }
@ -129,9 +129,9 @@ static bool write_packet(vpn_packet_t *packet) {
} }
static void dump_device_stats(void) { static void dump_device_stats(void) {
logger(LOG_DEBUG, "Statistics for %s %s:", device_info, device); logger(DEBUG_ALWAYS, LOG_DEBUG, "Statistics for %s %s:", device_info, device);
logger(LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes in: %10"PRIu64, device_total_in);
logger(LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out); logger(DEBUG_ALWAYS, LOG_DEBUG, " total bytes out: %10"PRIu64, device_total_out);
} }
const devops_t vde_devops = { const devops_t vde_devops = {