Sapian
/
asterisk
mirror of http://gerrit.asterisk.org/asterisk
3
0
Fork 0
Code Issues Releases Wiki Activity

res_pjsip_logger: Expand functionality to improve logging.

Browse Source 
The PJSIP packet logger now has the following CLI commands:

pjsip set logger pcap <filename>

When used this will create a pcap file containing the incoming
and outgoing SIP packets, in unencrypted form.

pjsip set logger verbose <on / off>

This allows you to toggle logging to verbose on and off.

pjsip set logger host <IP/subnet mask> add

This allows you to add an additional IP address or subnet
mask to logging, allowing you to log multiple instead of
just a single IP address or all traffic.

The normal "pjsip set logger host" CLI command has also been
expanded to allow subnet masks as well.

ASTERISK-28895

Change-Id: If5859161a72b0d7dd2d1f92d45bed88e0cd07d0e
changes/62/14462/2
Joshua C. Colp 5 years ago committed by Friendly Automation
parent fef97a9a72
commit a7aaee70c6
2 changed files with 419 additions and 53 deletions
Show Stats Download Patch File Download Diff File

21
doc/CHANGES-staging/pjsip_logger_improvements.txt
Unescape View File

@ -0,0 +1,21 @@
Subject: res_pjsip_logger
The PJSIP packet logger now has the following CLI commands:
pjsip set logger pcap <filename>
When used this will create a pcap file containing the incoming
and outgoing SIP packets, in unencrypted form.
pjsip set logger console <on / off>
This allows you to toggle logging to console on and off.
pjsip set logger host <IP/subnet mask> add
This allows you to add an additional IP address or subnet
mask to logging, allowing you to log multiple instead of
just a single IP address or all traffic.
The normal "pjsip set logger host" CLI command has also been
expanded to allow subnet masks as well.

451
res/res_pjsip_logger.c
Unescape View File

