1 /* $OpenBSD: log.c,v 1.24 2001/10/05 08:18: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 75 static void _log_print (int, int, const char *, va_list, int, int); 76 77 static FILE *log_output; 78 79 #ifdef USE_DEBUG 80 static int log_level[LOG_ENDCLASS]; 81 82 #define TCPDUMP_MAGIC 0xa1b2c3d4 83 #define SNAPLEN (64 * 1024) 84 85 struct 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 94 struct 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 100 static char *pcaplog_file = NULL; 101 static FILE *packet_log; 102 static u_int8_t *packet_buf = NULL; 103 104 static int udp_cksum (struct packhdr *, const struct udphdr *, u_int16_t *); 105 static u_int16_t in_cksum (const u_int16_t *, int); 106 #endif /* USE_DEBUG */ 107 108 void 109 log_init (void) 110 { 111 log_output = stderr; 112 } 113 114 void 115 log_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 124 FILE * 125 log_current (void) 126 { 127 return log_output; 128 } 129 130 static 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 144 static 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 204 void 205 #ifdef __STDC__ 206 log_debug (int cls, int level, const char *fmt, ...) 207 #else 208 log_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 232 void 233 log_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 269 void 270 log_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 295 void 296 log_debug_toggle (void) 297 { 298 static int log_level_copy[LOG_ENDCLASS], toggle = 0; 299 300 if (!toggle) 301 { 302 LOG_DBG ((LOG_MISC, 50, "log_debug_toggle: debug levels cleared")); 303 memcpy (&log_level_copy, &log_level, sizeof log_level); 304 memset (&log_level, 0, sizeof log_level); 305 } 306 else 307 { 308 memcpy (&log_level, &log_level_copy, sizeof log_level); 309 LOG_DBG ((LOG_MISC, 50, "log_debug_toggle: debug levels restored")); 310 } 311 toggle = !toggle; 312 } 313 #endif /* USE_DEBUG */ 314 315 void 316 #ifdef __STDC__ 317 log_print (const char *fmt, ...) 318 #else 319 log_print (fmt, va_alist) 320 const char *fmt; 321 va_dcl 322 #endif 323 { 324 va_list ap; 325 326 #ifdef __STDC__ 327 va_start (ap, fmt); 328 #else 329 va_start (ap); 330 fmt = va_arg (ap, const char *); 331 #endif 332 _log_print (0, LOG_NOTICE, fmt, ap, LOG_PRINT, 0); 333 va_end (ap); 334 } 335 336 void 337 #ifdef __STDC__ 338 log_error (const char *fmt, ...) 339 #else 340 log_error (fmt, va_alist) 341 const char *fmt; 342 va_dcl 343 #endif 344 { 345 va_list ap; 346 347 #ifdef __STDC__ 348 va_start (ap, fmt); 349 #else 350 va_start (ap); 351 fmt = va_arg (ap, const char *); 352 #endif 353 _log_print (1, LOG_ERR, fmt, ap, LOG_PRINT, 0); 354 va_end (ap); 355 } 356 357 void 358 #ifdef __STDC__ 359 log_fatal (const char *fmt, ...) 360 #else 361 log_fatal (fmt, va_alist) 362 const char *fmt; 363 va_dcl 364 #endif 365 { 366 va_list ap; 367 368 #ifdef __STDC__ 369 va_start (ap, fmt); 370 #else 371 va_start (ap); 372 fmt = va_arg (ap, const char *); 373 #endif 374 _log_print (1, LOG_CRIT, fmt, ap, LOG_PRINT, 0); 375 va_end (ap); 376 exit (1); 377 } 378 379 #ifdef USE_DEBUG 380 void 381 log_packet_init (char *newname) 382 { 383 struct pcap_file_header sf_hdr; 384 mode_t old_umask; 385 386 /* Allocate packet buffer first time through. */ 387 if (!packet_buf) 388 packet_buf = malloc (SNAPLEN); 389 390 if (!packet_buf) 391 { 392 log_error ("log_packet_init: malloc (%d) failed", SNAPLEN); 393 return; 394 } 395 396 if (pcaplog_file && strcmp (pcaplog_file, PCAP_FILE_DEFAULT) != 0) 397 free (pcaplog_file); 398 399 pcaplog_file = strdup (newname); 400 if (!pcaplog_file) 401 { 402 log_error ("log_packet_init: strdup (\"%s\") failed", newname); 403 return; 404 } 405 406 old_umask = umask (S_IRWXG | S_IRWXO); 407 packet_log = fopen (pcaplog_file, "w"); 408 umask (old_umask); 409 410 if (!packet_log) 411 { 412 log_error ("log_packet_init: fopen (\"%s\", \"w\") failed", 413 pcaplog_file); 414 return; 415 } 416 417 log_print ("log_packet_init: starting IKE packet capture to file \"%s\"", 418 pcaplog_file); 419 420 sf_hdr.magic = TCPDUMP_MAGIC; 421 sf_hdr.version_major = PCAP_VERSION_MAJOR; 422 sf_hdr.version_minor = PCAP_VERSION_MINOR; 423 sf_hdr.thiszone = 0; 424 sf_hdr.snaplen = SNAPLEN; 425 sf_hdr.sigfigs = 0; 426 sf_hdr.linktype = DLT_NULL; 427 428 fwrite ((char *)&sf_hdr, sizeof sf_hdr, 1, packet_log); 429 fflush (packet_log); 430 } 431 432 void 433 log_packet_restart (char *newname) 434 { 435 struct stat st; 436 437 if (packet_log) 438 { 439 log_print ("log_packet_restart: capture already active on file \"%s\"", 440 pcaplog_file); 441 return; 442 } 443 444 if (newname) 445 { 446 if (stat (newname, &st) == 0) 447 log_print ("log_packet_restart: won't overwrite existing \"%s\"", 448 newname); 449 else 450 log_packet_init (newname); 451 } 452 else if (!pcaplog_file) 453 log_packet_init (PCAP_FILE_DEFAULT); 454 else if (stat (pcaplog_file, &st) != 0) 455 log_packet_init (pcaplog_file); 456 else 457 { 458 /* Re-activate capture on current file. */ 459 packet_log = fopen (pcaplog_file, "a"); 460 if (!packet_log) 461 log_error ("log_packet_restart: fopen (\"%s\", \"a\") failed", 462 pcaplog_file); 463 else 464 log_print ("log_packet_restart: capture restarted on file \"%s\"", 465 pcaplog_file); 466 } 467 } 468 469 void 470 log_packet_stop (void) 471 { 472 /* Stop capture. */ 473 if (packet_log) 474 { 475 fclose (packet_log); 476 log_print ("log_packet_stop: stopped capture"); 477 } 478 packet_log = 0; 479 } 480 481 void 482 log_packet_iov (struct sockaddr *src, struct sockaddr *dst, struct iovec *iov, 483 int iovcnt) 484 { 485 struct isakmp_hdr *isakmphdr; 486 struct packhdr hdr; 487 struct udphdr udp; 488 int off, datalen, hdrlen, i; 489 struct timeval tv; 490 491 for (i = 0, datalen = 0; i < iovcnt; i++) 492 datalen += iov[i].iov_len; 493 494 if (!packet_log || datalen > SNAPLEN) 495 return; 496 497 /* copy packet into buffer */ 498 for (i = 0, off = 0; i < iovcnt; i++) 499 { 500 memcpy (packet_buf + off, iov[i].iov_base, iov[i].iov_len); 501 off += iov[i].iov_len; 502 } 503 504 memset (&hdr, 0, sizeof hdr); 505 memset (&udp, 0, sizeof udp); 506 507 /* isakmp - turn off the encryption bit in the isakmp hdr */ 508 isakmphdr = (struct isakmp_hdr *)packet_buf; 509 isakmphdr->flags &= ~(ISAKMP_FLAGS_ENC); 510 511 /* udp */ 512 udp.uh_sport = udp.uh_dport = htons (500); 513 datalen += sizeof udp; 514 udp.uh_ulen = htons (datalen); 515 516 /* ip */ 517 hdr.sa_family = htonl (src->sa_family); 518 switch (src->sa_family) 519 { 520 default: 521 /* Assume IPv4. XXX Can 'default' ever happen here? */ 522 hdr.sa_family = htonl (AF_INET); 523 hdr.ip.ip4.ip_src.s_addr = 0x02020202; 524 hdr.ip.ip4.ip_dst.s_addr = 0x01010101; 525 /* The rest of the setup is common to AF_INET. */ 526 goto setup_ip4; 527 528 case AF_INET: 529 hdr.ip.ip4.ip_src.s_addr = ((struct sockaddr_in *)src)->sin_addr.s_addr; 530 hdr.ip.ip4.ip_dst.s_addr = ((struct sockaddr_in *)dst)->sin_addr.s_addr; 531 532 setup_ip4: 533 hdrlen = sizeof hdr.ip.ip4; 534 hdr.ip.ip4.ip_v = 0x4; 535 hdr.ip.ip4.ip_hl = 0x5; 536 hdr.ip.ip4.ip_p = IPPROTO_UDP; 537 hdr.ip.ip4.ip_len = htons (datalen + hdrlen); 538 /* Let's use the IP ID as a "packet counter". */ 539 i = ntohs (hdr.ip.ip4.ip_id) + 1; 540 hdr.ip.ip4.ip_id = htons (i); 541 /* Calculate IP header checksum. */ 542 hdr.ip.ip4.ip_sum = in_cksum ((u_int16_t *)&hdr.ip.ip4, 543 hdr.ip.ip4.ip_hl << 2); 544 break; 545 546 case AF_INET6: 547 hdrlen = sizeof (hdr.ip.ip6); 548 hdr.ip.ip6.ip6_vfc = IPV6_VERSION; 549 hdr.ip.ip6.ip6_nxt = IPPROTO_UDP; 550 hdr.ip.ip6.ip6_plen = udp.uh_ulen; 551 memcpy (&hdr.ip.ip6.ip6_src, &((struct sockaddr_in6 *)src)->sin6_addr, 552 sizeof hdr.ip.ip6.ip6_src); 553 memcpy (&hdr.ip.ip6.ip6_dst, &((struct sockaddr_in6 *)dst)->sin6_addr, 554 sizeof hdr.ip.ip6.ip6_dst); 555 break; 556 } 557 558 /* Calculate UDP checksum. */ 559 udp.uh_sum = udp_cksum (&hdr, &udp, (u_int16_t *)packet_buf); 560 hdrlen += sizeof hdr.sa_family; 561 562 /* pcap file packet header */ 563 gettimeofday (&tv, 0); 564 hdr.pcap.ts.tv_sec = tv.tv_sec; 565 hdr.pcap.ts.tv_usec = tv.tv_usec; 566 hdr.pcap.caplen = datalen + hdrlen; 567 hdr.pcap.len = datalen + hdrlen; 568 569 hdrlen += sizeof (struct pcap_pkthdr); 570 datalen -= sizeof (struct udphdr); 571 572 /* Write to pcap file. */ 573 fwrite (&hdr, hdrlen, 1, packet_log); /* pcap + IP */ 574 fwrite (&udp, sizeof (struct udphdr), 1, packet_log); /* UDP */ 575 fwrite (packet_buf, datalen, 1, packet_log); /* IKE-data */ 576 fflush (packet_log); 577 return; 578 } 579 580 /* Copied from tcpdump/print-udp.c, mostly rewritten. */ 581 static int 582 udp_cksum (struct packhdr *hdr, const struct udphdr *u, u_int16_t *d) 583 { 584 int i, hdrlen, tlen = ntohs (u->uh_ulen) - sizeof (struct udphdr); 585 struct ip *ip4; 586 struct ip6_hdr *ip6; 587 588 union phu { 589 struct ip4pseudo { 590 struct in_addr src; 591 struct in_addr dst; 592 u_int8_t z; 593 u_int8_t proto; 594 u_int16_t len; 595 } ip4p; 596 struct ip6pseudo { 597 struct in6_addr src; 598 struct in6_addr dst; 599 u_int32_t plen; 600 u_int16_t z0; 601 u_int8_t z1; 602 u_int8_t nxt; 603 } ip6p; 604 u_int16_t pa[20]; 605 } phu; 606 const u_int16_t *sp; 607 u_int32_t sum; 608 609 /* Setup pseudoheader. */ 610 memset (phu.pa, 0, sizeof phu); 611 switch (ntohl (hdr->sa_family)) 612 { 613 case AF_INET: 614 ip4 = &hdr->ip.ip4; 615 memcpy (&phu.ip4p.src, &ip4->ip_src, sizeof (struct in_addr)); 616 memcpy (&phu.ip4p.dst, &ip4->ip_dst, sizeof (struct in_addr)); 617 phu.ip4p.proto = ip4->ip_p; 618 phu.ip4p.len = u->uh_ulen; 619 hdrlen = sizeof phu.ip4p; 620 break; 621 622 case AF_INET6: 623 ip6 = &hdr->ip.ip6; 624 memcpy (&phu.ip6p.src, &ip6->ip6_src, sizeof (phu.ip6p.src)); 625 memcpy (&phu.ip6p.dst, &ip6->ip6_dst, sizeof (phu.ip6p.dst)); 626 phu.ip6p.plen = u->uh_ulen; 627 phu.ip6p.nxt = ip6->ip6_nxt; 628 hdrlen = sizeof phu.ip6p; 629 break; 630 631 default: 632 return 0; 633 } 634 635 /* IPv6 wants a 0xFFFF checksum "on error", not 0x0. */ 636 if (tlen < 0) 637 return (ntohl (hdr->sa_family) == AF_INET ? 0 : 0xFFFF); 638 639 sum = 0; 640 for (i = 0; i < hdrlen; i += 2) 641 sum += phu.pa[i/2]; 642 643 sp = (u_int16_t *)u; 644 for (i = 0; i < sizeof (struct udphdr); i += 2) 645 sum += *sp++; 646 647 sp = d; 648 for (i = 0; i < (tlen&~1); i += 2) 649 sum += *sp++; 650 651 if (tlen & 1) 652 sum += htons ((*(const char *)sp) << 8); 653 654 while (sum > 0xffff) 655 sum = (sum & 0xffff) + (sum >> 16); 656 sum = ~sum & 0xffff; 657 658 return sum; 659 } 660 661 /* Copied from tcpdump/print-ip.c, modified. */ 662 static u_int16_t 663 in_cksum (const u_int16_t *w, int len) 664 { 665 int nleft = len, sum = 0; 666 u_int16_t answer; 667 668 while (nleft > 1) { 669 sum += *w++; 670 nleft -= 2; 671 } 672 if (nleft == 1) 673 sum += htons (*(u_char *)w << 8); 674 675 sum = (sum >> 16) + (sum & 0xffff); /* add hi 16 to low 16 */ 676 sum += (sum >> 16); /* add carry */ 677 answer = ~sum; /* truncate to 16 bits */ 678 return answer; 679 } 680 681 #endif /* USE_DEBUG */ 682