log.c revision 1.31
1/* $OpenBSD: log.c,v 1.31 2003/05/15 00:28:53 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#include <stdarg.h> 66#include <unistd.h> 67 68#include "isakmp_num.h" 69#include "log.h" 70#include "monitor.h" 71 72static void _log_print (int, int, const char *, va_list, int, int); 73 74static FILE *log_output; 75 76#if defined (USE_DEBUG) 77static int log_level[LOG_ENDCLASS]; 78 79#define TCPDUMP_MAGIC 0xa1b2c3d4 80#define SNAPLEN (64 * 1024) 81 82struct packhdr { 83 struct pcap_pkthdr pcap; /* pcap file packet header */ 84 u_int32_t sa_family; /* address family */ 85 union { 86 struct ip ip4; /* IPv4 header (w/o options) */ 87 struct ip6_hdr ip6; /* IPv6 header */ 88 } ip; 89}; 90 91struct isakmp_hdr { 92 u_int8_t icookie[8], rcookie[8]; 93 u_int8_t next, ver, type, flags; 94 u_int32_t msgid, len; 95}; 96 97static char *pcaplog_file = NULL; 98static FILE *packet_log; 99static u_int8_t *packet_buf = NULL; 100 101static int udp_cksum (struct packhdr *, const struct udphdr *, u_int16_t *); 102static u_int16_t in_cksum (const u_int16_t *, int); 103#endif /* USE_DEBUG */ 104 105void 106log_init (void) 107{ 108 log_output = stderr; 109} 110 111void 112log_to (FILE *f) 113{ 114 if (!log_output && f) 115 closelog (); 116 log_output = f; 117 if (!f) 118 openlog ("isakmpd", LOG_PID | LOG_CONS, LOG_DAEMON); 119} 120 121FILE * 122log_current (void) 123{ 124 return log_output; 125} 126 127static char * 128_log_get_class (int error_class) 129{ 130 /* XXX For test purposes. To be removed later on? */ 131 static char *class_text[] = LOG_CLASSES_TEXT; 132 133 if (error_class < 0) 134 return "Dflt"; 135 else if (error_class >= LOG_ENDCLASS) 136 return "Unkn"; 137 else 138 return class_text[error_class]; 139} 140 141static void 142_log_print (int error, int syslog_level, const char *fmt, va_list ap, 143 int class, int level) 144{ 145 char buffer[LOG_SIZE], nbuf[LOG_SIZE + 32]; 146 static const char fallback_msg[] = 147 "write to log file failed (errno %d), redirecting output to syslog"; 148 int len; 149 struct tm *tm; 150 struct timeval now; 151 time_t t; 152 153 len = vsnprintf (buffer, LOG_SIZE, fmt, ap); 154 if (len > 0 && len < LOG_SIZE - 1 && error) 155 snprintf (buffer + len, LOG_SIZE - len, ": %s", strerror (errno)); 156 if (log_output) 157 { 158 gettimeofday (&now, 0); 159 t = now.tv_sec; 160 tm = localtime (&t); 161 if (class >= 0) 162 snprintf (nbuf, LOG_SIZE + 32, "%02d%02d%02d.%06ld %s %02d ", 163 tm->tm_hour, tm->tm_min, tm->tm_sec, now.tv_usec, 164 _log_get_class (class), level); 165 else /* LOG_PRINT (-1) or LOG_REPORT (-2) */ 166 snprintf (nbuf, LOG_SIZE + 32, "%02d%02d%02d.%06ld %s ", tm->tm_hour, 167 tm->tm_min, tm->tm_sec, now.tv_usec, 168 class == LOG_PRINT ? "Default" : "Report>"); 169 strlcat (nbuf, buffer, LOG_SIZE + 32); 170#if defined (USE_PRIVSEP) 171 strlcat (nbuf, getuid() ? "" : " [priv]", LOG_SIZE + 32); 172#endif 173 strlcat (nbuf, "\n", LOG_SIZE + 32); 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); /* XXX monitor_fclose ? */ 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 205log_debug (int cls, int level, const char *fmt, ...) 206{ 207 va_list ap; 208 209 /* 210 * If we are not debugging this class, or the level is too low, just return. 211 */ 212 if (cls >= 0 && (log_level[cls] == 0 || level > log_level[cls])) 213 return; 214 va_start (ap, fmt); 215 _log_print (0, LOG_DEBUG, fmt, ap, cls, level); 216 va_end (ap); 217} 218 219void 220log_debug_buf (int cls, int level, const char *header, const u_int8_t *buf, 221 size_t sz) 222{ 223 char s[73]; 224 int i, j; 225 226 /* 227 * If we are not debugging this class, or the level is too low, just return. 228 */ 229 if (cls >= 0 && (log_level[cls] == 0 || level > log_level[cls])) 230 return; 231 232 log_debug (cls, level, "%s:", header); 233 for (i = j = 0; i < sz;) 234 { 235 snprintf (s + j, 73 - j, "%02x", buf[i++]); 236 j += 2; 237 if (i % 4 == 0) 238 { 239 if (i % 32 == 0) 240 { 241 s[j] = '\0'; 242 log_debug (cls, level, "%s", s); 243 j = 0; 244 } 245 else 246 s[j++] = ' '; 247 } 248 } 249 if (j) 250 { 251 s[j] = '\0'; 252 log_debug (cls, level, "%s", s); 253 } 254} 255 256void 257log_debug_cmd (int cls, int level) 258{ 259 if (cls < 0 || cls >= LOG_ENDCLASS) 260 { 261 log_print ("log_debug_cmd: invalid debugging class %d", cls); 262 return; 263 } 264 265 if (level < 0) 266 { 267 log_print ("log_debug_cmd: invalid debugging level %d for class %d", 268 level, cls); 269 return; 270 } 271 272 if (level == log_level[cls]) 273 log_print ("log_debug_cmd: log level unchanged for class %d", cls); 274 else 275 { 276 log_print ("log_debug_cmd: log level changed from %d to %d for class %d", 277 log_level[cls], level, cls); 278 log_level[cls] = level; 279 } 280} 281 282void 283log_debug_toggle (void) 284{ 285 static int log_level_copy[LOG_ENDCLASS], toggle = 0; 286 287 if (!toggle) 288 { 289 LOG_DBG ((LOG_MISC, 50, "log_debug_toggle: debug levels cleared")); 290 memcpy (&log_level_copy, &log_level, sizeof log_level); 291 memset (&log_level, 0, sizeof log_level); 292 } 293 else 294 { 295 memcpy (&log_level, &log_level_copy, sizeof log_level); 296 LOG_DBG ((LOG_MISC, 50, "log_debug_toggle: debug levels restored")); 297 } 298 toggle = !toggle; 299} 300#endif /* USE_DEBUG */ 301 302void 303log_print (const char *fmt, ...) 304{ 305 va_list ap; 306 307 va_start (ap, fmt); 308 _log_print (0, LOG_NOTICE, fmt, ap, LOG_PRINT, 0); 309 va_end (ap); 310} 311 312void 313log_error (const char *fmt, ...) 314{ 315 va_list ap; 316 317 va_start (ap, fmt); 318 _log_print (1, LOG_ERR, fmt, ap, LOG_PRINT, 0); 319 va_end (ap); 320} 321 322void 323log_fatal (const char *fmt, ...) 324{ 325 va_list ap; 326 327 va_start (ap, fmt); 328 _log_print (1, LOG_CRIT, fmt, ap, LOG_PRINT, 0); 329 va_end (ap); 330 exit (1); 331} 332 333#ifdef USE_DEBUG 334void 335log_packet_init (char *newname) 336{ 337 struct pcap_file_header sf_hdr; 338 struct stat st; 339 mode_t old_umask; 340 char *mode; 341 342 /* Allocate packet buffer first time through. */ 343 if (!packet_buf) 344 packet_buf = malloc (SNAPLEN); 345 346 if (!packet_buf) 347 { 348 log_error ("log_packet_init: malloc (%d) failed", SNAPLEN); 349 return; 350 } 351 352 if (pcaplog_file && strcmp (pcaplog_file, PCAP_FILE_DEFAULT) != 0) 353 free (pcaplog_file); 354 355 pcaplog_file = strdup (newname); 356 if (!pcaplog_file) 357 { 358 log_error ("log_packet_init: strdup (\"%s\") failed", newname); 359 return; 360 } 361 362 /* Does the file already exist? XXX lstat() or stat()? */ 363 if (lstat (pcaplog_file, &st) == 0) 364 { 365 /* Sanity checks. */ 366 if ((st.st_mode & S_IFMT) != S_IFREG) 367 { 368 log_print ("log_packet_init: existing capture file is " 369 "not a regular file"); 370 return; 371 } 372 373 if ((st.st_mode & (S_IRWXG | S_IRWXO)) != 0) 374 { 375 log_print ("log_packet_init: existing capture file has bad modes"); 376 return; 377 } 378 379 /* XXX It would be nice to check if it actually is a pcap file... */ 380 381 mode = "a"; 382 } 383 else 384 mode = "w"; 385 386 old_umask = umask (S_IRWXG | S_IRWXO); 387 packet_log = monitor_fopen (pcaplog_file, mode); 388 umask (old_umask); 389 390 if (!packet_log) 391 { 392 log_error ("log_packet_init: fopen (\"%s\", \"%s\") failed", 393 pcaplog_file, mode); 394 return; 395 } 396 397 log_print ("log_packet_init: starting IKE packet capture to file \"%s\"", 398 pcaplog_file); 399 400 /* If this is a new file, we need to write a PCAP header to it. */ 401 if (*mode == 'w') 402 { 403 sf_hdr.magic = TCPDUMP_MAGIC; 404 sf_hdr.version_major = PCAP_VERSION_MAJOR; 405 sf_hdr.version_minor = PCAP_VERSION_MINOR; 406 sf_hdr.thiszone = 0; 407 sf_hdr.snaplen = SNAPLEN; 408 sf_hdr.sigfigs = 0; 409 sf_hdr.linktype = DLT_LOOP; 410 411 fwrite ((char *)&sf_hdr, sizeof sf_hdr, 1, packet_log); 412 fflush (packet_log); 413 } 414} 415 416void 417log_packet_restart (char *newname) 418{ 419 if (packet_log) 420 { 421 log_print ("log_packet_restart: capture already active on file \"%s\"", 422 pcaplog_file); 423 return; 424 } 425 426 if (newname) 427 log_packet_init (newname); 428 else if (!pcaplog_file) 429 log_packet_init (PCAP_FILE_DEFAULT); 430 else 431 log_packet_init (pcaplog_file); 432} 433 434void 435log_packet_stop (void) 436{ 437 /* Stop capture. */ 438 if (packet_log) 439 { 440 monitor_fclose (packet_log); 441 log_print ("log_packet_stop: stopped capture"); 442 } 443 packet_log = 0; 444} 445 446void 447log_packet_iov (struct sockaddr *src, struct sockaddr *dst, struct iovec *iov, 448 int iovcnt) 449{ 450 struct isakmp_hdr *isakmphdr; 451 struct packhdr hdr; 452 struct udphdr udp; 453 int off, datalen, hdrlen, i; 454 struct timeval tv; 455 456 for (i = 0, datalen = 0; i < iovcnt; i++) 457 datalen += iov[i].iov_len; 458 459 if (!packet_log || datalen > SNAPLEN) 460 return; 461 462 /* copy packet into buffer */ 463 for (i = 0, off = 0; i < iovcnt; i++) 464 { 465 memcpy (packet_buf + off, iov[i].iov_base, iov[i].iov_len); 466 off += iov[i].iov_len; 467 } 468 469 memset (&hdr, 0, sizeof hdr); 470 memset (&udp, 0, sizeof udp); 471 472 /* isakmp - turn off the encryption bit in the isakmp hdr */ 473 isakmphdr = (struct isakmp_hdr *)packet_buf; 474 isakmphdr->flags &= ~(ISAKMP_FLAGS_ENC); 475 476 /* udp */ 477 udp.uh_sport = udp.uh_dport = htons (500); 478 datalen += sizeof udp; 479 udp.uh_ulen = htons (datalen); 480 481 /* ip */ 482 hdr.sa_family = htonl (src->sa_family); 483 switch (src->sa_family) 484 { 485 default: 486 /* Assume IPv4. XXX Can 'default' ever happen here? */ 487 hdr.sa_family = htonl (AF_INET); 488 hdr.ip.ip4.ip_src.s_addr = 0x02020202; 489 hdr.ip.ip4.ip_dst.s_addr = 0x01010101; 490 /* The rest of the setup is common to AF_INET. */ 491 goto setup_ip4; 492 493 case AF_INET: 494 hdr.ip.ip4.ip_src.s_addr = ((struct sockaddr_in *)src)->sin_addr.s_addr; 495 hdr.ip.ip4.ip_dst.s_addr = ((struct sockaddr_in *)dst)->sin_addr.s_addr; 496 497 setup_ip4: 498 hdrlen = sizeof hdr.ip.ip4; 499 hdr.ip.ip4.ip_v = 0x4; 500 hdr.ip.ip4.ip_hl = 0x5; 501 hdr.ip.ip4.ip_p = IPPROTO_UDP; 502 hdr.ip.ip4.ip_len = htons (datalen + hdrlen); 503 /* Let's use the IP ID as a "packet counter". */ 504 i = ntohs (hdr.ip.ip4.ip_id) + 1; 505 hdr.ip.ip4.ip_id = htons (i); 506 /* Calculate IP header checksum. */ 507 hdr.ip.ip4.ip_sum = in_cksum ((u_int16_t *)&hdr.ip.ip4, 508 hdr.ip.ip4.ip_hl << 2); 509 break; 510 511 case AF_INET6: 512 hdrlen = sizeof (hdr.ip.ip6); 513 hdr.ip.ip6.ip6_vfc = IPV6_VERSION; 514 hdr.ip.ip6.ip6_nxt = IPPROTO_UDP; 515 hdr.ip.ip6.ip6_plen = udp.uh_ulen; 516 memcpy (&hdr.ip.ip6.ip6_src, &((struct sockaddr_in6 *)src)->sin6_addr, 517 sizeof hdr.ip.ip6.ip6_src); 518 memcpy (&hdr.ip.ip6.ip6_dst, &((struct sockaddr_in6 *)dst)->sin6_addr, 519 sizeof hdr.ip.ip6.ip6_dst); 520 break; 521 } 522 523 /* Calculate UDP checksum. */ 524 udp.uh_sum = udp_cksum (&hdr, &udp, (u_int16_t *)packet_buf); 525 hdrlen += sizeof hdr.sa_family; 526 527 /* pcap file packet header */ 528 gettimeofday (&tv, 0); 529 hdr.pcap.ts.tv_sec = tv.tv_sec; 530 hdr.pcap.ts.tv_usec = tv.tv_usec; 531 hdr.pcap.caplen = datalen + hdrlen; 532 hdr.pcap.len = datalen + hdrlen; 533 534 hdrlen += sizeof (struct pcap_pkthdr); 535 datalen -= sizeof (struct udphdr); 536 537 /* Write to pcap file. */ 538 fwrite (&hdr, hdrlen, 1, packet_log); /* pcap + IP */ 539 fwrite (&udp, sizeof (struct udphdr), 1, packet_log); /* UDP */ 540 fwrite (packet_buf, datalen, 1, packet_log); /* IKE-data */ 541 fflush (packet_log); 542 return; 543} 544 545/* Copied from tcpdump/print-udp.c, mostly rewritten. */ 546static int 547udp_cksum (struct packhdr *hdr, const struct udphdr *u, u_int16_t *d) 548{ 549 int i, hdrlen, tlen = ntohs (u->uh_ulen) - sizeof (struct udphdr); 550 struct ip *ip4; 551 struct ip6_hdr *ip6; 552 553 union phu { 554 struct ip4pseudo { 555 struct in_addr src; 556 struct in_addr dst; 557 u_int8_t z; 558 u_int8_t proto; 559 u_int16_t len; 560 } ip4p; 561 struct ip6pseudo { 562 struct in6_addr src; 563 struct in6_addr dst; 564 u_int32_t plen; 565 u_int16_t z0; 566 u_int8_t z1; 567 u_int8_t nxt; 568 } ip6p; 569 u_int16_t pa[20]; 570 } phu; 571 const u_int16_t *sp; 572 u_int32_t sum; 573 574 /* Setup pseudoheader. */ 575 memset (phu.pa, 0, sizeof phu); 576 switch (ntohl (hdr->sa_family)) 577 { 578 case AF_INET: 579 ip4 = &hdr->ip.ip4; 580 memcpy (&phu.ip4p.src, &ip4->ip_src, sizeof (struct in_addr)); 581 memcpy (&phu.ip4p.dst, &ip4->ip_dst, sizeof (struct in_addr)); 582 phu.ip4p.proto = ip4->ip_p; 583 phu.ip4p.len = u->uh_ulen; 584 hdrlen = sizeof phu.ip4p; 585 break; 586 587 case AF_INET6: 588 ip6 = &hdr->ip.ip6; 589 memcpy (&phu.ip6p.src, &ip6->ip6_src, sizeof (phu.ip6p.src)); 590 memcpy (&phu.ip6p.dst, &ip6->ip6_dst, sizeof (phu.ip6p.dst)); 591 phu.ip6p.plen = u->uh_ulen; 592 phu.ip6p.nxt = ip6->ip6_nxt; 593 hdrlen = sizeof phu.ip6p; 594 break; 595 596 default: 597 return 0; 598 } 599 600 /* IPv6 wants a 0xFFFF checksum "on error", not 0x0. */ 601 if (tlen < 0) 602 return (ntohl (hdr->sa_family) == AF_INET ? 0 : 0xFFFF); 603 604 sum = 0; 605 for (i = 0; i < hdrlen; i += 2) 606 sum += phu.pa[i/2]; 607 608 sp = (u_int16_t *)u; 609 for (i = 0; i < sizeof (struct udphdr); i += 2) 610 sum += *sp++; 611 612 sp = d; 613 for (i = 0; i < (tlen&~1); i += 2) 614 sum += *sp++; 615 616 if (tlen & 1) 617 sum += htons ((*(const char *)sp) << 8); 618 619 while (sum > 0xffff) 620 sum = (sum & 0xffff) + (sum >> 16); 621 sum = ~sum & 0xffff; 622 623 return sum; 624} 625 626/* Copied from tcpdump/print-ip.c, modified. */ 627static u_int16_t 628in_cksum (const u_int16_t *w, int len) 629{ 630 int nleft = len, sum = 0; 631 u_int16_t answer; 632 633 while (nleft > 1) { 634 sum += *w++; 635 nleft -= 2; 636 } 637 if (nleft == 1) 638 sum += htons (*(u_char *)w << 8); 639 640 sum = (sum >> 16) + (sum & 0xffff); /* add hi 16 to low 16 */ 641 sum += (sum >> 16); /* add carry */ 642 answer = ~sum; /* truncate to 16 bits */ 643 return answer; 644} 645 646#endif /* USE_DEBUG */ 647 648