log.c revision 1.21
1/* $OpenBSD: log.c,v 1.21 2001/07/10 10:47:37 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, 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 < 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