upnpstun.c: improve error and debug log

This commit is contained in:
Thomas Bernard 2020-04-21 23:24:58 +02:00
parent 38c3419ea5
commit 78956a97df
No known key found for this signature in database
GPG Key ID: 0FF11B67A5C0863C
2 changed files with 133 additions and 42 deletions

View File

@ -1,8 +1,9 @@
$Id: Changelog.txt,v 1.460 2020/04/12 17:27:31 nanard Exp $
$Id: Changelog.txt,v 1.463 2020/04/21 21:20:04 nanard Exp $
2020/04/21:
Remove FW API detecting code from Makefile (BSD). generate bsdmake.inc
netfilter: addmasqueraderule() even if internal/external ports are the same
improve error and debug log in upnpstun.c
2020/04/20:
Fix "IGD2 Port Triggering" in update_portmapping()

View File

@ -1,4 +1,4 @@
/* $Id: $ */
/* $Id: upnpstun.c,v 1.5 2020/04/21 21:21:59 nanard Exp $ */
/* vim: tabstop=4 shiftwidth=4 noexpandtab
* MiniUPnP project
* http://miniupnp.free.fr/ or http://miniupnp.tuxfamily.org/
@ -15,6 +15,7 @@
#include <netdb.h>
#include <stdlib.h>
#include <stdio.h>
#include <syslog.h>
#include <string.h>
#include <errno.h>
@ -22,6 +23,7 @@
#include "config.h"
#endif
#include "upnputils.h"
#include "upnpstun.h"
#if defined(USE_NETFILTER)
@ -62,7 +64,7 @@ static void fill_request(unsigned char buffer[28], int change_ip, int change_por
buffer[2] = 0x00;
buffer[3] = 0x08;
/* Magic Cookie: 0x2120A442 */
/* RFC5389 Magic Cookie: 0x2120A442 */
buffer[4] = 0x21;
buffer[5] = 0x12;
buffer[6] = 0xA4;
@ -99,6 +101,7 @@ static int resolve_stun_host(const char *stun_host, unsigned short stun_port, st
struct addrinfo hints;
struct addrinfo *result, *rp;
char service[6];
int r;
if (stun_port == 0)
stun_port = (unsigned short)3478;
@ -110,7 +113,10 @@ static int resolve_stun_host(const char *stun_host, unsigned short stun_port, st
hints.ai_protocol = IPPROTO_UDP;
hints.ai_flags = AI_NUMERICSERV;
if (getaddrinfo(stun_host, service, &hints, &result) != 0) {
r = getaddrinfo(stun_host, service, &hints, &result);
if (r != 0) {
syslog(LOG_ERR, "%s: getaddrinfo(%s, %s, ...) failed : %s",
"resolve_stun_host", stun_host, service, gai_strerror(r));
errno = EHOSTUNREACH;
return -1;
}
@ -127,8 +133,16 @@ static int resolve_stun_host(const char *stun_host, unsigned short stun_port, st
freeaddrinfo(result);
if (!have_sock) {
syslog(LOG_WARNING, "%s: failed to resolve IPv4 address for %s:%s",
"resolve_stun_host", stun_host, service);
errno = EHOSTUNREACH;
return -1;
} else {
char addr_str[48];
if (sockaddr_to_string((struct sockaddr *)sock_addr, addr_str, sizeof(addr_str)) > 0) {
syslog(LOG_DEBUG, "%s: %s:%s => %s",
"resolve_stun_host", stun_host, service, addr_str);
}
}
return 0;
@ -142,8 +156,11 @@ static int stun_socket(unsigned short *local_port)
struct sockaddr_in local_addr;
fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
if (fd < 0)
if (fd < 0) {
syslog(LOG_ERR, "%s: socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP): %m",
"stun_socket");
return -1;
}
memset(&local_addr, 0, sizeof(local_addr));
local_addr.sin_family = AF_INET;
@ -151,12 +168,16 @@ static int stun_socket(unsigned short *local_port)
local_addr.sin_port = 0;
if (bind(fd, (struct sockaddr *)&local_addr, sizeof(local_addr)) != 0) {
syslog(LOG_ERR, "%s: bind(): %m",
"stun_socket");
close(fd);
return -1;
}
addr_len = sizeof(local_addr);
if (getsockname(fd, (struct sockaddr *)&local_addr, &addr_len) != 0) {
syslog(LOG_ERR, "%s: getsockname(): %m",
"stun_socket");
close(fd);
return -1;
}
@ -173,12 +194,33 @@ static size_t receive_stun_response(int fd, unsigned char *buffer, unsigned char
socklen_t peer_addr_len = sizeof(*peer_addr);
len = recvfrom(fd, buffer, buffer_len, 0, (struct sockaddr *)peer_addr, &peer_addr_len);
if (len < 20 || peer_addr_len != sizeof(*peer_addr))
if (len < 0) {
syslog(LOG_ERR, "%s: recvfrom(): %m", "receive_stun_response");
return 0;
}
if (peer_addr_len != sizeof(*peer_addr)) {
syslog(LOG_ERR, "%s: recvfrom(): peer_addr_len mismatch",
"receive_stun_response");
return 0;
}
if (len < 20) {
syslog(LOG_WARNING, "%s: response too short : %ld",
"receive_stun_response", (long)len);
return 0;
}
/* Check that buffer is STUN message with class Response and Binding method with transaction id */
if ((buffer[0] & 0xFF) != 0x01 || (buffer[1] & 0xEF) != 0x01 || memcmp(buffer+8, transaction_id, 12) != 0)
/* Check that buffer is STUN message with class Response
* and Binding method with transaction id */
if ((buffer[0] & 0xFF) != 0x01 || (buffer[1] & 0xEF) != 0x01) {
syslog(LOG_WARNING, "%s: STUN message type is 0x%02x%02x",
"receive_stun_response", buffer[0], buffer[1]);
return 0;
}
if (memcmp(buffer+8, transaction_id, 12) != 0) {
syslog(LOG_WARNING, "%s: transaction id mismatch",
"receive_stun_response");
return 0;
}
return len;
}
@ -209,8 +251,12 @@ static int wait_for_stun_responses(int fds[4], unsigned char *transaction_ids[4]
}
ret = select(max_fd+1, &fdset, NULL, NULL, &timeout);
if (ret < 0)
if (ret < 0) {
if (errno == EINTR)
continue;
syslog(LOG_ERR, "%s: select(): %m", "wait_for_stun_responses");
return -1;
}
if (ret == 0)
return 0;
@ -236,13 +282,20 @@ static int parse_stun_response(unsigned char *buffer, size_t len, struct sockadd
if (len < 20)
return -1;
/* Check that buffer is STUN message with class Success Response and Binding method */
if (buffer[0] != 0x01 || buffer[1] != 0x01)
syslog(LOG_DEBUG, "%s: Type 0x%04x, Length %hu, Magic Cookie %02x%02x%02x%02x",
"parse_stun_response", ((uint16_t)buffer[0] << 8) + buffer[1],
((uint16_t)buffer[2] << 8) + buffer[3],
buffer[4], buffer[5], buffer[6], buffer[7]);
/* Check that buffer is STUN message with class Response and Binding method */
if (buffer[0] != 0x01 || (buffer[1] & 0xEF) != 0x01)
return -1;
/* Check that STUN message is not longer as buffer length */
if (((size_t)buffer[2] << 8) + buffer[3] + 20 > len)
if (((size_t)buffer[2] << 8) + buffer[3] + 20 > len) {
syslog(LOG_ERR, "%s: truncated STUN response", "parse_stun_response");
return -1;
}
ptr = buffer + 20;
end = buffer + len;
@ -254,14 +307,18 @@ static int parse_stun_response(unsigned char *buffer, size_t len, struct sockadd
attr_len = ((uint16_t)ptr[2] << 8) + ptr[3];
ptr += 4;
if (ptr + attr_len > end)
if (ptr + attr_len > end) {
syslog(LOG_WARNING, "%s: truncated attribute", "parse_stun_response");
break;
}
if (attr_type == 0x0001 || attr_type == 0x8020) {
switch (attr_type) {
case 0x0001: /* MAPPED-ADDRESS */
case 0x8020: /* XOR-MAPPED-ADDRESS (2005 draft) */
/* Mapped Address or XOR Mapped Address */
if (attr_len == 8 && ptr[1] == 1) {
/* IPv4 address */
if (attr_type == 0x8020) {
if ((attr_type & 0x7fff) == 0x0020) {
/* Restore XOR Mapped Address */
ptr[2] ^= buffer[4];
ptr[3] ^= buffer[5];
@ -276,11 +333,15 @@ static int parse_stun_response(unsigned char *buffer, size_t len, struct sockadd
mapped_addr->sin_addr.s_addr = htonl(((uint32_t)ptr[4] << 24) + (ptr[5] << 16) + (ptr[6] << 8) + ptr[7]);
/* Prefer XOR Mapped Address, some NATs change IP addresses in UDP packets */
if (attr_type == 0x8020)
if ((attr_type & 0x7fff) == 0x0020)
return 0;
have_address = 1;
}
break;
default:
syslog(LOG_WARNING, "%s: unknown attribute type 0x%04x (len=%hu)",
"parse_stun_response", attr_type, attr_len);
}
ptr += attr_len;
@ -289,8 +350,11 @@ static int parse_stun_response(unsigned char *buffer, size_t len, struct sockadd
return have_address ? 0 : -1;
}
/* Perform main STUN operation, return external IP address and check if host is behind restrictive NAT */
/* Restrictive NAT means any NAT which do some filtering and which is not static 1:1, basically NAT which is not usable for port forwarding */
/* Perform main STUN operation, return external IP address and check
* if host is behind restrictive NAT.
* Restrictive NAT means any NAT which do some filtering and
* which is not static 1:1, basically NAT which is not usable
* for port forwarding */
int perform_stun(const char *if_name, const char *if_addr, const char *stun_host, unsigned short stun_port, struct in_addr *ext_addr, int *restrictive_nat)
{
int fds[4];
@ -300,7 +364,7 @@ int perform_stun(const char *if_name, const char *if_addr, const char *stun_host
size_t responses_sizes[4];
unsigned char requests[4][28];
unsigned char *transaction_ids[4];
int have_mapped_addrs[4];
int have_mapped_addr, mapped_addrs_count;
struct sockaddr_in remote_addr, peer_addrs[4], mapped_addrs[4];
unsigned short local_ports[4];
int have_ext_addr;
@ -325,21 +389,32 @@ int perform_stun(const char *if_name, const char *if_addr, const char *stun_host
fill_request(requests[i], i/2, i%2);
transaction_ids[i] = requests[i]+8;
}
syslog(LOG_INFO, "%s: local ports %hu %hu %hu %hu",
"perform_stun", local_ports[0], local_ports[1],
local_ports[2], local_ports[3]);
/* Unblock local ports */
for (i = 0; i < 4; ++i)
add_filter_rule2(if_name, NULL, if_addr, local_ports[i], local_ports[i], IPPROTO_UDP, "stun test");
for (i = 0; i < 4; ++i) {
if (add_filter_rule2(if_name, NULL, if_addr, local_ports[i], local_ports[i], IPPROTO_UDP, "stun test") < 0) {
syslog(LOG_ERR, "%s: add_filter_rule2(..., %hu, ...) FAILED",
"perform_stun", local_ports[i]);
}
}
/* Send STUN requests and wait for responses */
for (j = 0; j < 3; ++j) {
for (i = 0; i < 4; ++i) {
ssize_t n;
if (responses_lens[i])
continue;
if (sendto(fds[i], requests[i], sizeof(requests[i]), 0, (struct sockaddr *)&remote_addr, sizeof(remote_addr)) != sizeof(requests[i]))
n = sendto(fds[i], requests[i], sizeof(requests[i]), 0, (struct sockaddr *)&remote_addr, sizeof(remote_addr));
if (n != sizeof(requests[i])) {
syslog(LOG_ERR, "%s: #%d,%d sendto(): %m", "perform_stun", j, i);
break;
}
}
if (wait_for_stun_responses(fds, transaction_ids, responses, responses_sizes, peer_addrs, responses_lens) != 0)
@ -358,14 +433,16 @@ int perform_stun(const char *if_name, const char *if_addr, const char *stun_host
/* Parse received STUN messages */
have_ext_addr = 0;
have_mapped_addr = 0;
mapped_addrs_count = 0;
for (i = 0; i < 4; ++i) {
if (parse_stun_response(responses[i], responses_lens[i], &mapped_addrs[i]) == 0)
have_mapped_addrs[i] = 1;
else
have_mapped_addrs[i] = 0;
if (!have_ext_addr && have_mapped_addrs[i]) {
memcpy(ext_addr, &mapped_addrs[i].sin_addr, sizeof(*ext_addr));
have_ext_addr = 1;
if (parse_stun_response(responses[i], responses_lens[i], &mapped_addrs[i]) == 0) {
mapped_addrs_count++;
have_mapped_addr |= (1 << i);
if (!have_ext_addr) {
memcpy(ext_addr, &mapped_addrs[i].sin_addr, sizeof(*ext_addr));
have_ext_addr = 1;
}
}
}
@ -375,42 +452,54 @@ int perform_stun(const char *if_name, const char *if_addr, const char *stun_host
return -1;
}
for (i = 0; i < 4; ++i) {
if (!have_mapped_addrs[i]) {
/* We have not received all four responses, therefore NAT or firewall is doing some filtering */
*restrictive_nat = 1;
return 0;
}
*restrictive_nat = 0;
if (mapped_addrs_count < 4) {
/* We have not received all four responses,
* therefore NAT or firewall is doing some filtering */
syslog(LOG_NOTICE, "%s: %d response out of 4 received",
"perform_stun", mapped_addrs_count);
*restrictive_nat = 1;
}
if (memcmp(&remote_addr, &peer_addrs[0], sizeof(peer_addrs[0])) != 0) {
/* We received STUN response from different address even we did not asked for it, so some strange NAT is active */
/* We received STUN response from different address
* even we did not asked for it, so some strange NAT is active */
syslog(LOG_NOTICE, "%s: address changed",
"perform_stun");
*restrictive_nat = 1;
return 0;
}
for (i = 0; i < 4; ++i) {
if (!(have_mapped_addr & (1 << i)))
continue;
if (ntohs(mapped_addrs[i].sin_port) != local_ports[i] || memcmp(&mapped_addrs[i].sin_addr, ext_addr, sizeof(*ext_addr)) != 0) {
/* External IP address or port was changed, therefore symmetric NAT is active */
/* External IP address or port was changed,
* therefore symmetric NAT is active */
syslog(LOG_NOTICE, "%s: #%d external address or port changed",
"perform_stun", i);
*restrictive_nat = 1;
return 0;
}
}
/* Otherwise we are either directly connected or behind unrestricted NAT 1:1 */
/* There is no filtering, so port forwarding would work fine */
*restrictive_nat = 0;
return 0;
}
#ifdef TEST_LINUX_DEBUG_APP
/* This linux test application for debugging purposes can be compiled as: */
/* gcc upnpstun.c -o upnpstun -g3 -W -Wall -O2 -DTEST_LINUX_DEBUG_APP */
/* gcc upnpstun.c upnputils.o -o upnpstun -g3 -W -Wall -O2 -DTEST_LINUX_DEBUG_APP */
#include <arpa/inet.h>
#include <time.h>
#include "upnpglobalvars.h"
struct lan_addr_list lan_addrs;
int runtime_flags = 0;
time_t startup_time = 0;
static int add_filter_rule2(const char *ifname, const char *rhost, const char *iaddr, unsigned short eport, unsigned short iport, int proto, const char *desc)
{
char buffer[100];
@ -450,6 +539,7 @@ int main(int argc, char *argv[])
srandom(time(NULL) * getpid());
openlog("upnpstun", LOG_CONS|LOG_PERROR, LOG_USER);
ret = perform_stun(NULL, NULL, argv[1], atoi(argv[2]), &ext_addr, &restrictive_nat);
if (ret != 0) {
printf("STUN Failed: %s\n", strerror(errno));