3 Subroutines that support tracing of OMAPI wire transactions and
4 provide a mechanism for programs using OMAPI to trace their own
8 * Copyright (c) 2009-2010 by Internet Systems Consortium, Inc. ("ISC")
9 * Copyright (c) 2004-2007 by Internet Systems Consortium, Inc. ("ISC")
10 * Copyright (c) 2001-2003 by Internet Software Consortium
12 * Permission to use, copy, modify, and distribute this software for any
13 * purpose with or without fee is hereby granted, provided that the above
14 * copyright notice and this permission notice appear in all copies.
16 * THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES
17 * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
18 * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL ISC BE LIABLE FOR
19 * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
20 * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
21 * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT
22 * OF OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
24 * Internet Systems Consortium, Inc.
26 * Redwood City, CA 94063
28 * https://www.isc.org/
30 * This software has been written for Internet Systems Consortium
31 * by Ted Lemon, as part of a project for Nominum, Inc. To learn more
32 * about Internet Systems Consortium, see https://www.isc.org/. To
33 * learn more about Nominum, Inc., see ``http://www.nominum.com''.
37 #include <omapip/omapip_p.h>
41 void (*trace_set_time_hook) (TIME);
42 static int tracing_stopped;
43 static int traceoutfile;
44 static int traceindex;
45 static trace_type_t **trace_types;
46 static int trace_type_count;
47 static int trace_type_max;
48 static trace_type_t *new_trace_types;
49 static FILE *traceinfile;
50 static tracefile_header_t tracefile_header;
51 static int trace_playback_flag;
52 trace_type_t trace_time_marker;
54 #if defined (DEBUG_MEMORY_LEAKAGE) || defined (DEBUG_MEMORY_LEAKAGE_ON_EXIT)
55 extern omapi_array_t *trace_listeners;
56 extern omapi_array_t *omapi_connections;
60 void trace_free_all ()
66 new_trace_types = tp -> next;
68 dfree (tp -> name, MDL);
69 tp -> name = (char *)0;
74 for (i = 0; i < trace_type_count; i++) {
75 if (trace_types [i]) {
76 if (trace_types [i] -> name)
77 dfree (trace_types [i] -> name, MDL);
78 dfree (trace_types [i], MDL);
81 dfree (trace_types, MDL);
82 trace_types = (trace_type_t **)0;
83 trace_type_count = trace_type_max = 0;
85 omapi_array_free (&trace_listeners, MDL);
86 omapi_array_free (&omapi_connections, MDL);
90 static isc_result_t trace_type_record (trace_type_t *,
91 unsigned, const char *, int);
95 return trace_playback_flag;
100 if (traceoutfile && !tracing_stopped)
105 isc_result_t trace_init (void (*set_time) (TIME),
106 const char *file, int line)
108 trace_type_t *root_type;
109 static int root_setup = 0;
112 return ISC_R_SUCCESS;
114 trace_set_time_hook = set_time;
116 root_type = trace_type_register ("trace-index-mapping",
117 (void *)0, trace_index_map_input,
118 trace_index_stop_tracing, file, line);
120 return ISC_R_UNEXPECTED;
121 if (new_trace_types == root_type)
122 new_trace_types = new_trace_types -> next;
123 root_type -> index = 0;
124 trace_type_stash (root_type);
127 return ISC_R_SUCCESS;
130 isc_result_t trace_begin (const char *filename,
131 const char *file, int line)
133 tracefile_header_t tfh;
135 trace_type_t *tptr, *next;
139 log_error ("%s(%d): trace_begin called twice",
141 return DHCP_R_INVALIDARG;
144 traceoutfile = open (filename, O_CREAT | O_WRONLY | O_EXCL, 0600);
145 if (traceoutfile < 0 && errno == EEXIST) {
146 log_error ("WARNING: Overwriting trace file \"%s\"", filename);
147 traceoutfile = open (filename, O_WRONLY | O_EXCL | O_TRUNC,
151 if (traceoutfile < 0) {
152 log_error ("%s(%d): trace_begin: %s: %m",
153 file, line, filename);
154 return ISC_R_UNEXPECTED;
156 #if defined (HAVE_SETFD)
157 if (fcntl (traceoutfile, F_SETFD, 1) < 0)
158 log_error ("Can't set close-on-exec on %s: %m", filename);
161 tfh.magic = htonl (TRACEFILE_MAGIC);
162 tfh.version = htonl (TRACEFILE_VERSION);
163 tfh.hlen = htonl (sizeof (tracefile_header_t));
164 tfh.phlen = htonl (sizeof (tracepacket_t));
166 status = write (traceoutfile, &tfh, sizeof tfh);
168 log_error ("%s(%d): trace_begin write failed: %m", file, line);
169 return ISC_R_UNEXPECTED;
170 } else if (status != sizeof tfh) {
171 log_error ("%s(%d): trace_begin: short write (%d:%ld)",
172 file, line, status, (long)(sizeof tfh));
174 return ISC_R_UNEXPECTED;
177 /* Stash all the types that have already been set up. */
178 if (new_trace_types) {
179 next = new_trace_types;
180 new_trace_types = (trace_type_t *)0;
181 for (tptr = next; tptr; tptr = next) {
183 if (tptr -> index != 0) {
184 result = (trace_type_record
186 strlen (tptr -> name), file, line));
187 if (result != ISC_R_SUCCESS)
193 return ISC_R_SUCCESS;
196 isc_result_t trace_write_packet (trace_type_t *ttype, unsigned length,
197 const char *buf, const char *file, int line)
203 return trace_write_packet_iov (ttype, 1, &iov, file, line);
206 isc_result_t trace_write_packet_iov (trace_type_t *ttype,
207 int count, trace_iov_t *iov,
208 const char *file, int line)
215 /* Really shouldn't get called here, but it may be hard to turn off
216 tracing midstream if the trace file write fails or something. */
221 log_error ("%s(%d): trace_write_packet with null trace type",
222 file ? file : "<unknown file>", line);
223 return DHCP_R_INVALIDARG;
226 log_error ("%s(%d): trace_write_packet with no tracefile.",
227 file ? file : "<unknown file>", line);
228 return DHCP_R_INVALIDARG;
231 /* Compute the total length of the iov. */
233 for (i = 0; i < count; i++)
234 length += iov [i].len;
236 /* We have to swap out the data, because it may be read back on a
237 machine of different endianness. */
238 tmp.type_index = htonl (ttype -> index);
239 tmp.when = htonl (time ((time_t *)0)); /* XXX */
240 tmp.length = htonl (length);
242 status = write (traceoutfile, &tmp, sizeof tmp);
244 log_error ("%s(%d): trace_write_packet write failed: %m",
246 return ISC_R_UNEXPECTED;
247 } else if (status != sizeof tmp) {
248 log_error ("%s(%d): trace_write_packet: short write (%d:%ld)",
249 file, line, status, (long)(sizeof tmp));
253 for (i = 0; i < count; i++) {
254 status = write (traceoutfile, iov [i].buf, iov [i].len);
256 log_error ("%s(%d): %s write failed: %m",
257 file, line, "trace_write_packet");
258 return ISC_R_UNEXPECTED;
259 } else if (status != iov [i].len) {
260 log_error ("%s(%d): %s: short write (%d:%d)",
262 "trace_write_packet", status, length);
267 /* Write padding on the end of the packet to align the next
268 packet to an 8-byte boundary. This is in case we decide to
269 use mmap in some clever way later on. */
271 static char zero [] = { 0, 0, 0, 0, 0, 0, 0 };
272 unsigned padl = 8 - (length % 8);
274 status = write (traceoutfile, zero, padl);
276 log_error ("%s(%d): trace_write_packet write failed: %m",
278 return ISC_R_UNEXPECTED;
279 } else if (status != padl) {
280 log_error ("%s(%d): trace_write_packet: short write (%d:%d)",
281 file, line, status, padl);
286 return ISC_R_SUCCESS;
289 void trace_type_stash (trace_type_t *tptr)
293 if (trace_type_max <= tptr -> index) {
294 delta = tptr -> index - trace_type_max + 10;
295 vec = dmalloc (((trace_type_max + delta) *
296 sizeof (trace_type_t *)), MDL);
299 memset (&vec [trace_type_max], 0,
300 (sizeof (trace_type_t *)) * delta);
301 trace_type_max += delta;
303 memcpy (vec, trace_types,
304 trace_type_count * sizeof (trace_type_t *));
305 dfree (trace_types, MDL);
309 trace_types [tptr -> index] = tptr;
310 if (tptr -> index >= trace_type_count)
311 trace_type_count = tptr -> index + 1;
314 trace_type_t *trace_type_register (const char *name,
316 void (*have_packet) (trace_type_t *,
318 void (*stop_tracing) (trace_type_t *),
319 const char *file, int line)
322 unsigned slen = strlen (name);
325 ttmp = dmalloc (sizeof *ttmp, file, line);
329 ttmp -> name = dmalloc (slen + 1, file, line);
331 dfree (ttmp, file, line);
332 return (trace_type_t *)0;
334 strcpy (ttmp -> name, name);
335 ttmp -> have_packet = have_packet;
336 ttmp -> stop_tracing = stop_tracing;
339 status = trace_type_record (ttmp, slen, file, line);
340 if (status != ISC_R_SUCCESS) {
341 dfree (ttmp -> name, file, line);
342 dfree (ttmp, file, line);
343 return (trace_type_t *)0;
346 ttmp -> next = new_trace_types;
347 new_trace_types = ttmp;
353 static isc_result_t trace_type_record (trace_type_t *ttmp, unsigned slen,
354 const char *file, int line)
356 trace_index_mapping_t *tim;
359 tim = dmalloc (slen + TRACE_INDEX_MAPPING_SIZE, file, line);
361 return ISC_R_NOMEMORY;
362 ttmp -> index = ++traceindex;
363 trace_type_stash (ttmp);
364 tim -> index = htonl (ttmp -> index);
365 memcpy (tim -> name, ttmp -> name, slen);
366 status = trace_write_packet (trace_types [0],
367 slen + TRACE_INDEX_MAPPING_SIZE,
368 (char *)tim, file, line);
369 dfree (tim, file, line);
373 /* Stop all registered trace types from trying to trace. */
375 void trace_stop (void)
379 for (i = 0; i < trace_type_count; i++)
380 if (trace_types [i] -> stop_tracing)
381 (*(trace_types [i] -> stop_tracing))
386 void trace_index_map_input (trace_type_t *ttype, unsigned length, char *buf)
388 trace_index_mapping_t *tmap;
390 trace_type_t *tptr, **prev;
392 if (length < TRACE_INDEX_MAPPING_SIZE) {
393 log_error ("short trace index mapping");
396 tmap = (trace_index_mapping_t *)buf;
398 prev = &new_trace_types;
399 for (tptr = new_trace_types; tptr; tptr = tptr -> next) {
400 len = strlen (tptr -> name);
401 if (len == length - TRACE_INDEX_MAPPING_SIZE &&
402 !memcmp (tptr -> name, tmap -> name, len)) {
403 tptr -> index = ntohl (tmap -> index);
404 trace_type_stash (tptr);
405 *prev = tptr -> next;
408 prev = &tptr -> next;
411 log_error ("No registered trace type for type name %.*s",
412 (int)length - TRACE_INDEX_MAPPING_SIZE, tmap -> name);
416 void trace_index_stop_tracing (trace_type_t *ttype) { }
418 void trace_replay_init (void)
420 trace_playback_flag = 1;
423 void trace_file_replay (const char *filename)
425 tracepacket_t *tpkt = NULL;
430 trace_type_t *ttype = NULL;
434 traceinfile = fopen (filename, "r");
436 log_error("Can't open tracefile %s: %m", filename);
439 #if defined (HAVE_SETFD)
440 if (fcntl (fileno(traceinfile), F_SETFD, 1) < 0)
441 log_error("Can't set close-on-exec on %s: %m", filename);
443 status = fread(&tracefile_header, 1,
444 sizeof tracefile_header, traceinfile);
445 if (status < sizeof tracefile_header) {
446 if (ferror(traceinfile))
447 log_error("Error reading trace file header: %m");
449 log_error("Short read on trace file header: %d %ld.",
450 status, (long)(sizeof tracefile_header));
453 tracefile_header.magic = ntohl(tracefile_header.magic);
454 tracefile_header.version = ntohl(tracefile_header.version);
455 tracefile_header.hlen = ntohl(tracefile_header.hlen);
456 tracefile_header.phlen = ntohl(tracefile_header.phlen);
458 if (tracefile_header.magic != TRACEFILE_MAGIC) {
459 log_error("%s: not a dhcp trace file.", filename);
462 if (tracefile_header.version > TRACEFILE_VERSION) {
463 log_error ("tracefile version %ld > current %ld.",
464 (long int)tracefile_header.version,
465 (long int)TRACEFILE_VERSION);
468 if (tracefile_header.phlen < sizeof *tpkt) {
469 log_error("tracefile packet size too small - %ld < %ld",
470 (long int)tracefile_header.phlen,
471 (long int)sizeof *tpkt);
474 len = (sizeof tracefile_header) - tracefile_header.hlen;
476 log_error("tracefile header size too small - %ld < %ld",
477 (long int)tracefile_header.hlen,
478 (long int)sizeof tracefile_header);
482 status = fseek(traceinfile, (long)len, SEEK_CUR);
484 log_error("can't seek past header: %m");
489 tpkt = dmalloc((unsigned)tracefile_header.phlen, MDL);
491 log_error ("can't allocate trace packet header.");
495 while ((result = trace_get_next_packet(&ttype, tpkt, &buf, &buflen,
496 &bufmax)) == ISC_R_SUCCESS) {
497 (*ttype->have_packet)(ttype, tpkt->length, buf);
508 /* Get the next packet from the file. If ttp points to a nonzero pointer
509 to a trace type structure, check the next packet to see if it's of the
510 expected type, and back off if not. */
512 isc_result_t trace_get_next_packet (trace_type_t **ttp,
514 char **buf, unsigned *buflen,
519 int status, curposok = 0;
524 status = fgetpos(traceinfile, &curpos);
526 log_error("Can't save tracefile position: %m");
531 status = fread(tpkt, 1, (size_t)tracefile_header.phlen,
533 if (status < tracefile_header.phlen) {
534 if (ferror(traceinfile))
535 log_error("Error reading trace packet header: "
537 else if (status == 0)
540 log_error ("Short read on trace packet header:"
543 (long int)tracefile_header.phlen);
544 return DHCP_R_PROTOCOLERROR;
547 /* Swap the packet. */
548 tpkt->type_index = ntohl(tpkt -> type_index);
549 tpkt->length = ntohl(tpkt -> length);
550 tpkt->when = ntohl(tpkt -> when);
552 /* See if there's a handler for this packet type. */
553 if (tpkt->type_index < trace_type_count &&
554 trace_types[tpkt->type_index])
555 ttype = trace_types[tpkt->type_index];
557 log_error ("Trace packet with unknown index %ld",
558 (long int)tpkt->type_index);
559 return DHCP_R_PROTOCOLERROR;
563 * Determine if we should try to expire any timer events.
565 * we aren't looking for a specific type of packet
566 * we have a hook to use to update the timer
567 * the timestamp on the packet doesn't match the current time
568 * When we do so we rewind the file to the beginning of this
569 * packet and then try for a new packet. This allows
570 * any code triggered by a timeout to get the current packet
571 * while we get the next one.
574 if ((ttp != NULL) && (*ttp == NULL) &&
575 (tpkt->when != cur_tv.tv_sec) &&
576 (trace_set_time_hook != NULL)) {
578 log_error("no curpos for fsetpos in "
580 return DHCP_R_PROTOCOLERROR;
583 status = fsetpos(traceinfile, &curpos);
585 log_error("fsetpos in tracefile failed: %m");
586 return DHCP_R_PROTOCOLERROR;
589 (*trace_set_time_hook) (tpkt->when);
595 /* If we were supposed to get a particular kind of packet,
596 check to see that we got the right kind. */
597 if (ttp && *ttp && ttype != *ttp) {
598 log_error ("Read packet type %s when expecting %s",
599 ttype -> name, (*ttp) -> name);
600 status = fsetpos (traceinfile, &curpos);
602 log_error ("fsetpos in tracefile failed: %m");
603 return DHCP_R_PROTOCOLERROR;
605 return ISC_R_UNEXPECTEDTOKEN;
608 paylen = tpkt -> length;
610 paylen += 8 - (tpkt -> length % 8);
611 if (paylen > (*bufmax)) {
614 (*bufmax) = ((paylen + 1023) & ~1023U);
615 (*buf) = dmalloc ((*bufmax), MDL);
617 log_error ("Can't allocate input buffer sized %d",
619 return ISC_R_NOMEMORY;
623 status = fread ((*buf), 1, paylen, traceinfile);
624 if (status < paylen) {
625 if (ferror (traceinfile))
626 log_error ("Error reading trace payload: %m");
628 log_error ("Short read on trace payload: %d %d.",
630 return DHCP_R_PROTOCOLERROR;
633 /* Store the actual length of the payload. */
634 *buflen = tpkt -> length;
638 return ISC_R_SUCCESS;
641 isc_result_t trace_get_packet (trace_type_t **ttp,
642 unsigned *buflen, char **buf)
649 return DHCP_R_INVALIDARG;
651 tpkt = dmalloc ((unsigned)tracefile_header.phlen, MDL);
653 log_error ("can't allocate trace packet header.");
654 return ISC_R_NOMEMORY;
657 status = trace_get_next_packet (ttp, tpkt, buf, buflen, &bufmax);
663 /* Get a packet from the trace input file that contains a file with the
664 specified name. We don't hunt for the packet - it should be the next
665 packet in the tracefile. If it's not, or something else bad happens,
666 return an error code. */
668 isc_result_t trace_get_file (trace_type_t *ttype,
669 const char *filename, unsigned *len, char **buf)
677 /* Disallow some obvious bogosities. */
678 if (!buf || !len || *buf)
679 return DHCP_R_INVALIDARG;
681 /* Save file position in case of filename mismatch. */
682 status = fgetpos (traceinfile, &curpos);
684 log_error ("Can't save tracefile position: %m");
686 tpkt = dmalloc ((unsigned)tracefile_header.phlen, MDL);
688 log_error ("can't allocate trace packet header.");
689 return ISC_R_NOMEMORY;
692 result = trace_get_next_packet (&ttype, tpkt, buf, len, &max);
693 if (result != ISC_R_SUCCESS) {
700 /* Make sure the filename is right. */
701 if (strcmp (filename, *buf)) {
702 log_error ("Read file %s when expecting %s", *buf, filename);
703 status = fsetpos (traceinfile, &curpos);
705 log_error ("fsetpos in tracefile failed: %m");
708 return DHCP_R_PROTOCOLERROR;
710 return ISC_R_UNEXPECTEDTOKEN;
714 return ISC_R_SUCCESS;