siplog.c

   1 /*
   2  *      A Simple SIP Logging Plugin for ulogd
   3  *
   4  *      (c) 2008 Martin Mares <mj@ucw.cz>
   5  */
   6
   7 #include <stdio.h>
   8 #include <errno.h>
   9 #include <string.h>
  10 #include <stdarg.h>
  11 #include <signal.h>
  12 #include <time.h>
  13 #include <alloca.h>
  14 #include <ulogd/ulogd.h>
  15 #include <ulogd/conffile.h>
  16
  17 typedef unsigned char byte;
  18 typedef unsigned int uns;
  19
  20 static inline int is_white(int c)
  21 {
  22   return (c == ' ' || c == '\t');
  23 }
  24
  25 /*** Configuration ***/
  26
  27 static config_entry_t sip_cf_log = {
  28   .next = NULL,
  29   .key = "file",
  30   .type = CONFIG_TYPE_STRING,
  31   .options = CONFIG_OPT_NONE,
  32   .u.string = "/var/log/ulog/sip.log"
  33 };
  34
  35 /*** Unaligned access ***/
  36
  37 static uns get_u16(byte *p)
  38 {
  39   return (p[0] << 8) | p[1];
  40 }
  41
  42 static uns get_u32(byte *p)
  43 {
  44   return (p[0] << 24) | (p[1] << 16) | (p[2] << 8) | p[3];
  45 }
  46
  47 /*** Keys ***/
  48
  49 static struct {
  50   char *name;
  51   uns id;
  52 } keys[] = {
  53   { "raw.pkt", 0 },
  54   { "raw.pktlen", 0 },
  55   { "oob.time.sec", 0 },
  56   { "oob.time.usec", 0 },
  57   { "oob.prefix", 0 },
  58 };
  59
  60 enum {
  61   K_RAW_PKT = 0,
  62   K_RAW_PKTLEN,
  63   K_OOB_TIME_SEC,
  64   K_OOB_TIME_USEC,
  65   K_OOB_PREFIX,
  66 };
  67
  68 static int init_keys(void)
  69 {
  70   for (uns i=0; i < sizeof(keys)/sizeof(keys[0]); i++)
  71     if (!(keys[i].id = keyh_getid(keys[i].name)))
  72       {
  73         ulogd_log(ULOGD_ERROR, "SIP: Unable to resolve key %s\n", keys[i].name);
  74         return 1;
  75       }
  76   return 0;
  77 }
  78
  79 #define KEY_H(i) ulogd_keyh[keys[i].id].interp->result[ulogd_keyh[keys[i].id].offset]
  80 #define KEY_VAL(i) KEY_H(i).value
  81 #define KEY_FLAGS(i) KEY_H(i).flags
  82 #define KEY_TYPE(i) KEY_H(i).type
  83 #define KEY_OK(i,t) ((KEY_FLAGS(i) & ULOGD_RETF_VALID) && KEY_TYPE(i) == ULOGD_RET_##t)
  84
  85 /*** Representation of packets ***/
  86
  87 struct pkt {
  88   time_t time_sec;              // Arrival time
  89   uns time_usec;
  90   char time[64];
  91   byte *raw;                    // Raw packet
  92   uns raw_len;
  93   uns out_p;
  94   byte *ip;                     // Inside IP
  95   uns ip_len;
  96   uns src_addr, dst_addr;
  97   byte *udp;                    // Inside UDP
  98   uns udp_len;
  99   uns src_port, dst_port;
 100   char *sip_rr;                 // Decoded SIP
 101   struct hdr *sip_hdr;
 102 };
 103
 104 struct hdr {
 105   struct hdr *next;
 106   char *name, *value;
 107 };
 108
 109 /*** Logging ***/
 110
 111 static FILE *siplog;
 112 static int verbose = 1;
 113
 114 static void debug(char *fmt, ...)
 115 {
 116   if (!verbose)
 117     return;
 118   va_list args;
 119   va_start(args, fmt);
 120   fputc('\t', siplog);
 121   vfprintf(siplog, fmt, args);
 122   fputc('\n', siplog);
 123   va_end(args);
 124 }
 125
 126 static int error(struct pkt *pkt, char *fmt, ...)
 127 {
 128   va_list args;
 129   va_start(args, fmt);
 130   fprintf(siplog, "%s ", pkt->time);
 131   vfprintf(siplog, fmt, args);
 132   fputc('\n', siplog);
 133   va_end(args);
 134   return 0;
 135 }
 136
 137 static int parse_rr(struct pkt *pkt)
 138 {
 139   char *rr = pkt->sip_rr;
 140   if (!strncmp(rr, "SIP/", 4))
 141     {
 142       // Reply
 143       while (*rr && !is_white(*rr))
 144         rr++;
 145       while (is_white(*rr))
 146         rr++;
 147     }
 148   else
 149     {
 150       // Request
 151     }
 152   return 1;
 153 }
 154
 155 static int parse_sip(struct pkt *pkt)
 156 {
 157   char *p = (char*) pkt->udp;
 158   char *end = p + pkt->udp_len;
 159   pkt->sip_hdr = NULL;
 160
 161   // Parse the request/reply line first
 162   pkt->sip_rr = p;
 163   while (p < end && *p != '\r' && *p != '\n')
 164     p++;
 165   if (p >= end)
 166     return error(pkt, "Truncated 1st line");
 167   if (*p == '\r')
 168     *p++ = 0;
 169   if (p < end && *p == '\n')
 170     *p++ = 0;
 171   debug(">>> %s", pkt->sip_rr);
 172
 173   // Slurp the other header lines
 174   for (;;)
 175     {
 176       char *start = p;
 177       char *w = start;
 178       for (;;)
 179         {
 180           if (p >= end)
 181             return error(pkt, "Truncated SIP headers");
 182           if (*p == '\r')
 183             p++;
 184           else if (*p == '\n')
 185             {
 186               p++;
 187               if (p < end && is_white(*p))
 188                 ;
 189               else
 190                 {
 191                   *w++ = 0;
 192                   break;
 193                 }
 194             }
 195           else
 196             *w++ = *p++;
 197         }
 198       if (!start[0])
 199         break;
 200       // Got a line, parse it
 201       char *sep = strchr(start, ':');
 202       if (!*sep)
 203         {
 204           error(pkt, "Malformed header line");
 205           continue;
 206         }
 207       *sep = 0;
 208       for (char *p=sep; p>start && is_white(p[-1]);)
 209         *--p = 0;
 210       while (++sep < end && is_white(*sep))
 211         *sep = 0;
 212       debug("\t%s: %s", start, sep);
 213       struct hdr *h = alloca(sizeof(*h));
 214       h->next = pkt->sip_hdr;
 215       pkt->sip_hdr = h;
 216       h->name = start;
 217       h->value = sep;
 218     }
 219
 220   return parse_rr(pkt);
 221 }
 222
 223 static int parse_udp(struct pkt *pkt)
 224 {
 225   byte *p = pkt->ip;
 226   if (pkt->ip_len < 8)
 227     return error(pkt, "Truncated UDP header");
 228   pkt->src_port = get_u16(p);
 229   pkt->dst_port = get_u16(p+2);
 230   uns ulen = get_u16(p+4);
 231   if (ulen < 8)
 232     return error(pkt, "Invalid UDP length (%d)", ulen);
 233   if (ulen > pkt->ip_len)
 234     return error(pkt, "Truncated UDP data (have %d, want %d)", pkt->ip_len, ulen);
 235   pkt->udp = p + 8;
 236   pkt->udp_len = ulen - 8;
 237   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);
 238   return parse_sip(pkt);
 239 }
 240
 241 static int parse_ip(struct pkt *pkt)
 242 {
 243   byte *p = pkt->raw;
 244   if (pkt->raw_len < 20)
 245     return error(pkt, "Very truncated IP header");
 246   uns ipver = p[0] >> 4;
 247   if (ipver != 4)
 248     return error(pkt, "We don't speak IPv%d", ipver);
 249   uns hlen = (p[0] & 0x0f)*4;
 250   if (pkt->raw_len < hlen)
 251     return error(pkt, "Truncated IP header (want %d)", hlen);
 252   uns ilen  = get_u16(p+2);
 253   if (ilen < hlen)
 254     return error(pkt, "Invalid IP length (have %d, want at least %d for header)", ilen, hlen);
 255   if (ilen > pkt->raw_len)
 256     return error(pkt, "Truncated (have %d, want %d)", pkt->raw_len, ilen);
 257   if (p[9] != 17)
 258     return error(pkt, "Not UDP (protocol %02x)", p[9]);
 259   if (get_u16(p+6) & 0x3fff)
 260     return error(pkt, "Fragmented");
 261   pkt->ip = p + hlen;
 262   pkt->ip_len = ilen - hlen;
 263   pkt->src_addr = get_u32(p+12);
 264   pkt->dst_addr = get_u32(p+16);
 265   return parse_udp(pkt);
 266 }
 267
 268 /*** Interface to ulogd ***/
 269
 270 static int sip_output(ulog_iret_t *res __attribute__((unused)))
 271 {
 272   struct pkt pkt;
 273
 274   char *prefix = (KEY_OK(K_OOB_PREFIX, STRING) ? KEY_VAL(K_OOB_PREFIX).ptr : "?");
 275   if (!strcasecmp(prefix, "phone-in"))
 276     pkt.out_p = 0;
 277   else if (!strcasecmp(prefix, "phone-out"))
 278     pkt.out_p = 1;
 279   else
 280     {
 281       if (verbose > 1)
 282         fprintf(siplog, "(non-phone packet received, prefix=%s)\n", prefix);
 283       return 0;
 284     }
 285
 286   if (!KEY_OK(K_RAW_PKT, RAW) ||
 287       !KEY_OK(K_RAW_PKTLEN, UINT32) ||
 288       !KEY_OK(K_OOB_TIME_SEC, UINT32) ||
 289       !KEY_OK(K_OOB_TIME_USEC, UINT32))
 290     {
 291       ulogd_log(ULOGD_ERROR, "SIP: Mandatory keys missing\n");
 292       return 1;
 293     }
 294   pkt.raw = KEY_VAL(K_RAW_PKT).ptr;
 295   pkt.raw_len = KEY_VAL(K_RAW_PKTLEN).ui32;
 296   pkt.time_sec = KEY_VAL(K_OOB_TIME_SEC).ui32;
 297   pkt.time_usec = KEY_VAL(K_OOB_TIME_USEC).ui32;
 298   struct tm *tm = localtime(&pkt.time_sec);
 299   if (!tm)
 300     sprintf(pkt.time, "<#%d.%06d> ", (int)pkt.time_sec, pkt.time_usec);
 301   else
 302     sprintf(pkt.time, "%04d-%02d-%02d %02d:%02d:%02d.%06d", tm->tm_year+1900, tm->tm_mon+1, tm->tm_mday,
 303       tm->tm_hour, tm->tm_min, tm->tm_sec, pkt.time_usec);
 304   if (verbose)
 305     fprintf(siplog, "\t%s\n", pkt.time);
 306
 307   parse_ip(&pkt);
 308   fflush(siplog);
 309   return 0;
 310 }
 311
 312 /*** Housekeeping ***/
 313
 314 static int sip_init(void)
 315 {
 316   if (config_parse_file("SIP", &sip_cf_log))
 317     {
 318       ulogd_log(ULOGD_ERROR, "SIP: Parsing of configuration file failed\n");
 319       return 1;
 320     }
 321   ulogd_log(ULOGD_INFO, "Initializing SIP plugin, logging to %s\n", sip_cf_log.u.string);
 322   siplog = fopen(sip_cf_log.u.string, "a");
 323   if (!siplog)
 324     {
 325       ulogd_log(ULOGD_ERROR, "Cannot open %s: %s", sip_cf_log.u.string, strerror(errno));
 326       return 1;
 327     }
 328   return 0;
 329 }
 330
 331 static void sip_fini(void)
 332 {
 333   // Logging does not work here
 334   // ulogd_log(ULOGD_INFO, "siplog fini\n");
 335   fclose(siplog);
 336 }
 337
 338 static void sip_signal(int sig)
 339 {
 340   if (sig == SIGHUP)
 341     {
 342       // FIXME: Should reopen the log file here
 343     }
 344 }
 345
 346 static ulog_output_t sip_op = {
 347   .name = "siplog",
 348   .init = sip_init,
 349   .fini = sip_fini,
 350   .output = sip_output,
 351   .signal = sip_signal
 352 };
 353
 354 static void __attribute__((constructor)) constr(void)
 355 {
 356   // All logging goes to stderr instead of the log file
 357   // ulogd_log(ULOGD_INFO, "Registered siplog plugin\n");
 358   if (!init_keys())
 359     register_output(&sip_op);
 360 }