Fix: events discarded timing inaccuracy
[babeltrace.git] / formats / ctf-text / ctf-text.c
1 /*
2 * BabelTrace - Common Trace Format (CTF)
3 *
4 * CTF Text Format registration.
5 *
6 * Copyright 2010-2011 EfficiOS Inc. and Linux Foundation
7 *
8 * Author: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
9 *
10 * Permission is hereby granted, free of charge, to any person obtaining a copy
11 * of this software and associated documentation files (the "Software"), to deal
12 * in the Software without restriction, including without limitation the rights
13 * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
14 * copies of the Software, and to permit persons to whom the Software is
15 * furnished to do so, subject to the following conditions:
16 *
17 * The above copyright notice and this permission notice shall be included in
18 * all copies or substantial portions of the Software.
19 *
20 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
21 * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
22 * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
23 * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
24 * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
25 * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
26 * SOFTWARE.
27 */
28
29 #include <babeltrace/format.h>
30 #include <babeltrace/ctf-text/types.h>
31 #include <babeltrace/ctf/metadata.h>
32 #include <babeltrace/babeltrace-internal.h>
33 #include <babeltrace/ctf/events-internal.h>
34 #include <inttypes.h>
35 #include <sys/mman.h>
36 #include <errno.h>
37 #include <sys/types.h>
38 #include <sys/stat.h>
39 #include <fcntl.h>
40 #include <dirent.h>
41 #include <glib.h>
42 #include <unistd.h>
43 #include <stdlib.h>
44
45 #define NSEC_PER_SEC 1000000000ULL
46
47 int opt_all_field_names,
48 opt_scope_field_names,
49 opt_header_field_names,
50 opt_context_field_names,
51 opt_payload_field_names,
52 opt_all_fields,
53 opt_trace_field,
54 opt_trace_domain_field,
55 opt_trace_procname_field,
56 opt_trace_vpid_field,
57 opt_trace_hostname_field,
58 opt_trace_default_fields = 1,
59 opt_loglevel_field,
60 opt_emf_field,
61 opt_callsite_field,
62 opt_delta_field = 1;
63
64 enum field_item {
65 ITEM_SCOPE,
66 ITEM_HEADER,
67 ITEM_CONTEXT,
68 ITEM_PAYLOAD,
69 };
70
71 enum bt_loglevel {
72 BT_LOGLEVEL_EMERG = 0,
73 BT_LOGLEVEL_ALERT = 1,
74 BT_LOGLEVEL_CRIT = 2,
75 BT_LOGLEVEL_ERR = 3,
76 BT_LOGLEVEL_WARNING = 4,
77 BT_LOGLEVEL_NOTICE = 5,
78 BT_LOGLEVEL_INFO = 6,
79 BT_LOGLEVEL_DEBUG_SYSTEM = 7,
80 BT_LOGLEVEL_DEBUG_PROGRAM = 8,
81 BT_LOGLEVEL_DEBUG_PROCESS = 9,
82 BT_LOGLEVEL_DEBUG_MODULE = 10,
83 BT_LOGLEVEL_DEBUG_UNIT = 11,
84 BT_LOGLEVEL_DEBUG_FUNCTION = 12,
85 BT_LOGLEVEL_DEBUG_LINE = 13,
86 BT_LOGLEVEL_DEBUG = 14,
87 };
88
89 static
90 struct bt_trace_descriptor *ctf_text_open_trace(const char *path, int flags,
91 void (*packet_seek)(struct bt_stream_pos *pos, size_t index,
92 int whence), FILE *metadata_fp);
93 static
94 int ctf_text_close_trace(struct bt_trace_descriptor *descriptor);
95
96 static
97 rw_dispatch write_dispatch_table[] = {
98 [ CTF_TYPE_INTEGER ] = ctf_text_integer_write,
99 [ CTF_TYPE_FLOAT ] = ctf_text_float_write,
100 [ CTF_TYPE_ENUM ] = ctf_text_enum_write,
101 [ CTF_TYPE_STRING ] = ctf_text_string_write,
102 [ CTF_TYPE_STRUCT ] = ctf_text_struct_write,
103 [ CTF_TYPE_VARIANT ] = ctf_text_variant_write,
104 [ CTF_TYPE_ARRAY ] = ctf_text_array_write,
105 [ CTF_TYPE_SEQUENCE ] = ctf_text_sequence_write,
106 };
107
108 static
109 struct bt_format ctf_text_format = {
110 .open_trace = ctf_text_open_trace,
111 .close_trace = ctf_text_close_trace,
112 };
113
114 static GQuark Q_STREAM_PACKET_CONTEXT_TIMESTAMP_BEGIN,
115 Q_STREAM_PACKET_CONTEXT_TIMESTAMP_END,
116 Q_STREAM_PACKET_CONTEXT_EVENTS_DISCARDED,
117 Q_STREAM_PACKET_CONTEXT_CONTENT_SIZE,
118 Q_STREAM_PACKET_CONTEXT_PACKET_SIZE;
119
120 static
121 void __attribute__((constructor)) init_quarks(void)
122 {
123 Q_STREAM_PACKET_CONTEXT_TIMESTAMP_BEGIN = g_quark_from_static_string("stream.packet.context.timestamp_begin");
124 Q_STREAM_PACKET_CONTEXT_TIMESTAMP_END = g_quark_from_static_string("stream.packet.context.timestamp_end");
125 Q_STREAM_PACKET_CONTEXT_EVENTS_DISCARDED = g_quark_from_static_string("stream.packet.context.events_discarded");
126 Q_STREAM_PACKET_CONTEXT_CONTENT_SIZE = g_quark_from_static_string("stream.packet.context.content_size");
127 Q_STREAM_PACKET_CONTEXT_PACKET_SIZE = g_quark_from_static_string("stream.packet.context.packet_size");
128 }
129
130 static
131 struct ctf_callsite_dups *ctf_trace_callsite_lookup(struct ctf_trace *trace,
132 GQuark callsite_name)
133 {
134 return g_hash_table_lookup(trace->callsites,
135 (gpointer) (unsigned long) callsite_name);
136 }
137
138 int print_field(struct bt_definition *definition)
139 {
140 /* Print all fields in verbose mode */
141 if (babeltrace_verbose)
142 return 1;
143
144 /* Filter out part of the packet context */
145 if (definition->path == Q_STREAM_PACKET_CONTEXT_TIMESTAMP_BEGIN)
146 return 0;
147 if (definition->path == Q_STREAM_PACKET_CONTEXT_TIMESTAMP_END)
148 return 0;
149 if (definition->path == Q_STREAM_PACKET_CONTEXT_EVENTS_DISCARDED)
150 return 0;
151 if (definition->path == Q_STREAM_PACKET_CONTEXT_CONTENT_SIZE)
152 return 0;
153 if (definition->path == Q_STREAM_PACKET_CONTEXT_PACKET_SIZE)
154 return 0;
155
156 return 1;
157 }
158
159 static
160 void set_field_names_print(struct ctf_text_stream_pos *pos, enum field_item item)
161 {
162 switch (item) {
163 case ITEM_SCOPE:
164 if (opt_all_field_names || opt_scope_field_names)
165 pos->print_names = 1;
166 else
167 pos->print_names = 0;
168 break;
169 case ITEM_HEADER:
170 if (opt_all_field_names || opt_header_field_names)
171 pos->print_names = 1;
172 else
173 pos->print_names = 0;
174 break;
175 case ITEM_CONTEXT:
176 if (opt_all_field_names || opt_context_field_names)
177 pos->print_names = 1;
178 else
179 pos->print_names = 0;
180 break;
181 case ITEM_PAYLOAD:
182 if (opt_all_field_names || opt_payload_field_names)
183 pos->print_names = 1;
184 else
185 pos->print_names = 0;
186
187 break;
188 default:
189 assert(0);
190 }
191 }
192
193 static
194 const char *print_loglevel(int value)
195 {
196 switch (value) {
197 case -1:
198 return "";
199 case BT_LOGLEVEL_EMERG:
200 return "TRACE_EMERG";
201 case BT_LOGLEVEL_ALERT:
202 return "TRACE_ALERT";
203 case BT_LOGLEVEL_CRIT:
204 return "TRACE_CRIT";
205 case BT_LOGLEVEL_ERR:
206 return "TRACE_ERR";
207 case BT_LOGLEVEL_WARNING:
208 return "TRACE_WARNING";
209 case BT_LOGLEVEL_NOTICE:
210 return "TRACE_NOTICE";
211 case BT_LOGLEVEL_INFO:
212 return "TRACE_INFO";
213 case BT_LOGLEVEL_DEBUG_SYSTEM:
214 return "TRACE_DEBUG_SYSTEM";
215 case BT_LOGLEVEL_DEBUG_PROGRAM:
216 return "TRACE_DEBUG_PROGRAM";
217 case BT_LOGLEVEL_DEBUG_PROCESS:
218 return "TRACE_DEBUG_PROCESS";
219 case BT_LOGLEVEL_DEBUG_MODULE:
220 return "TRACE_DEBUG_MODULE";
221 case BT_LOGLEVEL_DEBUG_UNIT:
222 return "TRACE_DEBUG_UNIT";
223 case BT_LOGLEVEL_DEBUG_FUNCTION:
224 return "TRACE_DEBUG_FUNCTION";
225 case BT_LOGLEVEL_DEBUG_LINE:
226 return "TRACE_DEBUG_LINE";
227 case BT_LOGLEVEL_DEBUG:
228 return "TRACE_DEBUG";
229 default:
230 return "<<UNKNOWN>>";
231 }
232 }
233
234 static
235 int ctf_text_write_event(struct bt_stream_pos *ppos, struct ctf_stream_definition *stream)
236
237 {
238 struct ctf_text_stream_pos *pos =
239 container_of(ppos, struct ctf_text_stream_pos, parent);
240 struct ctf_stream_declaration *stream_class = stream->stream_class;
241 int field_nr_saved;
242 struct ctf_event_declaration *event_class;
243 struct ctf_event_definition *event;
244 uint64_t id;
245 int ret;
246 int dom_print = 0;
247
248 id = stream->event_id;
249
250 if (id >= stream_class->events_by_id->len) {
251 fprintf(stderr, "[error] Event id %" PRIu64 " is outside range.\n", id);
252 return -EINVAL;
253 }
254 event = g_ptr_array_index(stream->events_by_id, id);
255 if (!event) {
256 fprintf(stderr, "[error] Event id %" PRIu64 " is unknown.\n", id);
257 return -EINVAL;
258 }
259 event_class = g_ptr_array_index(stream_class->events_by_id, id);
260 if (!event_class) {
261 fprintf(stderr, "[error] Event class id %" PRIu64 " is unknown.\n", id);
262 return -EINVAL;
263 }
264
265 if (stream->has_timestamp) {
266 set_field_names_print(pos, ITEM_HEADER);
267 if (pos->print_names)
268 fprintf(pos->fp, "timestamp = ");
269 else
270 fprintf(pos->fp, "[");
271 if (opt_clock_cycles) {
272 ctf_print_timestamp(pos->fp, stream, stream->cycles_timestamp);
273 } else {
274 ctf_print_timestamp(pos->fp, stream, stream->real_timestamp);
275 }
276 if (!pos->print_names)
277 fprintf(pos->fp, "]");
278
279 if (pos->print_names)
280 fprintf(pos->fp, ", ");
281 else
282 fprintf(pos->fp, " ");
283 }
284 if (opt_delta_field && stream->has_timestamp) {
285 uint64_t delta, delta_sec, delta_nsec;
286
287 set_field_names_print(pos, ITEM_HEADER);
288 if (pos->print_names)
289 fprintf(pos->fp, "delta = ");
290 else
291 fprintf(pos->fp, "(");
292 if (pos->last_real_timestamp != -1ULL) {
293 delta = stream->real_timestamp - pos->last_real_timestamp;
294 delta_sec = delta / NSEC_PER_SEC;
295 delta_nsec = delta % NSEC_PER_SEC;
296 fprintf(pos->fp, "+%" PRIu64 ".%09" PRIu64,
297 delta_sec, delta_nsec);
298 } else {
299 fprintf(pos->fp, "+?.?????????");
300 }
301 if (!pos->print_names)
302 fprintf(pos->fp, ")");
303
304 if (pos->print_names)
305 fprintf(pos->fp, ", ");
306 else
307 fprintf(pos->fp, " ");
308 pos->last_real_timestamp = stream->real_timestamp;
309 pos->last_cycles_timestamp = stream->cycles_timestamp;
310 }
311
312 if ((opt_trace_field || opt_all_fields) && stream_class->trace->parent.path[0] != '\0') {
313 set_field_names_print(pos, ITEM_HEADER);
314 if (pos->print_names) {
315 fprintf(pos->fp, "trace = ");
316 }
317 fprintf(pos->fp, "%s", stream_class->trace->parent.path);
318 if (pos->print_names)
319 fprintf(pos->fp, ", ");
320 else
321 fprintf(pos->fp, " ");
322 }
323 if ((opt_trace_hostname_field || opt_all_fields || opt_trace_default_fields)
324 && stream_class->trace->env.hostname[0] != '\0') {
325 set_field_names_print(pos, ITEM_HEADER);
326 if (pos->print_names) {
327 fprintf(pos->fp, "trace:hostname = ");
328 }
329 fprintf(pos->fp, "%s", stream_class->trace->env.hostname);
330 if (pos->print_names)
331 fprintf(pos->fp, ", ");
332 dom_print = 1;
333 }
334 if ((opt_trace_domain_field || opt_all_fields) && stream_class->trace->env.domain[0] != '\0') {
335 set_field_names_print(pos, ITEM_HEADER);
336 if (pos->print_names) {
337 fprintf(pos->fp, "trace:domain = ");
338 }
339 fprintf(pos->fp, "%s", stream_class->trace->env.domain);
340 if (pos->print_names)
341 fprintf(pos->fp, ", ");
342 dom_print = 1;
343 }
344 if ((opt_trace_procname_field || opt_all_fields || opt_trace_default_fields)
345 && stream_class->trace->env.procname[0] != '\0') {
346 set_field_names_print(pos, ITEM_HEADER);
347 if (pos->print_names) {
348 fprintf(pos->fp, "trace:procname = ");
349 } else if (dom_print) {
350 fprintf(pos->fp, ":");
351 }
352 fprintf(pos->fp, "%s", stream_class->trace->env.procname);
353 if (pos->print_names)
354 fprintf(pos->fp, ", ");
355 dom_print = 1;
356 }
357 if ((opt_trace_vpid_field || opt_all_fields || opt_trace_default_fields)
358 && stream_class->trace->env.vpid != -1) {
359 set_field_names_print(pos, ITEM_HEADER);
360 if (pos->print_names) {
361 fprintf(pos->fp, "trace:vpid = ");
362 } else if (dom_print) {
363 fprintf(pos->fp, ":");
364 }
365 fprintf(pos->fp, "%d", stream_class->trace->env.vpid);
366 if (pos->print_names)
367 fprintf(pos->fp, ", ");
368 dom_print = 1;
369 }
370 if ((opt_loglevel_field || opt_all_fields) && event_class->loglevel != -1) {
371 set_field_names_print(pos, ITEM_HEADER);
372 if (pos->print_names) {
373 fprintf(pos->fp, "loglevel = ");
374 } else if (dom_print) {
375 fprintf(pos->fp, ":");
376 }
377 fprintf(pos->fp, "%s (%d)",
378 print_loglevel(event_class->loglevel),
379 event_class->loglevel);
380 if (pos->print_names)
381 fprintf(pos->fp, ", ");
382 dom_print = 1;
383 }
384 if ((opt_emf_field || opt_all_fields) && event_class->model_emf_uri) {
385 set_field_names_print(pos, ITEM_HEADER);
386 if (pos->print_names) {
387 fprintf(pos->fp, "model.emf.uri = ");
388 } else if (dom_print) {
389 fprintf(pos->fp, ":");
390 }
391 fprintf(pos->fp, "\"%s\"",
392 g_quark_to_string(event_class->model_emf_uri));
393 if (pos->print_names)
394 fprintf(pos->fp, ", ");
395 dom_print = 1;
396 }
397 if ((opt_callsite_field || opt_all_fields)) {
398 struct ctf_callsite_dups *cs_dups;
399 struct ctf_callsite *callsite;
400
401 cs_dups = ctf_trace_callsite_lookup(stream_class->trace,
402 event_class->name);
403 if (cs_dups) {
404 int i = 0;
405
406 set_field_names_print(pos, ITEM_HEADER);
407 if (pos->print_names) {
408 fprintf(pos->fp, "callsite = ");
409 } else if (dom_print) {
410 fprintf(pos->fp, ":");
411 }
412 fprintf(pos->fp, "[");
413 bt_list_for_each_entry(callsite, &cs_dups->head, node) {
414 if (i != 0)
415 fprintf(pos->fp, ",");
416 if (CTF_CALLSITE_FIELD_IS_SET(callsite, ip)) {
417 fprintf(pos->fp, "%s@0x%" PRIx64 ":%s:%" PRIu64 "",
418 callsite->func, callsite->ip, callsite->file,
419 callsite->line);
420 } else {
421 fprintf(pos->fp, "%s:%s:%" PRIu64 "",
422 callsite->func, callsite->file,
423 callsite->line);
424 }
425 i++;
426 }
427 fprintf(pos->fp, "]");
428 if (pos->print_names)
429 fprintf(pos->fp, ", ");
430 dom_print = 1;
431 }
432 }
433 if (dom_print && !pos->print_names)
434 fprintf(pos->fp, " ");
435 set_field_names_print(pos, ITEM_HEADER);
436 if (pos->print_names)
437 fprintf(pos->fp, "name = ");
438 fprintf(pos->fp, "%s", g_quark_to_string(event_class->name));
439 if (pos->print_names)
440 pos->field_nr++;
441 else
442 fprintf(pos->fp, ":");
443
444 /* print cpuid field from packet context */
445 if (stream->stream_packet_context) {
446 if (pos->field_nr++ != 0)
447 fprintf(pos->fp, ",");
448 set_field_names_print(pos, ITEM_SCOPE);
449 if (pos->print_names)
450 fprintf(pos->fp, " stream.packet.context =");
451 field_nr_saved = pos->field_nr;
452 pos->field_nr = 0;
453 set_field_names_print(pos, ITEM_CONTEXT);
454 ret = generic_rw(ppos, &stream->stream_packet_context->p);
455 if (ret)
456 goto error;
457 pos->field_nr = field_nr_saved;
458 }
459
460 /* Only show the event header in verbose mode */
461 if (babeltrace_verbose && stream->stream_event_header) {
462 if (pos->field_nr++ != 0)
463 fprintf(pos->fp, ",");
464 set_field_names_print(pos, ITEM_SCOPE);
465 if (pos->print_names)
466 fprintf(pos->fp, " stream.event.header =");
467 field_nr_saved = pos->field_nr;
468 pos->field_nr = 0;
469 set_field_names_print(pos, ITEM_CONTEXT);
470 ret = generic_rw(ppos, &stream->stream_event_header->p);
471 if (ret)
472 goto error;
473 pos->field_nr = field_nr_saved;
474 }
475
476 /* print stream-declared event context */
477 if (stream->stream_event_context) {
478 if (pos->field_nr++ != 0)
479 fprintf(pos->fp, ",");
480 set_field_names_print(pos, ITEM_SCOPE);
481 if (pos->print_names)
482 fprintf(pos->fp, " stream.event.context =");
483 field_nr_saved = pos->field_nr;
484 pos->field_nr = 0;
485 set_field_names_print(pos, ITEM_CONTEXT);
486 ret = generic_rw(ppos, &stream->stream_event_context->p);
487 if (ret)
488 goto error;
489 pos->field_nr = field_nr_saved;
490 }
491
492 /* print event-declared event context */
493 if (event->event_context) {
494 if (pos->field_nr++ != 0)
495 fprintf(pos->fp, ",");
496 set_field_names_print(pos, ITEM_SCOPE);
497 if (pos->print_names)
498 fprintf(pos->fp, " event.context =");
499 field_nr_saved = pos->field_nr;
500 pos->field_nr = 0;
501 set_field_names_print(pos, ITEM_CONTEXT);
502 ret = generic_rw(ppos, &event->event_context->p);
503 if (ret)
504 goto error;
505 pos->field_nr = field_nr_saved;
506 }
507
508 /* Read and print event payload */
509 if (event->event_fields) {
510 if (pos->field_nr++ != 0)
511 fprintf(pos->fp, ",");
512 set_field_names_print(pos, ITEM_SCOPE);
513 if (pos->print_names)
514 fprintf(pos->fp, " event.fields =");
515 field_nr_saved = pos->field_nr;
516 pos->field_nr = 0;
517 set_field_names_print(pos, ITEM_PAYLOAD);
518 ret = generic_rw(ppos, &event->event_fields->p);
519 if (ret)
520 goto error;
521 pos->field_nr = field_nr_saved;
522 }
523 /* newline */
524 fprintf(pos->fp, "\n");
525 pos->field_nr = 0;
526
527 return 0;
528
529 error:
530 fprintf(stderr, "[error] Unexpected end of stream. Either the trace data stream is corrupted or metadata description does not match data layout.\n");
531 return ret;
532 }
533
534 static
535 struct bt_trace_descriptor *ctf_text_open_trace(const char *path, int flags,
536 void (*packet_seek)(struct bt_stream_pos *pos, size_t index,
537 int whence), FILE *metadata_fp)
538 {
539 struct ctf_text_stream_pos *pos;
540 FILE *fp;
541
542 pos = g_new0(struct ctf_text_stream_pos, 1);
543
544 pos->last_real_timestamp = -1ULL;
545 pos->last_cycles_timestamp = -1ULL;
546 switch (flags & O_ACCMODE) {
547 case O_RDWR:
548 if (!path)
549 fp = stdout;
550 else
551 fp = fopen(path, "w");
552 if (!fp)
553 goto error;
554 pos->fp = fp;
555 pos->parent.rw_table = write_dispatch_table;
556 pos->parent.event_cb = ctf_text_write_event;
557 pos->parent.trace = &pos->trace_descriptor;
558 pos->print_names = 0;
559 babeltrace_ctf_console_output++;
560 break;
561 case O_RDONLY:
562 default:
563 fprintf(stderr, "[error] Incorrect open flags.\n");
564 goto error;
565 }
566
567 return &pos->trace_descriptor;
568 error:
569 g_free(pos);
570 return NULL;
571 }
572
573 static
574 int ctf_text_close_trace(struct bt_trace_descriptor *td)
575 {
576 int ret;
577 struct ctf_text_stream_pos *pos =
578 container_of(td, struct ctf_text_stream_pos, trace_descriptor);
579
580 babeltrace_ctf_console_output--;
581 if (pos->fp != stdout) {
582 ret = fclose(pos->fp);
583 if (ret) {
584 perror("Error on fclose");
585 return -1;
586 }
587 }
588 g_free(pos);
589 return 0;
590 }
591
592 static
593 void __attribute__((constructor)) ctf_text_init(void)
594 {
595 int ret;
596
597 ctf_text_format.name = g_quark_from_static_string("text");
598 ret = bt_register_format(&ctf_text_format);
599 assert(!ret);
600 }
601
602 static
603 void __attribute__((destructor)) ctf_text_exit(void)
604 {
605 bt_unregister_format(&ctf_text_format);
606 }
This page took 0.040491 seconds and 4 git commands to generate.