@ -25,6 +25,8 @@
#include "asterisk.h"
#include <netinet/in.h> /* For IPPROTO_UDP and in6_addr */
#include <pjsip.h>
#include "asterisk/res_pjsip.h"
@ -32,60 +34,262 @@
#include "asterisk/logger.h"
#include "asterisk/cli.h"
#include "asterisk/netsock2.h"
#include "asterisk/acl.h"
/*! \brief PCAP Header */
struct pcap_header {
uint32_t magic_number; /*! \brief PCAP file format magic number */
uint16_t version_major; /*! \brief Major version number of the file format */
uint16_t version_minor; /*! \brief Minor version number of the file format */
int32_t thiszone; /*! \brief GMT to local correction */
uint32_t sigfigs; /*! \brief Accuracy of timestamps */
uint32_t snaplen; /*! \brief The maximum size that can be recorded in the file */
uint32_t network; /*! \brief Type of packets held within the file */
};
/*! \brief PCAP Packet Record Header */
struct pcap_record_header {
uint32_t ts_sec; /*! \brief When the record was created */
uint32_t ts_usec; /*! \brief When the record was created */
uint32_t incl_len; /*! \brief Length of packet as saved in the file */
uint32_t orig_len; /*! \brief Length of packet as sent over network */
};
enum pjsip_logging_mode {
LOGGING_MODE_DISABLED, /* No logging is enabled */
LOGGING_MODE_ENABLED, /* Logging is enabled */
/*! \brief PCAP Ethernet Header */
struct pcap_ethernet_header {
uint8_t dst[6]; /*! \brief Destination MAC address */
uint8_t src[6]; /*! \brief Source MAD address */
uint16_t type; /*! \brief The type of packet contained within */
} __attribute__((__packed__));
/*! \brief PCAP IPv4 Header */
struct pcap_ipv4_header {
uint8_t ver_ihl; /*! \brief IP header version and other bits */
uint8_t ip_tos; /*! \brief Type of service details */
uint16_t ip_len; /*! \brief Total length of the packet (including IPv4 header) */
uint16_t ip_id; /*! \brief Identification value */
uint16_t ip_off; /*! \brief Fragment offset */
uint8_t ip_ttl; /*! \brief Time to live for the packet */
uint8_t ip_protocol; /*! \brief Protocol of the data held within the packet (always UDP) */
uint16_t ip_sum; /*! \brief Checksum (not calculated for our purposes */
uint32_t ip_src; /*! \brief Source IP address */
uint32_t ip_dst; /*! \brief Destination IP address */
};
static enum pjsip_logging_mode logging_mode;
static struct ast_sockaddr log_addr;
/*! \brief PCAP IPv6 Header */
struct pcap_ipv6_header {
union {
struct ip6_hdrctl {
uint32_t ip6_un1_flow; /*! \brief Version, traffic class, flow label */
uint16_t ip6_un1_plen; /*! \brief Length of the packet (not including IPv6 header) */
uint8_t ip6_un1_nxt; /*! \brief Next header field */
uint8_t ip6_un1_hlim; /*! \brief Hop Limit */
} ip6_un1;
uint8_t ip6_un2_vfc; /*! \brief Version, traffic class */
} ip6_ctlun;
struct in6_addr ip6_src; /*! \brief Source IP address */
struct in6_addr ip6_dst; /*! \brief Destination IP address */
};
/*! \brief PCAP UDP Header */
struct pcap_udp_header {
uint16_t src; /*! \brief Source IP port */
uint16_t dst; /*! \brief Destination IP port */
uint16_t length; /*! \brief Length of the UDP header plus UDP packet */
uint16_t checksum; /*! \brief Packet checksum, left uncalculated for our purposes */
};
/*! \brief PJSIP Logging Session */
struct pjsip_logger_session {
/*! \brief Explicit addresses or ranges being logged */
struct ast_ha *matches;
/*! \brief Filename used for the pcap file */
char pcap_filename[PATH_MAX];
/*! \brief The pcap file itself */
FILE *pcap_file;
/*! \brief Whether the session is enabled or not */
unsigned int enabled:1;
/*! \brief Whether the session is logging all traffic or not */
unsigned int log_all_traffic:1;
/*! \brief Whether to log to verbose or not */
unsigned int log_to_verbose:1;
/*! \brief Whether to log to pcap or not */
unsigned int log_to_pcap:1;
};
/*! \brief The default logger session */
static struct pjsip_logger_session *default_logger;
/*! \brief Destructor for logger session */
static void pjsip_logger_session_destroy(void *obj)
{
struct pjsip_logger_session *session = obj;
if (session->pcap_file) {
fclose(session->pcap_file);
}
ast_free_ha(session->matches);
}
/*! \brief Allocator for logger session */
static struct pjsip_logger_session *pjsip_logger_session_alloc(void)
{
struct pjsip_logger_session *session;
session = ao2_alloc_options(sizeof(struct pjsip_logger_session), pjsip_logger_session_destroy,
AO2_ALLOC_OPT_LOCK_RWLOCK);
if (!session) {
return NULL;
}
session->log_to_verbose = 1;
return session;
}
/*! \brief See if we pass debug IP filter */
static inline int pjsip_log_test_addr(const char *address, int port)
static inline int pjsip_log_test_addr(const struct pjsip_logger_session *session, const char *address, int port)
{
struct ast_sockaddr test_addr;
if (logging_mode == LOGGING_MODE_DISABLED) {
if (!session->enabled) {
return 0;
}
/* A null logging address means we'll debug any address */
if (ast_sockaddr_isnull(&log_addr)) {
if (session->log_all_traffic) {
return 1;
}
/* A null address was passed in. Just reject it. */
if (ast_strlen_zero(address)) {
/* A null address was passed in or no explicit matches. Just reject it. */
if (ast_strlen_zero(address) || !session->matches) {
return 0;
}
ast_sockaddr_parse(&test_addr, address, PARSE_PORT_IGNORE);
ast_sockaddr_set_port(&test_addr, port);
/* If no port was specified for a debug address, just compare the
* addresses, otherwise compare the address and port
*/
if (ast_sockaddr_port(&log_addr)) {
return !ast_sockaddr_cmp(&log_addr, &test_addr);
/* Compare the address against the matches */
if (ast_apply_ha(session->matches, &test_addr) != AST_SENSE_ALLOW) {
return 1;
} else {
return !ast_sockaddr_cmp_addr(&log_addr, &test_addr);
return 0;
}
}
static void pjsip_logger_write_to_pcap(struct pjsip_logger_session *session, const char *msg, size_t msg_len,
pj_sockaddr *source, pj_sockaddr *destination)
{
struct timeval now = ast_tvnow();
struct pcap_record_header pcap_record_header = {
.ts_sec = now.tv_sec,
.ts_usec = now.tv_usec,
};
struct pcap_ethernet_header pcap_ethernet_header = {
.type = 0,
};
struct pcap_ipv4_header pcap_ipv4_header = {
.ver_ihl = 0x45, /* IPv4 + 20 bytes of header */
.ip_ttl = 128, /* We always put a TTL of 128 to keep Wireshark less blue */
};
struct pcap_ipv6_header pcap_ipv6_header = {
.ip6_ctlun.ip6_un2_vfc = 0x60,
};
void *pcap_ip_header;
size_t pcap_ip_header_len;
struct pcap_udp_header pcap_udp_header;
/* Packets are always stored as UDP to simplify this logic */
if (source) {
pcap_udp_header.src = ntohs(pj_sockaddr_get_port(source));
} else {
pcap_udp_header.src = ntohs(0);
}
if (destination) {
pcap_udp_header.dst = ntohs(pj_sockaddr_get_port(destination));
} else {
pcap_udp_header.dst = ntohs(0);
}
pcap_udp_header.length = ntohs(sizeof(struct pcap_udp_header) + msg_len);
/* Construct the appropriate IP header */
if ((source && source->addr.sa_family == pj_AF_INET()) ||
(destination && destination->addr.sa_family == pj_AF_INET())) {
pcap_ethernet_header.type = htons(0x0800); /* We are providing an IPv4 packet */
pcap_ip_header = &pcap_ipv4_header;
pcap_ip_header_len = sizeof(struct pcap_ipv4_header);
if (source) {
memcpy(&pcap_ipv4_header.ip_src, pj_sockaddr_get_addr(source), pj_sockaddr_get_addr_len(source));
}
if (destination) {
memcpy(&pcap_ipv4_header.ip_dst, pj_sockaddr_get_addr(destination), pj_sockaddr_get_addr_len(destination));
}
pcap_ipv4_header.ip_len = htons(sizeof(struct pcap_udp_header) + sizeof(struct pcap_ipv4_header) + msg_len);
pcap_ipv4_header.ip_protocol = IPPROTO_UDP; /* We always provide UDP */
} else {
pcap_ethernet_header.type = htons(0x86DD); /* We are providing an IPv6 packet */
pcap_ip_header = &pcap_ipv6_header;
pcap_ip_header_len = sizeof(struct pcap_ipv6_header);
if (source) {
memcpy(&pcap_ipv6_header.ip6_src, pj_sockaddr_get_addr(source), pj_sockaddr_get_addr_len(source));
}
if (destination) {
memcpy(&pcap_ipv6_header.ip6_dst, pj_sockaddr_get_addr(destination), pj_sockaddr_get_addr_len(destination));
}
pcap_ipv6_header.ip6_ctlun.ip6_un1.ip6_un1_plen = htons(sizeof(struct pcap_udp_header) + msg_len);
pcap_ipv6_header.ip6_ctlun.ip6_un1.ip6_un1_nxt = IPPROTO_UDP;
}
/* Add up all the sizes for this record */
pcap_record_header.incl_len = pcap_record_header.orig_len = sizeof(pcap_ethernet_header) + pcap_ip_header_len + sizeof(pcap_udp_header) + msg_len;
/* We lock the logger session since we're writing these out in parts */
ao2_wrlock(session);
if (session->pcap_file) {
if (fwrite(&pcap_record_header, sizeof(struct pcap_record_header), 1, session->pcap_file) != sizeof(struct pcap_record_header)) {
ast_log(LOG_WARNING, "Writing PCAP header failed: %s\n", strerror(errno));
}
if (fwrite(&pcap_ethernet_header, sizeof(struct pcap_ethernet_header), 1, session->pcap_file) != sizeof(struct pcap_ethernet_header)) {
ast_log(LOG_WARNING, "Writing ethernet header to pcap failed: %s\n", strerror(errno));
}
if (fwrite(pcap_ip_header, pcap_ip_header_len, 1, session->pcap_file) != pcap_ip_header_len) {
ast_log(LOG_WARNING, "Writing IP header to pcap failed: %s\n", strerror(errno));
}
if (fwrite(&pcap_udp_header, sizeof(struct pcap_udp_header), 1, session->pcap_file) != sizeof(struct pcap_udp_header)) {
ast_log(LOG_WARNING, "Writing UDP header to pcap failed: %s\n", strerror(errno));
}
if (fwrite(msg, msg_len, 1, session->pcap_file) != msg_len) {
ast_log(LOG_WARNING, "Writing UDP payload to pcap failed: %s\n", strerror(errno));
}
}
ao2_unlock(session);
}
static pj_status_t logging_on_tx_msg(pjsip_tx_data *tdata)
{
char buffer[AST_SOCKADDR_BUFLEN];
if (!pjsip_log_test_addr(tdata->tp_info.dst_name, tdata->tp_info.dst_port)) {
ao2_rdlock(default_logger);
if (!pjsip_log_test_addr(default_logger, tdata->tp_info.dst_name, tdata->tp_info.dst_port)) {
ao2_unlock(default_logger);
return PJ_SUCCESS;
}
ao2_unlock(default_logger);
if (default_logger->log_to_verbose) {
ast_verbose("<--- Transmitting SIP %s (%d bytes) to %s:%s --->\n%.*s\n",
tdata->msg->type == PJSIP_REQUEST_MSG ? "request" : "response",
(int) (tdata->buf.cur - tdata->buf.start),
tdata->tp_info.transport->type_name,
pj_sockaddr_print(&tdata->tp_info.dst_addr, buffer, sizeof(buffer), 3),
(int) (tdata->buf.end - tdata->buf.start), tdata->buf.start);
}
if (default_logger->log_to_pcap) {
pjsip_logger_write_to_pcap(default_logger, tdata->buf.start, (int) (tdata->buf.end - tdata->buf.start),
NULL, &tdata->tp_info.dst_addr);
}
ast_verbose("<--- Transmitting SIP %s (%d bytes) to %s:%s --->\n%.*s\n",
tdata->msg->type == PJSIP_REQUEST_MSG ? "request" : "response",
(int) (tdata->buf.cur - tdata->buf.start),
tdata->tp_info.transport->type_name,
pj_sockaddr_print(&tdata->tp_info.dst_addr, buffer, sizeof(buffer), 3),
(int) (tdata->buf.end - tdata->buf.start), tdata->buf.start);
return PJ_SUCCESS;
}
@ -93,20 +297,31 @@ static pj_bool_t logging_on_rx_msg(pjsip_rx_data *rdata)
{
char buffer[AST_SOCKADDR_BUFLEN];
if (!pjsip_log_test_addr(rdata->pkt_info.src_name, rdata->pkt_info.src_port)) {
if (!rdata->msg_info.msg) {
return PJ_FALSE;
}
if (!rdata->msg_info.msg) {
ao2_rdlock(default_logger);
if (!pjsip_log_test_addr(default_logger, rdata->pkt_info.src_name, rdata->pkt_info.src_port)) {
ao2_unlock(default_logger);
return PJ_FALSE;
}
ao2_unlock(default_logger);
if (default_logger->log_to_verbose) {
ast_verbose("<--- Received SIP %s (%d bytes) from %s:%s --->\n%s\n",
rdata->msg_info.msg->type == PJSIP_REQUEST_MSG ? "request" : "response",
rdata->msg_info.len,
rdata->tp_info.transport->type_name,
pj_sockaddr_print(&rdata->pkt_info.src_addr, buffer, sizeof(buffer), 3),
rdata->pkt_info.packet);
}
if (default_logger->log_to_pcap) {
pjsip_logger_write_to_pcap(default_logger, rdata->pkt_info.packet, rdata->msg_info.len,
&rdata->pkt_info.src_addr, NULL);
}
ast_verbose("<--- Received SIP %s (%d bytes) from %s:%s --->\n%s\n",
rdata->msg_info.msg->type == PJSIP_REQUEST_MSG ? "request" : "response",
rdata->msg_info.len,
rdata->tp_info.transport->type_name,
pj_sockaddr_print(&rdata->pkt_info.src_addr, buffer, sizeof(buffer), 3),
rdata->pkt_info.packet);
return PJ_FALSE;
}
@ -119,14 +334,135 @@ static pjsip_module logging_module = {
.on_tx_response = logging_on_tx_msg,
};
static char *pjsip_enable_logger_host(int fd, const char *arg)
static char *pjsip_enable_logger_all(int fd)
{
if (ast_sockaddr_resolve_first_af(&log_addr, arg, 0, AST_AF_UNSPEC)) {
return CLI_SHOWUSAGE;
ao2_wrlock(default_logger);
default_logger->enabled = 1;
default_logger->log_all_traffic = 1;
ao2_unlock(default_logger);
if (fd >= 0) {
ast_cli(fd, "PJSIP Logging enabled\n");
}
return CLI_SUCCESS;
}
static char *pjsip_enable_logger_host(int fd, const char *arg, unsigned int add_host)
{
const char *host = arg;
char *mask;
struct ast_sockaddr address;
int error = 0;
ao2_wrlock(default_logger);
default_logger->enabled = 1;
if (!add_host) {
/* If this is not adding an additional host or subnet then we have to
* remove what already exists.
*/
ast_free_ha(default_logger->matches);
default_logger->matches = NULL;
}
mask = strrchr(host, '/');
if (!mask && !ast_sockaddr_parse(&address, arg, 0)) {
if (ast_sockaddr_resolve_first_af(&address, arg, 0, AST_AF_UNSPEC)) {
ao2_unlock(default_logger);
return CLI_SHOWUSAGE;
}
host = ast_sockaddr_stringify(&address);
}
ast_cli(fd, "PJSIP Logging Enabled for host: %s\n", ast_sockaddr_stringify_addr(&log_addr));
logging_mode = LOGGING_MODE_ENABLED;
default_logger->matches = ast_append_ha_with_port("d", host, default_logger->matches, &error);
if (!default_logger->matches || error) {
if (fd >= 0) {
ast_cli(fd, "Failed to add address '%s' for logging\n", host);
}
ao2_unlock(default_logger);
return CLI_SUCCESS;
}
ao2_unlock(default_logger);
if (fd >= 0) {
ast_cli(fd, "PJSIP Logging Enabled for host: %s\n", ast_sockaddr_stringify_addr(&address));
}
return CLI_SUCCESS;
}
static char *pjsip_disable_logger(int fd)
{
ao2_wrlock(default_logger);
/* Default the settings back to the way they were */
default_logger->enabled = 0;
default_logger->log_all_traffic = 0;
default_logger->pcap_filename[0] = '\0';
default_logger->log_to_verbose = 1;
default_logger->log_to_pcap = 0;
/* Stop logging to the PCAP file if active */
if (default_logger->pcap_file) {
fclose(default_logger->pcap_file);
default_logger->pcap_file = NULL;
}
ast_free_ha(default_logger->matches);
default_logger->matches = NULL;
ao2_unlock(default_logger);
if (fd >= 0) {
ast_cli(fd, "PJSIP Logging disabled\n");
}
return CLI_SUCCESS;
}
static char *pjsip_set_logger_verbose(int fd, const char *arg)
{
ao2_wrlock(default_logger);
default_logger->log_to_verbose = ast_true(arg);
ao2_unlock(default_logger);
ast_cli(fd, "PJSIP Logging to verbose has been %s\n", ast_true(arg) ? "enabled" : "disabled");
return CLI_SUCCESS;
}
static char *pjsip_set_logger_pcap(int fd, const char *arg)
{
struct pcap_header pcap_header = {
.magic_number = 0xa1b2c3d4,
.version_major = 2,
.version_minor = 4,
.snaplen = 65535,
.network = 1, /* We always use ethernet so we can combine IPv4 and IPv6 in same pcap */
};
ao2_wrlock(default_logger);
ast_copy_string(default_logger->pcap_filename, arg, sizeof(default_logger->pcap_filename));
if (default_logger->pcap_file) {
fclose(default_logger->pcap_file);
default_logger->pcap_file = NULL;
}
default_logger->pcap_file = fopen(arg, "wb");
if (!default_logger->pcap_file) {
ao2_unlock(default_logger);
ast_cli(fd, "Failed to open file '%s' for pcap writing\n", arg);
return CLI_SUCCESS;
}
fwrite(&pcap_header, 1, sizeof(struct pcap_header), default_logger->pcap_file);
default_logger->log_to_pcap = 1;
ao2_unlock(default_logger);
ast_cli(fd, "PJSIP logging to pcap file '%s'\n", arg);
return CLI_SUCCESS;
}
@ -136,9 +472,9 @@ static char *pjsip_set_logger(struct ast_cli_entry *e, int cmd, struct ast_cli_a
const char *what;
if (cmd == CLI_INIT) {
e->command = "pjsip set logger {on|off|host}";
e->command = "pjsip set logger {on|off|host|add|verbose|pcap}";
e->usage =
"Usage: pjsip set logger {on|off|host <name>}\n"
"Usage: pjsip set logger {on|off|host <name/subnet>|add <name/subnet>|verbose <on/off>|pcap <filename>}\n"
" Enables or disabling logging of SIP packets\n"
" read on ports bound to PJSIP transports either\n"
" globally or enables logging for an individual\n"
@ -152,18 +488,19 @@ static char *pjsip_set_logger(struct ast_cli_entry *e, int cmd, struct ast_cli_a
if (a->argc == e->args) { /* on/off */
if (!strcasecmp(what, "on")) {
logging_mode = LOGGING_MODE_ENABLED;
ast_cli(a->fd, "PJSIP Logging enabled\n");
ast_sockaddr_setnull(&log_addr);
return CLI_SUCCESS;
return pjsip_enable_logger_all(a->fd);
} else if (!strcasecmp(what, "off")) {
logging_mode = LOGGING_MODE_DISABLED;
ast_cli(a->fd, "PJSIP Logging disabled\n");
return CLI_SUCCESS;
return pjsip_disable_logger(a->fd);
}
} else if (a->argc == e->args + 1) {
if (!strcasecmp(what, "host")) {
return pjsip_enable_logger_host(a->fd, a->argv[e->args]);
return pjsip_enable_logger_host(a->fd, a->argv[e->args], 0);
} else if (!strcasecmp(what, "add")) {
return pjsip_enable_logger_host(a->fd, a->argv[e->args], 1);
} else if (!strcasecmp(what, "verbose")) {
return pjsip_set_logger_verbose(a->fd, a->argv[e->args]);
} else if (!strcasecmp(what, "pcap")) {
return pjsip_set_logger_pcap(a->fd, a->argv[e->args]);
}
}
@ -179,19 +516,16 @@ static void check_debug(void)
RAII_VAR(char *, debug, ast_sip_get_debug(), ast_free);
if (ast_false(debug)) {
logging_mode = LOGGING_MODE_DISABLED;
pjsip_disable_logger(-1);
return;
}
logging_mode = LOGGING_MODE_ENABLED;
if (ast_true(debug)) {
ast_sockaddr_setnull(&log_addr);
pjsip_enable_logger_all(-1);
return;
}
/* assume host */
if (ast_sockaddr_resolve_first_af(&log_addr, debug, 0, AST_AF_UNSPEC)) {
if (pjsip_enable_logger_host(-1, debug, 0) != CLI_SUCCESS) {
ast_log(LOG_WARNING, "Could not resolve host %s for debug "
"logging\n", debug);
}
@ -213,6 +547,14 @@ static int load_module(void)
return AST_MODULE_LOAD_DECLINE;
}
default_logger = pjsip_logger_session_alloc();
if (!default_logger) {
ast_sorcery_observer_remove(
ast_sip_get_sorcery(), "global", &global_observer);
ast_log(LOG_WARNING, "Unable to create default logger\n");
return AST_MODULE_LOAD_DECLINE;
}
check_debug();
ast_sip_register_service(&logging_module);
@ -229,6 +571,9 @@ static int unload_module(void)
ast_sorcery_observer_remove(
ast_sip_get_sorcery(), "global", &global_observer);
ao2_cleanup(default_logger);
default_logger = NULL;
return 0;
}

Write Preview
Loading…
Cancel
Save