log.c revision 1.17 
1/*	$OpenBSD: log.c,v 1.17 2001/04/09 21:21:57 ho 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 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/udp.h>
49#include <arpa/inet.h>
50
51#ifdef HAVE_PCAP
52#include <pcap.h>
53#else
54#include "sysdep/common/pcap.h"
55#endif
56
57#endif /* USE_DEBUG */
58
59#include <errno.h>
60#include <stdio.h>
61#include <stdlib.h>
62#include <string.h>
63#include <syslog.h>
64
65#ifdef __STDC__
66#include <stdarg.h>
67#else
68#include <varargs.h>
69#endif
70
71#include "isakmp_num.h"
72#include "log.h"
73
74static void _log_print (int, int, const char *, va_list, int, int);
75
76static FILE *log_output;
77
78#ifdef USE_DEBUG
79static int log_level[LOG_ENDCLASS];
80
81#define TCPDUMP_MAGIC	0xa1b2c3d4
82#define SNAPLEN		(64 * 1024)
83
84struct packhdr {
85  struct pcap_pkthdr pcap;		/* pcap file packet header */
86  struct {
87    u_int32_t null_family;		/* NULL encapsulation */
88  } null;
89  struct ip ip;				/* IP header (w/o options) */
90  struct udphdr udp;			/* UDP header */
91};
92
93struct isakmp_hdr {
94  u_int8_t icookie[8], rcookie[8];
95  u_int8_t next, ver, type, flags;
96  u_int32_t msgid, len;
97};
98
99static char *pcaplog_file = NULL;
100static FILE *packet_log;
101static u_int8_t pack[SNAPLEN + sizeof (struct packhdr)];
102static struct packhdr *hdr;
103
104static int udp_cksum (const struct ip *, const struct udphdr *, int);
105static u_int16_t in_cksum (const struct ip *, 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 < 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  if (pcaplog_file && strcmp (pcaplog_file, PCAP_FILE_DEFAULT) != 0)
368    free (pcaplog_file);
369
370  pcaplog_file = strdup (newname);
371  if (!pcaplog_file)
372    {
373      log_error ("log_packet_init: strdup (\"%s\") failed", newname);
374      return;
375    }
376
377  old_umask = umask (S_IRWXG | S_IRWXO);
378  packet_log = fopen (pcaplog_file, "w");
379  umask (old_umask);
380
381  if (!packet_log)
382    {
383      log_error ("log_packet_init: fopen (\"%s\", \"w\") failed",
384		 pcaplog_file);
385      return;
386    }
387
388  log_print ("log_packet_init: starting IKE packet capture to file \"%s\"",
389	     pcaplog_file);
390
391  sf_hdr.magic = TCPDUMP_MAGIC;
392  sf_hdr.version_major = PCAP_VERSION_MAJOR;
393  sf_hdr.version_minor = PCAP_VERSION_MINOR;
394  sf_hdr.thiszone = 0;
395  sf_hdr.snaplen = SNAPLEN;
396  sf_hdr.sigfigs = 0;
397  sf_hdr.linktype = DLT_NULL;
398
399  fwrite ((char *)&sf_hdr, sizeof sf_hdr, 1, packet_log);
400  fflush (packet_log);
401
402  /* prep dummy header prepended to each packet */
403  hdr = (struct packhdr *)pack;
404  hdr->null.null_family = AF_INET;
405  hdr->ip.ip_v = 0x4;
406  hdr->ip.ip_hl = 0x5;
407  hdr->ip.ip_p = IPPROTO_UDP;
408  hdr->udp.uh_sport = htons (500);
409  hdr->udp.uh_dport = htons (500);
410}
411
412void
413log_packet_restart (char *newname)
414{
415  struct stat st;
416
417  if (packet_log)
418    {
419      log_print ("log_packet_restart: capture already active on file \"%s\"",
420		 pcaplog_file);
421      return;
422    }
423
424  if (newname)
425    {
426      if (stat (newname, &st) == 0)
427	log_print ("log_packet_restart: won't overwrite existing \"%s\"",
428		   newname);
429      else
430	log_packet_init (newname);
431    }
432  else if (!pcaplog_file)
433    log_packet_init (PCAP_FILE_DEFAULT);
434  else if (stat (pcaplog_file, &st) != 0)
435    log_packet_init (pcaplog_file);
436  else
437    {
438      /* Re-activate capture on current file.  */
439      packet_log = fopen (pcaplog_file, "a");
440      if (!packet_log)
441	log_error ("log_packet_restart: fopen (\"%s\", \"a\") failed",
442		   pcaplog_file);
443      else
444	log_print ("log_packet_restart: capture restarted on file \"%s\"",
445		   pcaplog_file);
446    }
447}
448
449void
450log_packet_stop (void)
451{
452  /* Stop capture.  */
453  if (packet_log)
454    {
455      fclose (packet_log);
456      log_print ("log_packet_stop: stopped capture");
457    }
458  packet_log = 0;
459}
460
461void
462log_packet_iov (struct sockaddr *src, struct sockaddr *dst, struct iovec *iov,
463		int iovcnt)
464{
465  struct isakmp_hdr *isakmphdr;
466  int off, len, i;
467
468  len = 0;
469  for (i = 0; i < iovcnt; i++)
470    len += iov[i].iov_len;
471
472  if (!packet_log || len > SNAPLEN)
473    return;
474
475  /* copy packet into buffer */
476  off = sizeof *hdr;
477  for (i = 0; i < iovcnt; i++)
478    {
479      memcpy (pack + off, iov[i].iov_base, iov[i].iov_len);
480      off += iov[i].iov_len;
481    }
482
483  /* isakmp - turn off the encryption bit in the isakmp hdr */
484  isakmphdr = (struct isakmp_hdr *)(pack + sizeof *hdr);
485  isakmphdr->flags &= ~(ISAKMP_FLAGS_ENC);
486
487  /* udp */
488  len += sizeof hdr->udp;
489  hdr->udp.uh_ulen = htons (len);
490
491  /* ip */
492  len += sizeof hdr->ip;
493  hdr->ip.ip_len = htons (len);
494
495  switch (src->sa_family)
496    {
497    case AF_INET:
498      hdr->ip.ip_src.s_addr = ((struct sockaddr_in *)src)->sin_addr.s_addr;
499      hdr->ip.ip_dst.s_addr = ((struct sockaddr_in *)dst)->sin_addr.s_addr;
500      break;
501    case AF_INET6:
502      /* XXX TBD */
503    default:
504      hdr->ip.ip_src.s_addr = 0x02020202;
505      hdr->ip.ip_dst.s_addr = 0x01010101;
506    }
507
508  /* Let's use the IP ID as a "packet counter".  */
509  i = ntohs (hdr->ip.ip_id) + 1;
510  hdr->ip.ip_id = htons (i);
511
512  /* Calculate UDP checksum.  */
513  hdr->udp.uh_sum = 0;
514  hdr->udp.uh_sum = udp_cksum (&hdr->ip, &hdr->udp, len);
515
516  /* Calculate IP header checksum. */
517  hdr->ip.ip_sum = 0;
518  hdr->ip.ip_sum = in_cksum (&hdr->ip, hdr->ip.ip_hl << 2);
519
520  /* null header */
521  len += sizeof hdr->null;
522
523  /* pcap file packet header */
524  gettimeofday (&hdr->pcap.ts, 0);
525  hdr->pcap.caplen = len;
526  hdr->pcap.len = len;
527  len += sizeof hdr->pcap;
528
529  fwrite (pack, len, 1, packet_log);
530  fflush (packet_log);
531  return;
532}
533
534/* Copied from tcpdump/print-udp.c  */
535static int
536udp_cksum (const struct ip *ip, const struct udphdr *up, int len)
537{
538  int i, tlen;
539  union phu {
540    struct phdr {
541      u_int32_t src;
542      u_int32_t dst;
543      u_char mbz;
544      u_char proto;
545      u_int16_t len;
546    } ph;
547    u_int16_t pa[6];
548  } phu;
549  const u_int16_t *sp;
550  u_int32_t sum;
551  tlen = ntohs (ip->ip_len) - ((const char *)up-(const char*)ip);
552
553  /* pseudo-header.. */
554  phu.ph.len = htons (tlen);
555  phu.ph.mbz = 0;
556  phu.ph.proto = ip->ip_p;
557  memcpy (&phu.ph.src, &ip->ip_src.s_addr, sizeof (u_int32_t));
558  memcpy (&phu.ph.dst, &ip->ip_dst.s_addr, sizeof (u_int32_t));
559
560  sp = &phu.pa[0];
561  sum = sp[0] + sp[1] + sp[2] + sp[3] + sp[4] + sp[5];
562
563  sp = (const u_int16_t *)up;
564
565  for (i = 0; i < (tlen&~1); i += 2)
566    sum += *sp++;
567
568  if (tlen & 1) {
569    sum += htons ((*(const char *)sp) << 8);
570  }
571
572  while (sum > 0xffff)
573    sum = (sum & 0xffff) + (sum >> 16);
574  sum = ~sum & 0xffff;
575
576  return sum;
577}
578
579/* Copied from tcpdump/print-ip.c, modified.  */
580static u_int16_t
581in_cksum (const struct ip *ip, int len)
582{
583  int nleft = len;
584  const u_short *w = (const u_short *)ip;
585  u_short answer;
586  int sum = 0;
587
588  while (nleft > 1)  {
589    sum += *w++;
590    nleft -= 2;
591  }
592  if (nleft == 1)
593    sum += htons (*(u_char *)w<<8);
594
595  sum = (sum >> 16) + (sum & 0xffff);     /* add hi 16 to low 16 */
596  sum += (sum >> 16);                     /* add carry */
597  answer = ~sum;                          /* truncate to 16 bits */
598  return answer;
599}
600
601
602#endif /* USE_DEBUG */
603