log.c revision 1.22 
1/*	$OpenBSD: log.c,v 1.22 2001/08/18 20:50:02 deraadt Exp $	*/
2/*	$EOM: log.c,v 1.30 2000/09/29 08:19:23 niklas Exp $	*/
3
4/*
5 * Copyright (c) 1998, 1999, 2001 Niklas Hallqvist.  All rights reserved.
6 * Copyright (c) 1999, 2000, 2001 H�kan Olsson.  All rights reserved.
7 *
8 * Redistribution and use in source and binary forms, with or without
9 * modification, are permitted provided that the following conditions
10 * are met:
11 * 1. Redistributions of source code must retain the above copyright
12 *    notice, this list of conditions and the following disclaimer.
13 * 2. Redistributions in binary form must reproduce the above copyright
14 *    notice, this list of conditions and the following disclaimer in the
15 *    documentation and/or other materials provided with the distribution.
16 * 3. All advertising materials mentioning features or use of this software
17 *    must display the following acknowledgement:
18 *	This product includes software developed by Ericsson Radio Systems.
19 * 4. The name of the author may not be used to endorse or promote products
20 *    derived from this software without specific prior written permission.
21 *
22 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR ``AS IS'' AND ANY EXPRESS OR
23 * IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
24 * OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.
25 * IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY DIRECT, INDIRECT,
26 * INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT
27 * NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
28 * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
29 * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
30 * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
31 * THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
32 */
33
34/*
35 * This code was written under funding by Ericsson Radio Systems.
36 */
37
38#include <sys/types.h>
39#include <sys/time.h>
40
41#ifdef USE_DEBUG
42#include <sys/socket.h>
43#include <sys/stat.h>
44#include <sys/uio.h>
45#include <netinet/in.h>
46#include <netinet/in_systm.h>
47#include <netinet/ip.h>
48#include <netinet/ip6.h>
49#include <netinet/udp.h>
50#include <arpa/inet.h>
51
52#ifdef HAVE_PCAP
53#include <pcap.h>
54#else
55#include "sysdep/common/pcap.h"
56#endif
57
58#endif /* USE_DEBUG */
59
60#include <errno.h>
61#include <stdio.h>
62#include <stdlib.h>
63#include <string.h>
64#include <syslog.h>
65
66#ifdef __STDC__
67#include <stdarg.h>
68#else
69#include <varargs.h>
70#endif
71
72#include "isakmp_num.h"
73#include "log.h"
74
75static void _log_print (int, int, const char *, va_list, int, int);
76
77static FILE *log_output;
78
79#ifdef USE_DEBUG
80static int log_level[LOG_ENDCLASS];
81
82#define TCPDUMP_MAGIC	0xa1b2c3d4
83#define SNAPLEN		(64 * 1024)
84
85struct packhdr {
86  struct pcap_pkthdr pcap;		/* pcap file packet header */
87  u_int32_t sa_family;			/* address family */
88  union {
89    struct ip ip4;			/* IPv4 header (w/o options) */
90    struct ip6_hdr ip6;			/* IPv6 header */
91  } ip;
92};
93
94struct isakmp_hdr {
95  u_int8_t icookie[8], rcookie[8];
96  u_int8_t next, ver, type, flags;
97  u_int32_t msgid, len;
98};
99
100static char *pcaplog_file = NULL;
101static FILE *packet_log;
102static u_int8_t *packet_buf = NULL;
103
104static int udp_cksum (struct packhdr *, const struct udphdr *, u_int16_t *);
105static u_int16_t in_cksum (const u_int16_t *, int);
106#endif /* USE_DEBUG */
107
108void
109log_init (void)
110{
111  log_output = stderr;
112}
113
114void
115log_to (FILE *f)
116{
117  if (!log_output && f)
118    closelog ();
119  log_output = f;
120  if (!f)
121    openlog ("isakmpd", LOG_PID | LOG_CONS, LOG_DAEMON);
122}
123
124FILE *
125log_current (void)
126{
127  return log_output;
128}
129
130static char *
131_log_get_class (int error_class)
132{
133  /* XXX For test purposes. To be removed later on?  */
134  static char *class_text[] = LOG_CLASSES_TEXT;
135
136  if (error_class < 0)
137    return "Dflt";
138  else if (error_class >= LOG_ENDCLASS)
139    return "Unkn";
140  else
141    return class_text[error_class];
142}
143
144static void
145_log_print (int error, int syslog_level, const char *fmt, va_list ap,
146	    int class, int level)
147{
148  char buffer[LOG_SIZE], nbuf[LOG_SIZE + 32];
149  static const char fallback_msg[] =
150    "write to log file failed (errno %d), redirecting output to syslog";
151  int len;
152  struct tm *tm;
153  struct timeval now;
154  time_t t;
155
156  len = vsnprintf (buffer, LOG_SIZE, fmt, ap);
157  if (len > 0 && len < LOG_SIZE - 1 && error)
158    snprintf (buffer + len, LOG_SIZE - len, ": %s", strerror (errno));
159  if (log_output)
160    {
161      gettimeofday (&now, 0);
162      t = now.tv_sec;
163      tm = localtime (&t);
164      if (class >= 0)
165	sprintf (nbuf, "%02d%02d%02d.%06ld %s %02d ", tm->tm_hour,
166		 tm->tm_min, tm->tm_sec, now.tv_usec, _log_get_class (class),
167		 level);
168      else /* LOG_PRINT (-1) or LOG_REPORT (-2) */
169	sprintf (nbuf, "%02d%02d%02d.%06ld %s ", tm->tm_hour,
170		 tm->tm_min, tm->tm_sec, now.tv_usec,
171		 class == LOG_PRINT ? "Default" : "Report>");
172      strcat (nbuf, buffer);
173      strcat (nbuf, "\n");
174
175      if (fwrite (nbuf, strlen (nbuf), 1, log_output) == 0)
176	{
177	  /* Report fallback.  */
178	  syslog (LOG_ALERT, fallback_msg, errno);
179	  fprintf (log_output, fallback_msg, errno);
180
181	  /*
182	   * Close log_output to prevent isakmpd from locking the file.
183	   * We may need to explicitly close stdout to do this properly.
184	   * XXX - Figure out how to match two FILE *'s and rewrite.
185	   */
186	  if (fileno (log_output) != -1
187	      && fileno (stdout) == fileno (log_output))
188	    fclose (stdout);
189	  fclose (log_output);
190
191	  /* Fallback to syslog.  */
192	  log_to (0);
193
194	  /* (Re)send current message to syslog().  */
195	  syslog (class == LOG_REPORT ? LOG_ALERT
196		  : syslog_level, "%s", buffer);
197	}
198    }
199  else
200    syslog (class == LOG_REPORT ? LOG_ALERT : syslog_level, "%s", buffer);
201}
202
203#ifdef USE_DEBUG
204void
205#ifdef __STDC__
206log_debug (int cls, int level, const char *fmt, ...)
207#else
208log_debug (cls, level, fmt, va_alist)
209     int cls;
210     int level;
211     const char *fmt;
212     va_dcl
213#endif
214{
215  va_list ap;
216
217  /*
218   * If we are not debugging this class, or the level is too low, just return.
219   */
220  if (cls >= 0 && (log_level[cls] == 0 || level > log_level[cls]))
221    return;
222#ifdef __STDC__
223  va_start (ap, fmt);
224#else
225  va_start (ap);
226  fmt = va_arg (ap, const char *);
227#endif
228  _log_print (0, LOG_DEBUG, fmt, ap, cls, level);
229  va_end (ap);
230}
231
232void
233log_debug_buf (int cls, int level, const char *header, const u_int8_t *buf,
234	       size_t sz)
235{
236  char s[73];
237  int i, j;
238
239  /*
240   * If we are not debugging this class, or the level is too low, just return.
241   */
242  if (cls >= 0 && (log_level[cls] == 0 || level > log_level[cls]))
243    return;
244
245  log_debug (cls, level, "%s:", header);
246  for (i = j = 0; i < sz;)
247    {
248      sprintf (s + j, "%02x", buf[i++]);
249      j += 2;
250      if (i % 4 == 0)
251	{
252	  if (i % 32 == 0)
253	    {
254	      s[j] = '\0';
255	      log_debug (cls, level, "%s", s);
256	      j = 0;
257	    }
258	  else
259	    s[j++] = ' ';
260	}
261    }
262  if (j)
263    {
264      s[j] = '\0';
265      log_debug (cls, level, "%s", s);
266    }
267}
268
269void
270log_debug_cmd (int cls, int level)
271{
272  if (cls < 0 || cls >= LOG_ENDCLASS)
273    {
274      log_print ("log_debug_cmd: invalid debugging class %d", cls);
275      return;
276    }
277
278  if (level < 0)
279    {
280      log_print ("log_debug_cmd: invalid debugging level %d for class %d",
281		 level, cls);
282      return;
283    }
284
285  if (level == log_level[cls])
286    log_print ("log_debug_cmd: log level unchanged for class %d", cls);
287  else
288    {
289      log_print ("log_debug_cmd: log level changed from %d to %d for class %d",
290		 log_level[cls], level, cls);
291      log_level[cls] = level;
292    }
293}
294#endif /* USE_DEBUG */
295
296void
297#ifdef __STDC__
298log_print (const char *fmt, ...)
299#else
300log_print (fmt, va_alist)
301     const char *fmt;
302     va_dcl
303#endif
304{
305  va_list ap;
306
307#ifdef __STDC__
308  va_start (ap, fmt);
309#else
310  va_start (ap);
311  fmt = va_arg (ap, const char *);
312#endif
313  _log_print (0, LOG_NOTICE, fmt, ap, LOG_PRINT, 0);
314  va_end (ap);
315}
316
317void
318#ifdef __STDC__
319log_error (const char *fmt, ...)
320#else
321log_error (fmt, va_alist)
322     const char *fmt;
323     va_dcl
324#endif
325{
326  va_list ap;
327
328#ifdef __STDC__
329  va_start (ap, fmt);
330#else
331  va_start (ap);
332  fmt = va_arg (ap, const char *);
333#endif
334  _log_print (1, LOG_ERR, fmt, ap, LOG_PRINT, 0);
335  va_end (ap);
336}
337
338void
339#ifdef __STDC__
340log_fatal (const char *fmt, ...)
341#else
342log_fatal (fmt, va_alist)
343     const char *fmt;
344     va_dcl
345#endif
346{
347  va_list ap;
348
349#ifdef __STDC__
350  va_start (ap, fmt);
351#else
352  va_start (ap);
353  fmt = va_arg (ap, const char *);
354#endif
355  _log_print (1, LOG_CRIT, fmt, ap, LOG_PRINT, 0);
356  va_end (ap);
357  exit (1);
358}
359
360#ifdef USE_DEBUG
361void
362log_packet_init (char *newname)
363{
364  struct pcap_file_header sf_hdr;
365  mode_t old_umask;
366
367  /* Allocate packet buffer first time through.  */
368  if (!packet_buf)
369    packet_buf = malloc (SNAPLEN);
370
371  if (!packet_buf)
372    {
373      log_error ("log_packet_init: malloc (%d) failed", SNAPLEN);
374      return;
375    }
376
377  if (pcaplog_file && strcmp (pcaplog_file, PCAP_FILE_DEFAULT) != 0)
378    free (pcaplog_file);
379
380  pcaplog_file = strdup (newname);
381  if (!pcaplog_file)
382    {
383      log_error ("log_packet_init: strdup (\"%s\") failed", newname);
384      return;
385    }
386
387  old_umask = umask (S_IRWXG | S_IRWXO);
388  packet_log = fopen (pcaplog_file, "w");
389  umask (old_umask);
390
391  if (!packet_log)
392    {
393      log_error ("log_packet_init: fopen (\"%s\", \"w\") failed",
394		 pcaplog_file);
395      return;
396    }
397
398  log_print ("log_packet_init: starting IKE packet capture to file \"%s\"",
399	     pcaplog_file);
400
401  sf_hdr.magic = TCPDUMP_MAGIC;
402  sf_hdr.version_major = PCAP_VERSION_MAJOR;
403  sf_hdr.version_minor = PCAP_VERSION_MINOR;
404  sf_hdr.thiszone = 0;
405  sf_hdr.snaplen = SNAPLEN;
406  sf_hdr.sigfigs = 0;
407  sf_hdr.linktype = DLT_NULL;
408
409  fwrite ((char *)&sf_hdr, sizeof sf_hdr, 1, packet_log);
410  fflush (packet_log);
411}
412
413void
414log_packet_restart (char *newname)
415{
416  struct stat st;
417
418  if (packet_log)
419    {
420      log_print ("log_packet_restart: capture already active on file \"%s\"",
421		 pcaplog_file);
422      return;
423    }
424
425  if (newname)
426    {
427      if (stat (newname, &st) == 0)
428	log_print ("log_packet_restart: won't overwrite existing \"%s\"",
429		   newname);
430      else
431	log_packet_init (newname);
432    }
433  else if (!pcaplog_file)
434    log_packet_init (PCAP_FILE_DEFAULT);
435  else if (stat (pcaplog_file, &st) != 0)
436    log_packet_init (pcaplog_file);
437  else
438    {
439      /* Re-activate capture on current file.  */
440      packet_log = fopen (pcaplog_file, "a");
441      if (!packet_log)
442	log_error ("log_packet_restart: fopen (\"%s\", \"a\") failed",
443		   pcaplog_file);
444      else
445	log_print ("log_packet_restart: capture restarted on file \"%s\"",
446		   pcaplog_file);
447    }
448}
449
450void
451log_packet_stop (void)
452{
453  /* Stop capture.  */
454  if (packet_log)
455    {
456      fclose (packet_log);
457      log_print ("log_packet_stop: stopped capture");
458    }
459  packet_log = 0;
460}
461
462void
463log_packet_iov (struct sockaddr *src, struct sockaddr *dst, struct iovec *iov,
464		int iovcnt)
465{
466  struct isakmp_hdr *isakmphdr;
467  struct packhdr hdr;
468  struct udphdr udp;
469  int off, datalen, hdrlen, i;
470
471  for (i = 0, datalen = 0; i < iovcnt; i++)
472    datalen += iov[i].iov_len;
473
474  if (!packet_log || datalen > SNAPLEN)
475    return;
476
477  /* copy packet into buffer */
478  for (i = 0, off = 0; i < iovcnt; i++)
479    {
480      memcpy (packet_buf + off, iov[i].iov_base, iov[i].iov_len);
481      off += iov[i].iov_len;
482    }
483
484  memset (&hdr, 0, sizeof hdr);
485  memset (&udp, 0, sizeof udp);
486
487  /* isakmp - turn off the encryption bit in the isakmp hdr */
488  isakmphdr = (struct isakmp_hdr *)packet_buf;
489  isakmphdr->flags &= ~(ISAKMP_FLAGS_ENC);
490
491  /* udp */
492  udp.uh_sport = udp.uh_dport = htons (500);
493  datalen += sizeof udp;
494  udp.uh_ulen = htons (datalen);
495
496  /* ip */
497  hdr.sa_family = htonl (src->sa_family);
498  switch (src->sa_family)
499    {
500    default:
501      /* Assume IPv4. XXX Can 'default' ever happen here?  */
502      hdr.sa_family = htonl (AF_INET);
503      hdr.ip.ip4.ip_src.s_addr = 0x02020202;
504      hdr.ip.ip4.ip_dst.s_addr = 0x01010101;
505      /* The rest of the setup is common to AF_INET.  */
506      goto setup_ip4;
507
508    case AF_INET:
509      hdr.ip.ip4.ip_src.s_addr = ((struct sockaddr_in *)src)->sin_addr.s_addr;
510      hdr.ip.ip4.ip_dst.s_addr = ((struct sockaddr_in *)dst)->sin_addr.s_addr;
511
512    setup_ip4:
513      hdrlen = sizeof hdr.ip.ip4;
514      hdr.ip.ip4.ip_v = 0x4;
515      hdr.ip.ip4.ip_hl = 0x5;
516      hdr.ip.ip4.ip_p = IPPROTO_UDP;
517      hdr.ip.ip4.ip_len = htons (datalen + hdrlen);
518      /* Let's use the IP ID as a "packet counter".  */
519      i = ntohs (hdr.ip.ip4.ip_id) + 1;
520      hdr.ip.ip4.ip_id = htons (i);
521      /* Calculate IP header checksum. */
522      hdr.ip.ip4.ip_sum = in_cksum ((u_int16_t *)&hdr.ip.ip4,
523				    hdr.ip.ip4.ip_hl << 2);
524      break;
525
526    case AF_INET6:
527      hdrlen = sizeof (hdr.ip.ip6);
528      hdr.ip.ip6.ip6_vfc = IPV6_VERSION;
529      hdr.ip.ip6.ip6_nxt = IPPROTO_UDP;
530      hdr.ip.ip6.ip6_plen = udp.uh_ulen;
531      memcpy (&hdr.ip.ip6.ip6_src, &((struct sockaddr_in6 *)src)->sin6_addr,
532	      sizeof hdr.ip.ip6.ip6_src);
533      memcpy (&hdr.ip.ip6.ip6_dst, &((struct sockaddr_in6 *)dst)->sin6_addr,
534	      sizeof hdr.ip.ip6.ip6_dst);
535      break;
536   }
537
538  /* Calculate UDP checksum.  */
539  udp.uh_sum = udp_cksum (&hdr, &udp, (u_int16_t *)packet_buf);
540  hdrlen += sizeof hdr.sa_family;
541
542  /* pcap file packet header */
543  gettimeofday (&hdr.pcap.ts, 0);
544  hdr.pcap.caplen = datalen + hdrlen;
545  hdr.pcap.len = datalen + hdrlen;
546
547  hdrlen += sizeof (struct pcap_pkthdr);
548  datalen -= sizeof (struct udphdr);
549
550  /* Write to pcap file.  */
551  fwrite (&hdr, hdrlen, 1, packet_log);			/* pcap + IP */
552  fwrite (&udp, sizeof (struct udphdr), 1, packet_log);	/* UDP */
553  fwrite (packet_buf, datalen, 1, packet_log);		/* IKE-data */
554  fflush (packet_log);
555  return;
556}
557
558/* Copied from tcpdump/print-udp.c, mostly rewritten.  */
559static int
560udp_cksum (struct packhdr *hdr, const struct udphdr *u, u_int16_t *d)
561{
562  int i, hdrlen, tlen = ntohs (u->uh_ulen) - sizeof (struct udphdr);
563  struct ip *ip4;
564  struct ip6_hdr *ip6;
565
566  union phu {
567    struct ip4pseudo {
568      struct in_addr src;
569      struct in_addr dst;
570      u_int8_t z;
571      u_int8_t proto;
572      u_int16_t len;
573    } ip4p;
574    struct ip6pseudo {
575      struct in6_addr src;
576      struct in6_addr dst;
577      u_int32_t plen;
578      u_int16_t z0;
579      u_int8_t z1;
580      u_int8_t nxt;
581    } ip6p;
582    u_int16_t pa[20];
583  } phu;
584  const u_int16_t *sp;
585  u_int32_t sum;
586
587  /* Setup pseudoheader.  */
588  memset (phu.pa, 0, sizeof phu);
589  switch (ntohl (hdr->sa_family))
590    {
591    case AF_INET:
592      ip4 = &hdr->ip.ip4;
593      memcpy (&phu.ip4p.src, &ip4->ip_src, sizeof (struct in_addr));
594      memcpy (&phu.ip4p.dst, &ip4->ip_dst, sizeof (struct in_addr));
595      phu.ip4p.proto = ip4->ip_p;
596      phu.ip4p.len = u->uh_ulen;
597      hdrlen = sizeof phu.ip4p;
598      break;
599
600    case AF_INET6:
601      ip6 = &hdr->ip.ip6;
602      memcpy (&phu.ip6p.src, &ip6->ip6_src, sizeof (phu.ip6p.src));
603      memcpy (&phu.ip6p.dst, &ip6->ip6_dst, sizeof (phu.ip6p.dst));
604      phu.ip6p.plen = u->uh_ulen;
605      phu.ip6p.nxt = ip6->ip6_nxt;
606      hdrlen = sizeof phu.ip6p;
607      break;
608
609    default:
610      return 0;
611    }
612
613  /* IPv6 wants a 0xFFFF checksum "on error", not 0x0.  */
614  if (tlen < 0)
615    return (ntohl (hdr->sa_family) == AF_INET ? 0 : 0xFFFF);
616
617  sum = 0;
618  for (i = 0; i < hdrlen; i += 2)
619    sum += phu.pa[i/2];
620
621  sp = (u_int16_t *)u;
622  for (i = 0; i < sizeof (struct udphdr); i += 2)
623    sum += *sp++;
624
625  sp = d;
626  for (i = 0; i < (tlen&~1); i += 2)
627    sum += *sp++;
628
629  if (tlen & 1)
630    sum += htons ((*(const char *)sp) << 8);
631
632  while (sum > 0xffff)
633    sum = (sum & 0xffff) + (sum >> 16);
634  sum = ~sum & 0xffff;
635
636  return sum;
637}
638
639/* Copied from tcpdump/print-ip.c, modified.  */
640static u_int16_t
641in_cksum (const u_int16_t *w, int len)
642{
643  int nleft = len, sum = 0;
644  u_int16_t answer;
645
646  while (nleft > 1)  {
647    sum += *w++;
648    nleft -= 2;
649  }
650  if (nleft == 1)
651    sum += htons (*(u_char *)w << 8);
652
653  sum = (sum >> 16) + (sum & 0xffff);     /* add hi 16 to low 16 */
654  sum += (sum >> 16);                     /* add carry */
655  answer = ~sum;                          /* truncate to 16 bits */
656  return answer;
657}
658
659#endif /* USE_DEBUG */
660