From: Martin Mares <mj@ucw.cz>
Date: Sun, 6 Jan 2008 21:23:43 +0000 (+0100)
Subject: First working version.
X-Git-Tag: v1.0~3
X-Git-Url: http://mj.ucw.cz/gitweb/?a=commitdiff_plain;h=0beb693544108b1e57ee844b6aec8282f5364a88;p=siplog.git

First working version.
---

diff --git a/siplog.c b/siplog.c
index c458471..215b803 100644
--- a/siplog.c
+++ b/siplog.c
@@ -5,6 +5,7 @@
  */
 
 #include <stdio.h>
+#include <stdlib.h>
 #include <errno.h>
 #include <string.h>
 #include <stdarg.h>
@@ -17,15 +18,26 @@
 typedef unsigned char byte;
 typedef unsigned int uns;
 
-static inline int is_white(int c)
-{
-  return (c == ' ' || c == '\t');
-}
-
 /*** Configuration ***/
 
-static config_entry_t sip_cf_log = {
+static config_entry_t sip_cf_mail_to = {
   .next = NULL,
+  .key = "mailto",
+  .type = CONFIG_TYPE_STRING,
+  .options = CONFIG_OPT_NONE,
+  .u.string = ""
+};
+
+static config_entry_t sip_cf_debug_log = {
+  .next = &sip_cf_mail_to,
+  .key = "debuglog",
+  .type = CONFIG_TYPE_STRING,
+  .options = CONFIG_OPT_NONE,
+  .u.string = ""
+};
+
+static config_entry_t sip_cf_log = {
+  .next = &sip_cf_debug_log,
   .key = "file",
   .type = CONFIG_TYPE_STRING,
   .options = CONFIG_OPT_NONE,
@@ -99,6 +111,12 @@ struct pkt {
   uns src_port, dst_port;
   char *sip_rr;			// Decoded SIP
   struct hdr *sip_hdr;
+  char *sip_method;
+  char *sip_uri;
+  int sip_status;
+  char *sip_msg;
+  struct call *sip_call;
+  char *sip_seq;
 };
 
 struct hdr {
@@ -106,20 +124,32 @@ struct hdr {
   char *name, *value;
 };
 
+static char *find_hdr(struct pkt *pkt, char *name)
+{
+  for (struct hdr *h=pkt->sip_hdr; h; h=h->next)
+    if (!strcasecmp(h->name, name))
+      return h->value;
+  return NULL;
+}
+
+static char *find_hdr2(struct pkt *pkt, char *name, char *alt)
+{
+  return find_hdr(pkt, name) ? : find_hdr(pkt, alt);
+}
+
 /*** Logging ***/
 
-static FILE *siplog;
-static int verbose = 1;
+static FILE *siplog, *debuglog;
 
 static void debug(char *fmt, ...)
 {
-  if (!verbose)
+  if (!debuglog)
     return;
   va_list args;
   va_start(args, fmt);
-  fputc('\t', siplog);
-  vfprintf(siplog, fmt, args);
-  fputc('\n', siplog);
+  fputc('\t', debuglog);
+  vfprintf(debuglog, fmt, args);
+  fputc('\n', debuglog);
   va_end(args);
 }
 
@@ -127,35 +157,328 @@ static int error(struct pkt *pkt, char *fmt, ...)
 {
   va_list args;
   va_start(args, fmt);
-  fprintf(siplog, "%s ", pkt->time);
+  fprintf(siplog, "%s ERR: ", pkt->time);
   vfprintf(siplog, fmt, args);
   fputc('\n', siplog);
   va_end(args);
   return 0;
 }
 
+/*** Auxillary routines ***/
+
+static inline int is_white(int c)
+{
+  return (c == ' ' || c == '\t');
+}
+
+static char *skip_ws(char *c)
+{
+  while (is_white(*c))
+    c++;
+  return c;
+}
+
+static char *skip_nonws(char *c)
+{
+  while (*c && !is_white(*c))
+    c++;
+  return c;
+}
+
+/*** The parser ***/
+
+#define CALL_ID_LEN 63
+#define NUM_LEN 63
+#define CSEQ_LEN 63
+
+enum call_state {
+  CALL_IDLE,
+  CALL_DIALING,
+  CALL_CONNECTED,
+  CALL_BYE,
+};
+
+enum call_flags {
+  FLAG_RING = 1,
+  FLAG_ANSWERED = 2,
+  FLAG_REDIRECT = 4,
+};
+
+struct call {
+  struct call *next;
+  char call_id[CALL_ID_LEN+1];
+  enum call_state state;
+  uns out_p;
+  char active_seq[CSEQ_LEN+1];
+  char src_party[NUM_LEN+1];
+  char dst_party[NUM_LEN+1];
+  uns flags;
+};
+static struct call *call_list;
+
+static void log_call(struct pkt *pkt, struct call *c)
+{
+  fprintf(siplog, "%s: CALL %s <%s> -> <%s>", pkt->time, (c->out_p ? "OUT" : "IN"), c->src_party, c->dst_party);
+  if (c->flags & FLAG_ANSWERED)
+    fprintf(siplog, " ANS");
+  else if (c->flags & FLAG_RING)
+    fprintf(siplog, " RING");
+  if (c->flags & FLAG_REDIRECT)
+    fprintf(siplog, " REDIR");
+  if (pkt->sip_status >= 300)
+    fprintf(siplog, " ERR:%s", pkt->sip_msg);
+  else
+    fprintf(siplog, " OK");
+  fputc('\n', siplog);
+
+  if (sip_cf_mail_to.u.string[0])
+    {
+      char cmd[256];
+      sprintf(cmd, "mail -s 'SIP CALL' %s", sip_cf_mail_to.u.string);
+      debug("Running %s", cmd);
+      FILE *m = popen(cmd, "w");
+      if (m)
+        {
+	  fprintf(m, "Finished-At: %s\n", pkt->time);
+	  fprintf(m, "Direction: %s\n", (c->out_p ? "OUT" : "IN"));
+	  fprintf(m, "From: %s\n", c->src_party);
+	  fprintf(m, "To: %s\n", c->dst_party);
+	  fprintf(m, "Flags:%s%s%s\n",
+	    ((c->flags & FLAG_ANSWERED) ? " ANS" : ""),
+	    ((c->flags & FLAG_RING) ? " RING" : ""),
+	    ((c->flags & FLAG_REDIRECT) ? " REDIR" : ""));
+	  fprintf(m, "Status: %s\n", pkt->sip_msg);
+	  fclose(m);
+	}
+      else
+        error(pkt, "Cannot execute `%s': %m", cmd);
+    }
+}
+
+static void extract_number(char *buf, char *h)
+{
+  if (!h)
+    h = "???";
+  char *c;
+  // Multiple addresses => use the first one
+  if (c = strchr(h, ','))
+    *c = 0;
+  // Tagged parameters => drop them
+  if (c = strchr(h, ';'))
+    *c = 0;
+  // Quoted part => prefer it
+  if (c = strchr(h, '<'))
+    {
+      h = c+1;
+      if (c = strchr(h, '>'))
+        *c = 0;
+    }
+  // Skip URL scheme
+  if (c = strchr(h, ':'))
+    h = c+1;
+  // Use only numeric characters, * and #
+  char *d = buf;
+  while (d < buf + NUM_LEN)
+    {
+      if (*h >= '0' && *h <= '9' || *h == '*')
+        *d++ = *h++;
+      else if (*h == '%' && h[1] == '2' && h[2] == '3')
+        {
+	  *d++ = '#';
+	  h += 3;
+	}
+      else
+	break;
+    }
+  *d = 0;
+}
+
+static int parse_request(struct pkt *pkt)
+{
+  struct call *c = pkt->sip_call;
+  if (!strcmp(pkt->sip_seq, c->active_seq))
+    {
+      debug("Retransmitted packet");
+      return 1;
+    }
+  if (!strcasecmp(pkt->sip_method, "INVITE"))
+    {
+      if (c->state != CALL_IDLE)
+	return error(pkt, "re-INVITE not supported yet");
+      c->state = CALL_DIALING;
+      c->out_p = pkt->out_p;
+      strcpy(c->active_seq, pkt->sip_seq);
+      extract_number(c->src_party, find_hdr2(pkt, "From", "f"));
+      extract_number(c->dst_party, find_hdr2(pkt, "To", "t"));
+    }
+  else if (!strcasecmp(pkt->sip_method, "BYE"))
+    {
+      if (c->state != CALL_CONNECTED)
+        {
+	  c->state = CALL_IDLE;
+	  return error(pkt, "Unexpected BYE");
+	}
+      c->state = CALL_BYE;
+      strcpy(c->active_seq, pkt->sip_seq);
+    }
+  return 1;
+}
+
+static int parse_reply(struct pkt *pkt)
+{
+  struct call *c = pkt->sip_call;
+  if (strcmp(pkt->sip_seq, c->active_seq))
+    {
+      debug("Reply not associated to active request %s", c->active_seq);
+      return 1;
+    }
+
+  uns stat = pkt->sip_status;
+  if (stat >= 200)
+    c->active_seq[0] = 0;
+
+  if (c->state == CALL_DIALING)
+    {
+      if (stat < 100)
+        ;
+      else if (stat < 200)
+        {
+	  // Provisional responses
+	  if (stat == 180)
+	    c->flags |= FLAG_RING;
+	}
+      else if (stat < 300)
+        {
+	  // Success
+	  c->state = CALL_CONNECTED;
+	  c->flags |= FLAG_ANSWERED;
+	}
+      else if (stat < 400)
+	{
+	  // Redirect
+	  c->flags |= FLAG_REDIRECT;
+	  log_call(pkt, c);
+	  c->state = CALL_IDLE;
+	}
+      else
+	{
+	  // Failure of some sort
+	  switch (stat)
+	    {
+	      case 408:		// Timeout
+	      case 404:		// Not found
+	      case 403:		// Forbidden
+	      case 480:		// Tmp unavailable
+	      case 486:		// Busy here
+	      case 487:		// Cancelled
+	      case 600:		// Busy everywhere
+	      case 603:		// Decline
+	      case 604:		// Does not exist
+	      case 606:		// Unaccaptable
+		log_call(pkt, c);
+	    }
+	  c->state = CALL_IDLE;
+	  // We do not reset flags on failures, because another INVITE may be sent for the same call and we wish to remember redirects etc.
+	}
+    }
+  else if (c->state == CALL_BYE)
+    {
+      if (stat >= 200)
+        {
+	  log_call(pkt, c);
+	  c->state = CALL_IDLE;
+	}
+    }
+  return 1;
+}
+
+static int parse_call(struct pkt *pkt)
+{
+  char *id = find_hdr2(pkt, "Call-ID", "i");
+  if (!id)
+    return error(pkt, "Missing Call-ID");
+  char *p = skip_nonws(id);
+  *p = 0;
+  if (!*id)
+    return error(pkt, "Empty Call-ID");
+  if (strlen(id) > CALL_ID_LEN)
+    return error(pkt, "Call-ID too long");
+
+  pkt->sip_seq = find_hdr(pkt, "CSeq");
+  if (!pkt->sip_seq)
+    return error(pkt, "Missing CSeq");
+  if (strlen(pkt->sip_seq) > CSEQ_LEN)
+    return error(pkt, "CSeq too long");
+
+  struct call *c;
+  for (c=call_list; c && strcasecmp(c->call_id, id); c=c->next)
+    ;
+  if (!c)
+    {
+      if (!pkt->sip_method)
+        return error(pkt, "Cannot match reply to an existing call");
+      debug("Creating new call <%s>", id);
+      c = malloc(sizeof(struct call));
+      if (!c)
+        return error(pkt, "Out of memory");
+      memset(c, 0, sizeof(*c));
+      c->next = call_list;
+      call_list = c;
+      strcpy(c->call_id, id);
+      c->state = CALL_IDLE;
+    }
+  else
+    debug("Continuing call <%s> in state %d", id, c->state);
+  pkt->sip_call = c;
+  // FIXME: We should time out the calls
+
+  if (pkt->sip_method)
+    return parse_request(pkt);
+  else
+    return parse_reply(pkt);
+}
+
 static int parse_rr(struct pkt *pkt)
 {
   char *rr = pkt->sip_rr;
   if (!strncmp(rr, "SIP/", 4))
     {
       // Reply
-      while (*rr && !is_white(*rr))
-        rr++;
-      while (is_white(*rr))
-        rr++;
+      rr = skip_ws(skip_nonws(rr));
+      if (!*rr)
+        return error(pkt, "Truncated SIP response");
+      pkt->sip_msg = rr;
+      pkt->sip_status = atol(rr);
+      pkt->sip_method = NULL;
+      pkt->sip_uri = NULL;
+      debug("SIP status %d (%s)", pkt->sip_status, pkt->sip_msg);
     }
   else
     {
       // Request
+      pkt->sip_msg = NULL;
+      pkt->sip_status = -1;
+      pkt->sip_method = rr;
+      rr = skip_nonws(rr);
+      if (!*rr)
+        return error(pkt, "Missing URI in SIP request");
+      *rr++ = 0;
+      rr = skip_ws(rr);
+      if (!*rr)
+        return error(pkt, "Missing URI in SIP request");
+      pkt->sip_uri = rr;
+      rr = skip_nonws(rr);
+      *rr = 0;
+      debug("SIP request %s on %s", pkt->sip_method, pkt->sip_uri);
     }
-  return 1;
+  return parse_call(pkt);
 }
 
 static int parse_sip(struct pkt *pkt)
 {
   char *p = (char*) pkt->udp;
   char *end = p + pkt->udp_len;
+  pkt->sip_rr = NULL;
   pkt->sip_hdr = NULL;
 
   // Parse the request/reply line first
@@ -170,7 +493,7 @@ static int parse_sip(struct pkt *pkt)
     *p++ = 0;
   debug(">>> %s", pkt->sip_rr);
 
-  // Slurp the other header lines
+  // Slurp the other header lines and sanitize them
   for (;;)
     {
       char *start = p;
@@ -184,7 +507,7 @@ static int parse_sip(struct pkt *pkt)
 	  else if (*p == '\n')
 	    {
 	      p++;
-	      if (p < end && is_white(*p))
+	      if (p < end && is_white(*p) && pkt->sip_rr)
 	        ;
 	      else
 	        {
@@ -192,12 +515,22 @@ static int parse_sip(struct pkt *pkt)
 		  break;
 		}
 	    }
-	  else
+	  else if (*p > 0x20 && *p != 0x7f || *p < 0)
 	    *w++ = *p++;
+	  else if (is_white(*p))
+	    *w++ = ' ', p++;
+	  else
+	    *w++ = '?', p++;
 	}
       if (!start[0])
         break;
       // Got a line, parse it
+      if (!pkt->sip_rr)
+        {
+	  pkt->sip_rr = start;
+	  debug(">>> %s", pkt->sip_rr);
+	  continue;
+	}
       char *sep = strchr(start, ':');
       if (!*sep)
 	{
@@ -216,6 +549,8 @@ static int parse_sip(struct pkt *pkt)
       h->name = start;
       h->value = sep;
     }
+  if (!pkt->sip_rr)
+    return error(pkt, "Missing SIP header");
 
   return parse_rr(pkt);
 }
@@ -234,7 +569,7 @@ static int parse_udp(struct pkt *pkt)
     return error(pkt, "Truncated UDP data (have %d, want %d)", pkt->ip_len, ulen);
   pkt->udp = p + 8;
   pkt->udp_len = ulen - 8;
-  debug("%08x:%d -> %08x:%d (%d bytes, out_p=%d)", pkt->src_addr, pkt->src_port, pkt->dst_addr, pkt->dst_port, pkt->out_p);
+  debug("%08x:%d -> %08x:%d (%d bytes, out_p=%d)", pkt->src_addr, pkt->src_port, pkt->dst_addr, pkt->dst_port, pkt->udp_len, pkt->out_p);
   return parse_sip(pkt);
 }
 
@@ -271,6 +606,9 @@ static int sip_output(ulog_iret_t *res __attribute__((unused)))
 {
   struct pkt pkt;
 
+  if (!siplog)
+    return 0;
+
   char *prefix = (KEY_OK(K_OOB_PREFIX, STRING) ? KEY_VAL(K_OOB_PREFIX).ptr : "?");
   if (!strcasecmp(prefix, "phone-in"))
     pkt.out_p = 0;
@@ -278,8 +616,7 @@ static int sip_output(ulog_iret_t *res __attribute__((unused)))
     pkt.out_p = 1;
   else
     {
-      if (verbose > 1)
-	fprintf(siplog, "(non-phone packet received, prefix=%s)\n", prefix);
+      // fprintf(debuglog, "(non-phone packet received, prefix=%s)\n", prefix);
       return 0;
     }
 
@@ -301,11 +638,13 @@ static int sip_output(ulog_iret_t *res __attribute__((unused)))
   else
     sprintf(pkt.time, "%04d-%02d-%02d %02d:%02d:%02d.%06d", tm->tm_year+1900, tm->tm_mon+1, tm->tm_mday,
       tm->tm_hour, tm->tm_min, tm->tm_sec, pkt.time_usec);
-  if (verbose)
-    fprintf(siplog, "\t%s\n", pkt.time);
+  if (debuglog)
+    fprintf(debuglog, "%s\n", pkt.time);
 
   parse_ip(&pkt);
   fflush(siplog);
+  if (debuglog)
+    fflush(debuglog);
   return 0;
 }
 
@@ -318,13 +657,22 @@ static int sip_init(void)
       ulogd_log(ULOGD_ERROR, "SIP: Parsing of configuration file failed\n");
       return 1;
     }
-  ulogd_log(ULOGD_INFO, "Initializing SIP plugin, logging to %s\n", sip_cf_log.u.string);
+  ulogd_log(ULOGD_INFO, "Initializing SIP plugin, logging to %s\n", sip_cf_debug_log.u.string);
   siplog = fopen(sip_cf_log.u.string, "a");
   if (!siplog)
     {
       ulogd_log(ULOGD_ERROR, "Cannot open %s: %s", sip_cf_log.u.string, strerror(errno));
       return 1;
     }
+  if (sip_cf_debug_log.u.string[0])
+    {
+      debuglog = fopen(sip_cf_debug_log.u.string, "a");
+      if (!debuglog)
+	{
+	  ulogd_log(ULOGD_ERROR, "Cannot open %s: %s", sip_cf_debug_log.u.string, strerror(errno));
+	  return 1;
+	}
+    }
   return 0;
 }
 
@@ -333,13 +681,15 @@ static void sip_fini(void)
   // Logging does not work here
   // ulogd_log(ULOGD_INFO, "siplog fini\n");
   fclose(siplog);
+  fclose(debuglog);
+  siplog = debuglog = NULL;
 }
 
 static void sip_signal(int sig)
 {
   if (sig == SIGHUP)
     {
-      // FIXME: Should reopen the log file here
+      // FIXME: Should reopen the log files here
     }
 }