1 /* $NetBSD: trace.c,v 1.1.1.3 2014/07/12 11:58:01 spz Exp $ */
4 Subroutines that support tracing of OMAPI wire transactions and
5 provide a mechanism for programs using OMAPI to trace their own
9 * Copyright (c) 2012,2014 by Internet Systems Consortium, Inc. ("ISC")
10 * Copyright (c) 2009-2010 by Internet Systems Consortium, Inc. ("ISC")
11 * Copyright (c) 2004-2007 by Internet Systems Consortium, Inc. ("ISC")
12 * Copyright (c) 2001-2003 by Internet Software Consortium
14 * Permission to use, copy, modify, and distribute this software for any
15 * purpose with or without fee is hereby granted, provided that the above
16 * copyright notice and this permission notice appear in all copies.
18 * THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES
19 * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
20 * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL ISC BE LIABLE FOR
21 * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
22 * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
23 * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT
24 * OF OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
26 * Internet Systems Consortium, Inc.
28 * Redwood City, CA 94063
30 * https://www.isc.org/
34 #include <sys/cdefs.h>
35 __RCSID("$NetBSD: trace.c,v 1.1.1.3 2014/07/12 11:58:01 spz Exp $");
38 #include <omapip/omapip_p.h>
42 void (*trace_set_time_hook
) (TIME
);
43 static int tracing_stopped
;
44 static int traceoutfile
;
45 static int traceindex
;
46 static trace_type_t
**trace_types
;
47 static int trace_type_count
;
48 static int trace_type_max
;
49 static trace_type_t
*new_trace_types
;
50 static FILE *traceinfile
;
51 static tracefile_header_t tracefile_header
;
52 static int trace_playback_flag
;
53 trace_type_t trace_time_marker
;
55 #if defined (DEBUG_MEMORY_LEAKAGE) || defined (DEBUG_MEMORY_LEAKAGE_ON_EXIT)
56 extern omapi_array_t
*trace_listeners
;
57 extern omapi_array_t
*omapi_connections
;
61 void trace_free_all ()
67 new_trace_types
= tp
-> next
;
69 dfree (tp
-> name
, MDL
);
70 tp
-> name
= (char *)0;
75 for (i
= 0; i
< trace_type_count
; i
++) {
76 if (trace_types
[i
]) {
77 if (trace_types
[i
] -> name
)
78 dfree (trace_types
[i
] -> name
, MDL
);
79 dfree (trace_types
[i
], MDL
);
82 dfree (trace_types
, MDL
);
83 trace_types
= (trace_type_t
**)0;
84 trace_type_count
= trace_type_max
= 0;
86 omapi_array_free (&trace_listeners
, MDL
);
87 omapi_array_free (&omapi_connections
, MDL
);
91 static isc_result_t
trace_type_record (trace_type_t
*,
92 unsigned, const char *, int);
96 return trace_playback_flag
;
101 if (traceoutfile
&& !tracing_stopped
)
106 isc_result_t
trace_init (void (*set_time
) (TIME
),
107 const char *file
, int line
)
109 trace_type_t
*root_type
;
110 static int root_setup
= 0;
113 return ISC_R_SUCCESS
;
115 trace_set_time_hook
= set_time
;
117 root_type
= trace_type_register ("trace-index-mapping",
118 (void *)0, trace_index_map_input
,
119 trace_index_stop_tracing
, file
, line
);
121 return ISC_R_UNEXPECTED
;
122 if (new_trace_types
== root_type
)
123 new_trace_types
= new_trace_types
-> next
;
124 root_type
-> index
= 0;
125 trace_type_stash (root_type
);
128 return ISC_R_SUCCESS
;
131 isc_result_t
trace_begin (const char *filename
,
132 const char *file
, int line
)
134 tracefile_header_t tfh
;
136 trace_type_t
*tptr
, *next
;
140 log_error ("%s(%d): trace_begin called twice",
142 return DHCP_R_INVALIDARG
;
145 traceoutfile
= open (filename
, O_CREAT
| O_WRONLY
| O_EXCL
, 0600);
146 if (traceoutfile
< 0 && errno
== EEXIST
) {
147 log_error ("WARNING: Overwriting trace file \"%s\"", filename
);
148 traceoutfile
= open (filename
, O_WRONLY
| O_EXCL
| O_TRUNC
,
152 if (traceoutfile
< 0) {
153 log_error ("%s(%d): trace_begin: %s: %m",
154 file
, line
, filename
);
155 return ISC_R_UNEXPECTED
;
157 #if defined (HAVE_SETFD)
158 if (fcntl (traceoutfile
, F_SETFD
, 1) < 0)
159 log_error ("Can't set close-on-exec on %s: %m", filename
);
162 tfh
.magic
= htonl (TRACEFILE_MAGIC
);
163 tfh
.version
= htonl (TRACEFILE_VERSION
);
164 tfh
.hlen
= htonl (sizeof (tracefile_header_t
));
165 tfh
.phlen
= htonl (sizeof (tracepacket_t
));
167 status
= write (traceoutfile
, &tfh
, sizeof tfh
);
169 log_error ("%s(%d): trace_begin write failed: %m", file
, line
);
170 return ISC_R_UNEXPECTED
;
171 } else if (status
!= sizeof tfh
) {
172 log_error ("%s(%d): trace_begin: short write (%d:%ld)",
173 file
, line
, status
, (long)(sizeof tfh
));
175 return ISC_R_UNEXPECTED
;
178 /* Stash all the types that have already been set up. */
179 if (new_trace_types
) {
180 next
= new_trace_types
;
181 new_trace_types
= (trace_type_t
*)0;
182 for (tptr
= next
; tptr
; tptr
= next
) {
184 if (tptr
-> index
!= 0) {
185 result
= (trace_type_record
187 strlen (tptr
-> name
), file
, line
));
188 if (result
!= ISC_R_SUCCESS
)
194 return ISC_R_SUCCESS
;
197 isc_result_t
trace_write_packet (trace_type_t
*ttype
, unsigned length
,
198 const char *buf
, const char *file
, int line
)
204 return trace_write_packet_iov (ttype
, 1, &iov
, file
, line
);
207 isc_result_t
trace_write_packet_iov (trace_type_t
*ttype
,
208 int count
, trace_iov_t
*iov
,
209 const char *file
, int line
)
216 /* Really shouldn't get called here, but it may be hard to turn off
217 tracing midstream if the trace file write fails or something. */
222 log_error ("%s(%d): trace_write_packet with null trace type",
223 file
? file
: "<unknown file>", line
);
224 return DHCP_R_INVALIDARG
;
227 log_error ("%s(%d): trace_write_packet with no tracefile.",
228 file
? file
: "<unknown file>", line
);
229 return DHCP_R_INVALIDARG
;
232 /* Compute the total length of the iov. */
234 for (i
= 0; i
< count
; i
++)
235 length
+= iov
[i
].len
;
237 /* We have to swap out the data, because it may be read back on a
238 machine of different endianness. */
239 memset(&tmp
, 0, sizeof(tmp
));
240 tmp
.type_index
= htonl (ttype
-> index
);
241 tmp
.when
= htonl (time ((time_t *)0)); /* XXX */
242 tmp
.length
= htonl (length
);
244 status
= write (traceoutfile
, &tmp
, sizeof tmp
);
246 log_error ("%s(%d): trace_write_packet write failed: %m",
248 return ISC_R_UNEXPECTED
;
249 } else if (status
!= sizeof tmp
) {
250 log_error ("%s(%d): trace_write_packet: short write (%d:%ld)",
251 file
, line
, status
, (long)(sizeof tmp
));
255 for (i
= 0; i
< count
; i
++) {
256 status
= write (traceoutfile
, iov
[i
].buf
, iov
[i
].len
);
258 log_error ("%s(%d): %s write failed: %m",
259 file
, line
, "trace_write_packet");
260 return ISC_R_UNEXPECTED
;
261 } else if (status
!= iov
[i
].len
) {
262 log_error ("%s(%d): %s: short write (%d:%d)",
264 "trace_write_packet", status
, length
);
269 /* Write padding on the end of the packet to align the next
270 packet to an 8-byte boundary. This is in case we decide to
271 use mmap in some clever way later on. */
273 static char zero
[] = { 0, 0, 0, 0, 0, 0, 0 };
274 unsigned padl
= 8 - (length
% 8);
276 status
= write (traceoutfile
, zero
, padl
);
278 log_error ("%s(%d): trace_write_packet write failed: %m",
280 return ISC_R_UNEXPECTED
;
281 } else if (status
!= padl
) {
282 log_error ("%s(%d): trace_write_packet: short write (%d:%d)",
283 file
, line
, status
, padl
);
288 return ISC_R_SUCCESS
;
291 void trace_type_stash (trace_type_t
*tptr
)
295 if (trace_type_max
<= tptr
-> index
) {
296 delta
= tptr
-> index
- trace_type_max
+ 10;
297 vec
= dmalloc (((trace_type_max
+ delta
) *
298 sizeof (trace_type_t
*)), MDL
);
301 memset (&vec
[trace_type_max
], 0,
302 (sizeof (trace_type_t
*)) * delta
);
303 trace_type_max
+= delta
;
305 memcpy (vec
, trace_types
,
306 trace_type_count
* sizeof (trace_type_t
*));
307 dfree (trace_types
, MDL
);
311 trace_types
[tptr
-> index
] = tptr
;
312 if (tptr
-> index
>= trace_type_count
)
313 trace_type_count
= tptr
-> index
+ 1;
316 trace_type_t
*trace_type_register (const char *name
,
318 void (*have_packet
) (trace_type_t
*,
320 void (*stop_tracing
) (trace_type_t
*),
321 const char *file
, int line
)
324 unsigned slen
= strlen (name
);
327 ttmp
= dmalloc (sizeof *ttmp
, file
, line
);
331 ttmp
-> name
= dmalloc (slen
+ 1, file
, line
);
333 dfree (ttmp
, file
, line
);
334 return (trace_type_t
*)0;
336 strcpy (ttmp
-> name
, name
);
337 ttmp
-> have_packet
= have_packet
;
338 ttmp
-> stop_tracing
= stop_tracing
;
341 status
= trace_type_record (ttmp
, slen
, file
, line
);
342 if (status
!= ISC_R_SUCCESS
) {
343 dfree (ttmp
-> name
, file
, line
);
344 dfree (ttmp
, file
, line
);
345 return (trace_type_t
*)0;
348 ttmp
-> next
= new_trace_types
;
349 new_trace_types
= ttmp
;
355 static isc_result_t
trace_type_record (trace_type_t
*ttmp
, unsigned slen
,
356 const char *file
, int line
)
358 trace_index_mapping_t
*tim
;
361 tim
= dmalloc (slen
+ TRACE_INDEX_MAPPING_SIZE
, file
, line
);
363 return ISC_R_NOMEMORY
;
364 ttmp
-> index
= ++traceindex
;
365 trace_type_stash (ttmp
);
366 tim
-> index
= htonl (ttmp
-> index
);
367 memcpy (tim
-> name
, ttmp
-> name
, slen
);
368 status
= trace_write_packet (trace_types
[0],
369 slen
+ TRACE_INDEX_MAPPING_SIZE
,
370 (char *)tim
, file
, line
);
371 dfree (tim
, file
, line
);
375 /* Stop all registered trace types from trying to trace. */
377 void trace_stop (void)
381 for (i
= 0; i
< trace_type_count
; i
++)
382 if (trace_types
[i
] -> stop_tracing
)
383 (*(trace_types
[i
] -> stop_tracing
))
388 void trace_index_map_input (trace_type_t
*ttype
, unsigned length
, char *buf
)
390 trace_index_mapping_t
*tmap
;
392 trace_type_t
*tptr
, **prev
;
394 if (length
< TRACE_INDEX_MAPPING_SIZE
) {
395 log_error ("short trace index mapping");
398 tmap
= (trace_index_mapping_t
*)buf
;
400 prev
= &new_trace_types
;
401 for (tptr
= new_trace_types
; tptr
; tptr
= tptr
-> next
) {
402 len
= strlen (tptr
-> name
);
403 if (len
== length
- TRACE_INDEX_MAPPING_SIZE
&&
404 !memcmp (tptr
-> name
, tmap
-> name
, len
)) {
405 tptr
-> index
= ntohl (tmap
-> index
);
406 trace_type_stash (tptr
);
407 *prev
= tptr
-> next
;
410 prev
= &tptr
-> next
;
413 log_error ("No registered trace type for type name %.*s",
414 (int)length
- TRACE_INDEX_MAPPING_SIZE
, tmap
-> name
);
418 void trace_index_stop_tracing (trace_type_t
*ttype
) { }
420 void trace_replay_init (void)
422 trace_playback_flag
= 1;
425 void trace_file_replay (const char *filename
)
427 tracepacket_t
*tpkt
= NULL
;
432 trace_type_t
*ttype
= NULL
;
436 traceinfile
= fopen (filename
, "r");
438 log_error("Can't open tracefile %s: %m", filename
);
441 #if defined (HAVE_SETFD)
442 if (fcntl (fileno(traceinfile
), F_SETFD
, 1) < 0)
443 log_error("Can't set close-on-exec on %s: %m", filename
);
445 status
= fread(&tracefile_header
, 1,
446 sizeof tracefile_header
, traceinfile
);
447 if (status
< sizeof tracefile_header
) {
448 if (ferror(traceinfile
))
449 log_error("Error reading trace file header: %m");
451 log_error("Short read on trace file header: %d %ld.",
452 status
, (long)(sizeof tracefile_header
));
455 tracefile_header
.magic
= ntohl(tracefile_header
.magic
);
456 tracefile_header
.version
= ntohl(tracefile_header
.version
);
457 tracefile_header
.hlen
= ntohl(tracefile_header
.hlen
);
458 tracefile_header
.phlen
= ntohl(tracefile_header
.phlen
);
460 if (tracefile_header
.magic
!= TRACEFILE_MAGIC
) {
461 log_error("%s: not a dhcp trace file.", filename
);
464 if (tracefile_header
.version
> TRACEFILE_VERSION
) {
465 log_error ("tracefile version %ld > current %ld.",
466 (long int)tracefile_header
.version
,
467 (long int)TRACEFILE_VERSION
);
470 if (tracefile_header
.phlen
< sizeof *tpkt
) {
471 log_error("tracefile packet size too small - %ld < %ld",
472 (long int)tracefile_header
.phlen
,
473 (long int)sizeof *tpkt
);
476 len
= (sizeof tracefile_header
) - tracefile_header
.hlen
;
478 log_error("tracefile header size too small - %ld < %ld",
479 (long int)tracefile_header
.hlen
,
480 (long int)sizeof tracefile_header
);
484 status
= fseek(traceinfile
, (long)len
, SEEK_CUR
);
486 log_error("can't seek past header: %m");
491 tpkt
= dmalloc((unsigned)tracefile_header
.phlen
, MDL
);
493 log_error ("can't allocate trace packet header.");
497 while ((result
= trace_get_next_packet(&ttype
, tpkt
, &buf
, &buflen
,
498 &bufmax
)) == ISC_R_SUCCESS
) {
499 (*ttype
->have_packet
)(ttype
, tpkt
->length
, buf
);
510 /* Get the next packet from the file. If ttp points to a nonzero pointer
511 to a trace type structure, check the next packet to see if it's of the
512 expected type, and back off if not. */
514 isc_result_t
trace_get_next_packet (trace_type_t
**ttp
,
516 char **buf
, unsigned *buflen
,
521 int status
, curposok
= 0;
526 status
= fgetpos(traceinfile
, &curpos
);
528 log_error("Can't save tracefile position: %m");
533 status
= fread(tpkt
, 1, (size_t)tracefile_header
.phlen
,
535 if (status
< tracefile_header
.phlen
) {
536 if (ferror(traceinfile
))
537 log_error("Error reading trace packet header: "
539 else if (status
== 0)
542 log_error ("Short read on trace packet header:"
545 (long int)tracefile_header
.phlen
);
546 return DHCP_R_PROTOCOLERROR
;
549 /* Swap the packet. */
550 tpkt
->type_index
= ntohl(tpkt
-> type_index
);
551 tpkt
->length
= ntohl(tpkt
-> length
);
552 tpkt
->when
= ntohl(tpkt
-> when
);
554 /* See if there's a handler for this packet type. */
555 if (tpkt
->type_index
< trace_type_count
&&
556 trace_types
[tpkt
->type_index
])
557 ttype
= trace_types
[tpkt
->type_index
];
559 log_error ("Trace packet with unknown index %ld",
560 (long int)tpkt
->type_index
);
561 return DHCP_R_PROTOCOLERROR
;
565 * Determine if we should try to expire any timer events.
567 * we aren't looking for a specific type of packet
568 * we have a hook to use to update the timer
569 * the timestamp on the packet doesn't match the current time
570 * When we do so we rewind the file to the beginning of this
571 * packet and then try for a new packet. This allows
572 * any code triggered by a timeout to get the current packet
573 * while we get the next one.
576 if ((ttp
!= NULL
) && (*ttp
== NULL
) &&
577 (tpkt
->when
!= cur_tv
.tv_sec
) &&
578 (trace_set_time_hook
!= NULL
)) {
580 log_error("no curpos for fsetpos in "
582 return DHCP_R_PROTOCOLERROR
;
585 status
= fsetpos(traceinfile
, &curpos
);
587 log_error("fsetpos in tracefile failed: %m");
588 return DHCP_R_PROTOCOLERROR
;
591 (*trace_set_time_hook
) (tpkt
->when
);
597 /* If we were supposed to get a particular kind of packet,
598 check to see that we got the right kind. */
599 if (ttp
&& *ttp
&& ttype
!= *ttp
) {
600 log_error ("Read packet type %s when expecting %s",
601 ttype
-> name
, (*ttp
) -> name
);
602 status
= fsetpos (traceinfile
, &curpos
);
604 log_error ("fsetpos in tracefile failed: %m");
605 return DHCP_R_PROTOCOLERROR
;
607 return ISC_R_UNEXPECTEDTOKEN
;
610 paylen
= tpkt
-> length
;
612 paylen
+= 8 - (tpkt
-> length
% 8);
613 if (paylen
> (*bufmax
)) {
616 (*bufmax
) = ((paylen
+ 1023) & ~1023U);
617 (*buf
) = dmalloc ((*bufmax
), MDL
);
619 log_error ("Can't allocate input buffer sized %d",
621 return ISC_R_NOMEMORY
;
625 status
= fread ((*buf
), 1, paylen
, traceinfile
);
626 if (status
< paylen
) {
627 if (ferror (traceinfile
))
628 log_error ("Error reading trace payload: %m");
630 log_error ("Short read on trace payload: %d %d.",
632 return DHCP_R_PROTOCOLERROR
;
635 /* Store the actual length of the payload. */
636 *buflen
= tpkt
-> length
;
640 return ISC_R_SUCCESS
;
643 isc_result_t
trace_get_packet (trace_type_t
**ttp
,
644 unsigned *buflen
, char **buf
)
651 return DHCP_R_INVALIDARG
;
653 tpkt
= dmalloc ((unsigned)tracefile_header
.phlen
, MDL
);
655 log_error ("can't allocate trace packet header.");
656 return ISC_R_NOMEMORY
;
659 status
= trace_get_next_packet (ttp
, tpkt
, buf
, buflen
, &bufmax
);
665 /* Get a packet from the trace input file that contains a file with the
666 specified name. We don't hunt for the packet - it should be the next
667 packet in the tracefile. If it's not, or something else bad happens,
668 return an error code. */
670 isc_result_t
trace_get_file (trace_type_t
*ttype
,
671 const char *filename
, unsigned *len
, char **buf
)
679 /* Disallow some obvious bogosities. */
680 if (!buf
|| !len
|| *buf
)
681 return DHCP_R_INVALIDARG
;
683 /* Save file position in case of filename mismatch. */
684 status
= fgetpos (traceinfile
, &curpos
);
686 log_error ("Can't save tracefile position: %m");
688 tpkt
= dmalloc ((unsigned)tracefile_header
.phlen
, MDL
);
690 log_error ("can't allocate trace packet header.");
691 return ISC_R_NOMEMORY
;
694 result
= trace_get_next_packet (&ttype
, tpkt
, buf
, len
, &max
);
695 /* done with tpkt, free it */
697 if (result
!= ISC_R_SUCCESS
) {
705 /* Make sure the filename is right. */
706 if (strcmp (filename
, *buf
)) {
707 log_error ("Read file %s when expecting %s", *buf
, filename
);
711 status
= fsetpos (traceinfile
, &curpos
);
713 log_error ("fsetpos in tracefile failed: %m");
714 return DHCP_R_PROTOCOLERROR
;
716 return ISC_R_UNEXPECTEDTOKEN
;
719 return ISC_R_SUCCESS
;