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) 2004-2017 by Internet Systems Consortium, Inc. ("ISC")
9 * Copyright (c) 2001-2003 by Internet Software Consortium
11 * This Source Code Form is subject to the terms of the Mozilla Public
12 * License, v. 2.0. If a copy of the MPL was not distributed with this
13 * file, You can obtain one at http://mozilla.org/MPL/2.0/.
15 * THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES
16 * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
17 * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL ISC BE LIABLE FOR
18 * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
19 * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
20 * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT
21 * OF OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
23 * Internet Systems Consortium, Inc.
25 * Newmarket, NH 03857 USA
27 * https://www.isc.org/
32 #include <omapip/omapip_p.h>
36 void (*trace_set_time_hook
) (TIME
);
37 static int tracing_stopped
;
38 static int traceoutfile
;
39 static int traceindex
;
40 static trace_type_t
**trace_types
;
41 static int trace_type_count
;
42 static int trace_type_max
;
43 static trace_type_t
*new_trace_types
;
44 static FILE *traceinfile
;
45 static tracefile_header_t tracefile_header
;
46 static int trace_playback_flag
;
47 trace_type_t trace_time_marker
;
49 #if defined (DEBUG_MEMORY_LEAKAGE) || defined (DEBUG_MEMORY_LEAKAGE_ON_EXIT)
50 extern omapi_array_t
*trace_listeners
;
51 extern omapi_array_t
*omapi_connections
;
55 void trace_free_all ()
61 new_trace_types
= tp
-> next
;
63 dfree (tp
-> name
, MDL
);
64 tp
-> name
= (char *)0;
69 for (i
= 0; i
< trace_type_count
; i
++) {
70 if (trace_types
[i
]) {
71 if (trace_types
[i
] -> name
)
72 dfree (trace_types
[i
] -> name
, MDL
);
73 dfree (trace_types
[i
], MDL
);
76 dfree (trace_types
, MDL
);
77 trace_types
= (trace_type_t
**)0;
78 trace_type_count
= trace_type_max
= 0;
80 omapi_array_free (&trace_listeners
, MDL
);
81 omapi_array_free (&omapi_connections
, MDL
);
85 static isc_result_t
trace_type_record (trace_type_t
*,
86 unsigned, const char *, int);
90 return trace_playback_flag
;
95 if (traceoutfile
&& !tracing_stopped
)
100 isc_result_t
trace_init (void (*set_time
) (TIME
),
101 const char *file
, int line
)
103 trace_type_t
*root_type
;
104 static int root_setup
= 0;
107 return ISC_R_SUCCESS
;
109 trace_set_time_hook
= set_time
;
111 root_type
= trace_type_register ("trace-index-mapping",
112 (void *)0, trace_index_map_input
,
113 trace_index_stop_tracing
, file
, line
);
115 return ISC_R_UNEXPECTED
;
116 if (new_trace_types
== root_type
)
117 new_trace_types
= new_trace_types
-> next
;
118 root_type
-> index
= 0;
119 trace_type_stash (root_type
);
122 return ISC_R_SUCCESS
;
125 isc_result_t
trace_begin (const char *filename
,
126 const char *file
, int line
)
128 tracefile_header_t tfh
;
130 trace_type_t
*tptr
, *next
;
134 log_error ("%s(%d): trace_begin called twice",
136 return DHCP_R_INVALIDARG
;
139 traceoutfile
= open (filename
, O_CREAT
| O_WRONLY
| O_EXCL
, 0600);
140 if (traceoutfile
< 0 && errno
== EEXIST
) {
141 log_error ("WARNING: Overwriting trace file \"%s\"", filename
);
142 traceoutfile
= open (filename
, O_WRONLY
| O_EXCL
| O_TRUNC
,
146 if (traceoutfile
< 0) {
147 log_error ("%s(%d): trace_begin: %s: %m",
148 file
, line
, filename
);
149 return ISC_R_UNEXPECTED
;
151 #if defined (HAVE_SETFD)
152 if (fcntl (traceoutfile
, F_SETFD
, 1) < 0)
153 log_error ("Can't set close-on-exec on %s: %m", filename
);
156 tfh
.magic
= htonl (TRACEFILE_MAGIC
);
157 tfh
.version
= htonl (TRACEFILE_VERSION
);
158 tfh
.hlen
= htonl (sizeof (tracefile_header_t
));
159 tfh
.phlen
= htonl (sizeof (tracepacket_t
));
161 status
= write (traceoutfile
, &tfh
, sizeof tfh
);
163 log_error ("%s(%d): trace_begin write failed: %m", file
, line
);
164 return ISC_R_UNEXPECTED
;
165 } else if (status
!= sizeof tfh
) {
166 log_error ("%s(%d): trace_begin: short write (%d:%ld)",
167 file
, line
, status
, (long)(sizeof tfh
));
169 return ISC_R_UNEXPECTED
;
172 /* Stash all the types that have already been set up. */
173 if (new_trace_types
) {
174 next
= new_trace_types
;
175 new_trace_types
= (trace_type_t
*)0;
176 for (tptr
= next
; tptr
; tptr
= next
) {
178 if (tptr
-> index
!= 0) {
179 result
= (trace_type_record
181 strlen (tptr
-> name
), file
, line
));
182 if (result
!= ISC_R_SUCCESS
)
188 return ISC_R_SUCCESS
;
191 isc_result_t
trace_write_packet (trace_type_t
*ttype
, unsigned length
,
192 const char *buf
, const char *file
, int line
)
198 return trace_write_packet_iov (ttype
, 1, &iov
, file
, line
);
201 isc_result_t
trace_write_packet_iov (trace_type_t
*ttype
,
202 int count
, trace_iov_t
*iov
,
203 const char *file
, int line
)
210 /* Really shouldn't get called here, but it may be hard to turn off
211 tracing midstream if the trace file write fails or something. */
216 log_error ("%s(%d): trace_write_packet with null trace type",
217 file
? file
: "<unknown file>", line
);
218 return DHCP_R_INVALIDARG
;
221 log_error ("%s(%d): trace_write_packet with no tracefile.",
222 file
? file
: "<unknown file>", line
);
223 return DHCP_R_INVALIDARG
;
226 /* Compute the total length of the iov. */
228 for (i
= 0; i
< count
; i
++)
229 length
+= iov
[i
].len
;
231 /* We have to swap out the data, because it may be read back on a
232 machine of different endianness. */
233 memset(&tmp
, 0, sizeof(tmp
));
234 tmp
.type_index
= htonl (ttype
-> index
);
235 tmp
.when
= htonl (time ((time_t *)0)); /* XXX */
236 tmp
.length
= htonl (length
);
238 status
= write (traceoutfile
, &tmp
, sizeof tmp
);
240 log_error ("%s(%d): trace_write_packet write failed: %m",
242 return ISC_R_UNEXPECTED
;
243 } else if (status
!= sizeof tmp
) {
244 log_error ("%s(%d): trace_write_packet: short write (%d:%ld)",
245 file
, line
, status
, (long)(sizeof tmp
));
249 for (i
= 0; i
< count
; i
++) {
250 status
= write (traceoutfile
, iov
[i
].buf
, iov
[i
].len
);
252 log_error ("%s(%d): %s write failed: %m",
253 file
, line
, "trace_write_packet");
254 return ISC_R_UNEXPECTED
;
255 } else if (status
!= iov
[i
].len
) {
256 log_error ("%s(%d): %s: short write (%d:%d)",
258 "trace_write_packet", status
, length
);
263 /* Write padding on the end of the packet to align the next
264 packet to an 8-byte boundary. This is in case we decide to
265 use mmap in some clever way later on. */
267 static char zero
[] = { 0, 0, 0, 0, 0, 0, 0 };
268 unsigned padl
= 8 - (length
% 8);
270 status
= write (traceoutfile
, zero
, padl
);
272 log_error ("%s(%d): trace_write_packet write failed: %m",
274 return ISC_R_UNEXPECTED
;
275 } else if (status
!= padl
) {
276 log_error ("%s(%d): trace_write_packet: short write (%d:%d)",
277 file
, line
, status
, padl
);
282 return ISC_R_SUCCESS
;
285 void trace_type_stash (trace_type_t
*tptr
)
289 if (trace_type_max
<= tptr
-> index
) {
290 delta
= tptr
-> index
- trace_type_max
+ 10;
291 vec
= dmalloc (((trace_type_max
+ delta
) *
292 sizeof (trace_type_t
*)), MDL
);
295 memset (&vec
[trace_type_max
], 0,
296 (sizeof (trace_type_t
*)) * delta
);
297 trace_type_max
+= delta
;
299 memcpy (vec
, trace_types
,
300 trace_type_count
* sizeof (trace_type_t
*));
301 dfree (trace_types
, MDL
);
305 trace_types
[tptr
-> index
] = tptr
;
306 if (tptr
-> index
>= trace_type_count
)
307 trace_type_count
= tptr
-> index
+ 1;
310 trace_type_t
*trace_type_register (const char *name
,
312 void (*have_packet
) (trace_type_t
*,
314 void (*stop_tracing
) (trace_type_t
*),
315 const char *file
, int line
)
318 unsigned slen
= strlen (name
);
321 ttmp
= dmalloc (sizeof *ttmp
, file
, line
);
325 ttmp
-> name
= dmalloc (slen
+ 1, file
, line
);
327 dfree (ttmp
, file
, line
);
328 return (trace_type_t
*)0;
330 strcpy (ttmp
-> name
, name
);
331 ttmp
-> have_packet
= have_packet
;
332 ttmp
-> stop_tracing
= stop_tracing
;
335 status
= trace_type_record (ttmp
, slen
, file
, line
);
336 if (status
!= ISC_R_SUCCESS
) {
337 dfree (ttmp
-> name
, file
, line
);
338 dfree (ttmp
, file
, line
);
339 return (trace_type_t
*)0;
342 ttmp
-> next
= new_trace_types
;
343 new_trace_types
= ttmp
;
349 static isc_result_t
trace_type_record (trace_type_t
*ttmp
, unsigned slen
,
350 const char *file
, int line
)
352 trace_index_mapping_t
*tim
;
355 tim
= dmalloc (slen
+ TRACE_INDEX_MAPPING_SIZE
, file
, line
);
357 return ISC_R_NOMEMORY
;
358 ttmp
-> index
= ++traceindex
;
359 trace_type_stash (ttmp
);
360 tim
-> index
= htonl (ttmp
-> index
);
361 memcpy (tim
-> name
, ttmp
-> name
, slen
);
362 status
= trace_write_packet (trace_types
[0],
363 slen
+ TRACE_INDEX_MAPPING_SIZE
,
364 (char *)tim
, file
, line
);
365 dfree (tim
, file
, line
);
369 /* Stop all registered trace types from trying to trace. */
371 void trace_stop (void)
375 for (i
= 0; i
< trace_type_count
; i
++)
376 if (trace_types
[i
] -> stop_tracing
)
377 (*(trace_types
[i
] -> stop_tracing
))
382 void trace_index_map_input (trace_type_t
*ttype
, unsigned length
, char *buf
)
384 trace_index_mapping_t
*tmap
;
386 trace_type_t
*tptr
, **prev
;
388 if (length
< TRACE_INDEX_MAPPING_SIZE
) {
389 log_error ("short trace index mapping");
392 tmap
= (trace_index_mapping_t
*)buf
;
394 prev
= &new_trace_types
;
395 for (tptr
= new_trace_types
; tptr
; tptr
= tptr
-> next
) {
396 len
= strlen (tptr
-> name
);
397 if (len
== length
- TRACE_INDEX_MAPPING_SIZE
&&
398 !memcmp (tptr
-> name
, tmap
-> name
, len
)) {
399 tptr
-> index
= ntohl (tmap
-> index
);
400 trace_type_stash (tptr
);
401 *prev
= tptr
-> next
;
404 prev
= &tptr
-> next
;
407 log_error ("No registered trace type for type name %.*s",
408 (int)length
- TRACE_INDEX_MAPPING_SIZE
, tmap
-> name
);
412 void trace_index_stop_tracing (trace_type_t
*ttype
) { }
414 void trace_replay_init (void)
416 trace_playback_flag
= 1;
419 void trace_file_replay (const char *filename
)
421 tracepacket_t
*tpkt
= NULL
;
426 trace_type_t
*ttype
= NULL
;
430 traceinfile
= fopen (filename
, "r");
432 log_error("Can't open tracefile %s: %m", filename
);
435 #if defined (HAVE_SETFD)
436 if (fcntl (fileno(traceinfile
), F_SETFD
, 1) < 0)
437 log_error("Can't set close-on-exec on %s: %m", filename
);
439 status
= fread(&tracefile_header
, 1,
440 sizeof tracefile_header
, traceinfile
);
441 if (status
< sizeof tracefile_header
) {
442 if (ferror(traceinfile
))
443 log_error("Error reading trace file header: %m");
445 log_error("Short read on trace file header: %d %ld.",
446 status
, (long)(sizeof tracefile_header
));
449 tracefile_header
.magic
= ntohl(tracefile_header
.magic
);
450 tracefile_header
.version
= ntohl(tracefile_header
.version
);
451 tracefile_header
.hlen
= ntohl(tracefile_header
.hlen
);
452 tracefile_header
.phlen
= ntohl(tracefile_header
.phlen
);
454 if (tracefile_header
.magic
!= TRACEFILE_MAGIC
) {
455 log_error("%s: not a dhcp trace file.", filename
);
458 if (tracefile_header
.version
> TRACEFILE_VERSION
) {
459 log_error ("tracefile version %ld > current %ld.",
460 (long int)tracefile_header
.version
,
461 (long int)TRACEFILE_VERSION
);
464 if (tracefile_header
.phlen
< sizeof *tpkt
) {
465 log_error("tracefile packet size too small - %ld < %ld",
466 (long int)tracefile_header
.phlen
,
467 (long int)sizeof *tpkt
);
470 len
= (sizeof tracefile_header
) - tracefile_header
.hlen
;
472 log_error("tracefile header size too small - %ld < %ld",
473 (long int)tracefile_header
.hlen
,
474 (long int)sizeof tracefile_header
);
478 status
= fseek(traceinfile
, (long)len
, SEEK_CUR
);
480 log_error("can't seek past header: %m");
485 tpkt
= dmalloc((unsigned)tracefile_header
.phlen
, MDL
);
487 log_error ("can't allocate trace packet header.");
491 while ((result
= trace_get_next_packet(&ttype
, tpkt
, &buf
, &buflen
,
492 &bufmax
)) == ISC_R_SUCCESS
) {
493 (*ttype
->have_packet
)(ttype
, tpkt
->length
, buf
);
504 /* Get the next packet from the file. If ttp points to a nonzero pointer
505 to a trace type structure, check the next packet to see if it's of the
506 expected type, and back off if not. */
508 isc_result_t
trace_get_next_packet (trace_type_t
**ttp
,
510 char **buf
, unsigned *buflen
,
515 int status
, curposok
= 0;
520 status
= fgetpos(traceinfile
, &curpos
);
522 log_error("Can't save tracefile position: %m");
527 status
= fread(tpkt
, 1, (size_t)tracefile_header
.phlen
,
529 if (status
< tracefile_header
.phlen
) {
530 if (ferror(traceinfile
))
531 log_error("Error reading trace packet header: "
533 else if (status
== 0)
536 log_error ("Short read on trace packet header:"
539 (long int)tracefile_header
.phlen
);
540 return DHCP_R_PROTOCOLERROR
;
543 /* Swap the packet. */
544 tpkt
->type_index
= ntohl(tpkt
-> type_index
);
545 tpkt
->length
= ntohl(tpkt
-> length
);
546 tpkt
->when
= ntohl(tpkt
-> when
);
548 /* See if there's a handler for this packet type. */
549 if (tpkt
->type_index
< trace_type_count
&&
550 trace_types
[tpkt
->type_index
])
551 ttype
= trace_types
[tpkt
->type_index
];
553 log_error ("Trace packet with unknown index %ld",
554 (long int)tpkt
->type_index
);
555 return DHCP_R_PROTOCOLERROR
;
559 * Determine if we should try to expire any timer events.
561 * we aren't looking for a specific type of packet
562 * we have a hook to use to update the timer
563 * the timestamp on the packet doesn't match the current time
564 * When we do so we rewind the file to the beginning of this
565 * packet and then try for a new packet. This allows
566 * any code triggered by a timeout to get the current packet
567 * while we get the next one.
570 if ((ttp
!= NULL
) && (*ttp
== NULL
) &&
571 (tpkt
->when
!= cur_tv
.tv_sec
) &&
572 (trace_set_time_hook
!= NULL
)) {
574 log_error("no curpos for fsetpos in "
576 return DHCP_R_PROTOCOLERROR
;
579 status
= fsetpos(traceinfile
, &curpos
);
581 log_error("fsetpos in tracefile failed: %m");
582 return DHCP_R_PROTOCOLERROR
;
585 (*trace_set_time_hook
) (tpkt
->when
);
591 /* If we were supposed to get a particular kind of packet,
592 check to see that we got the right kind. */
593 if (ttp
&& *ttp
&& ttype
!= *ttp
) {
594 log_error ("Read packet type %s when expecting %s",
595 ttype
-> name
, (*ttp
) -> name
);
596 status
= fsetpos (traceinfile
, &curpos
);
598 log_error ("fsetpos in tracefile failed: %m");
599 return DHCP_R_PROTOCOLERROR
;
601 return ISC_R_UNEXPECTEDTOKEN
;
604 paylen
= tpkt
-> length
;
606 paylen
+= 8 - (tpkt
-> length
% 8);
608 /* allocate a buffer if we need one or current buffer is too small */
609 if ((*buf
== NULL
) || (paylen
> (*bufmax
))) {
612 (*bufmax
) = ((paylen
+ 1023) & ~1023U);
613 (*buf
) = dmalloc ((*bufmax
), MDL
);
615 log_error ("Can't allocate input buffer sized %d",
617 return ISC_R_NOMEMORY
;
621 status
= fread ((*buf
), 1, paylen
, traceinfile
);
622 if (status
< paylen
) {
623 if (ferror (traceinfile
))
624 log_error ("Error reading trace payload: %m");
626 log_error ("Short read on trace payload: %d %d.",
628 return DHCP_R_PROTOCOLERROR
;
631 /* Store the actual length of the payload. */
632 *buflen
= tpkt
-> length
;
636 return ISC_R_SUCCESS
;
639 isc_result_t
trace_get_packet (trace_type_t
**ttp
,
640 unsigned *buflen
, char **buf
)
647 return DHCP_R_INVALIDARG
;
649 tpkt
= dmalloc ((unsigned)tracefile_header
.phlen
, MDL
);
651 log_error ("can't allocate trace packet header.");
652 return ISC_R_NOMEMORY
;
655 status
= trace_get_next_packet (ttp
, tpkt
, buf
, buflen
, &bufmax
);
661 /* Get a packet from the trace input file that contains a file with the
662 specified name. We don't hunt for the packet - it should be the next
663 packet in the tracefile. If it's not, or something else bad happens,
664 return an error code. */
666 isc_result_t
trace_get_file (trace_type_t
*ttype
,
667 const char *filename
, unsigned *len
, char **buf
)
675 /* Disallow some obvious bogosities. */
676 if (!buf
|| !len
|| *buf
)
677 return DHCP_R_INVALIDARG
;
679 /* Save file position in case of filename mismatch. */
680 status
= fgetpos (traceinfile
, &curpos
);
682 log_error ("Can't save tracefile position: %m");
684 tpkt
= dmalloc ((unsigned)tracefile_header
.phlen
, MDL
);
686 log_error ("can't allocate trace packet header.");
687 return ISC_R_NOMEMORY
;
690 result
= trace_get_next_packet (&ttype
, tpkt
, buf
, len
, &max
);
691 /* done with tpkt, free it */
693 if (result
!= ISC_R_SUCCESS
) {
701 /* Make sure the filename is right. */
702 if (strcmp (filename
, *buf
)) {
703 log_error ("Read file %s when expecting %s", *buf
, filename
);
707 status
= fsetpos (traceinfile
, &curpos
);
709 log_error ("fsetpos in tracefile failed: %m");
710 return DHCP_R_PROTOCOLERROR
;
712 return ISC_R_UNEXPECTEDTOKEN
;
715 return ISC_R_SUCCESS
;