de2d86a4fa8dd8fc4a498cc74ac70d816a2996bb
[lttv.git] / lttv / lttv / sync / event_processing_lttng_standard.c
1 /* This file is part of the Linux Trace Toolkit viewer
2 * Copyright (C) 2009 Benjamin Poirier <benjamin.poirier@polymtl.ca>
3 *
4 * This program is free software; you can redistribute it and/or modify
5 * it under the terms of the GNU General Public License Version 2 as
6 * published by the Free Software Foundation;
7 *
8 * This program is distributed in the hope that it will be useful,
9 * but WITHOUT ANY WARRANTY; without even the implied warranty of
10 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
11 * GNU General Public License for more details.
12 *
13 * You should have received a copy of the GNU General Public License
14 * along with this program; if not, write to the Free Software
15 * Foundation, Inc., 59 Temple Place - Suite 330, Boston,
16 * MA 02111-1307, USA.
17 */
18
19 #define _ISOC99_SOURCE
20
21 #ifdef HAVE_CONFIG_H
22 #include <config.h>
23 #endif
24
25 #include <linux/if_ether.h>
26 #include <math.h>
27 #include <netinet/in.h>
28 #include <stdint.h>
29 #include <stdlib.h>
30
31 #include "sync_chain_lttv.h"
32 #include "event_processing_lttng_common.h"
33
34 #include "event_processing_lttng_standard.h"
35
36
37 #ifndef g_info
38 #define g_info(format...) g_log (G_LOG_DOMAIN, G_LOG_LEVEL_INFO, format)
39 #endif
40
41
42 // Functions common to all processing modules
43 static void initProcessingLTTVStandard(SyncState* const syncState,
44 LttvTracesetContext* const traceSetContext);
45 static void destroyProcessingLTTVStandard(SyncState* const syncState);
46
47 static void finalizeProcessingLTTVStandard(SyncState* const syncState);
48 static void printProcessingStatsLTTVStandard(SyncState* const syncState);
49 static void writeProcessingGraphsPlotsLTTVStandard(FILE* stream, SyncState*
50 const syncState, const unsigned int i, const unsigned int j);
51 static void writeProcessingGraphsOptionsLTTVStandard(FILE* stream, SyncState*
52 const syncState, const unsigned int i, const unsigned int j);
53
54 // Functions specific to this module
55 static void registerProcessingLTTVStandard() __attribute__((constructor (102)));
56 static gboolean processEventLTTVStandard(void* hookData, void* callData);
57 static void partialDestroyProcessingLTTVStandard(SyncState* const syncState);
58
59
60 static ProcessingModule processingModuleLTTVStandard = {
61 .name= "LTTV-standard",
62 .initProcessing= &initProcessingLTTVStandard,
63 .destroyProcessing= &destroyProcessingLTTVStandard,
64 .finalizeProcessing= &finalizeProcessingLTTVStandard,
65 .printProcessingStats= &printProcessingStatsLTTVStandard,
66 .writeProcessingGraphsPlots= &writeProcessingGraphsPlotsLTTVStandard,
67 .writeProcessingGraphsOptions= &writeProcessingGraphsOptionsLTTVStandard,
68 };
69
70
71
72 /*
73 * Processing Module registering function
74 */
75 static void registerProcessingLTTVStandard()
76 {
77 g_queue_push_tail(&processingModules, &processingModuleLTTVStandard);
78
79 createQuarks();
80 }
81
82
83 /*
84 * Allocate and initialize data structures for synchronizing a traceset.
85 * Register event hooks.
86 *
87 * Args:
88 * syncState: container for synchronization data.
89 * This function allocates these processingData members:
90 * traceNumTable
91 * pendingRecv
92 * hookListList
93 * stats
94 * traceSetContext: set of LTTV traces
95 */
96 static void initProcessingLTTVStandard(SyncState* const syncState, LttvTracesetContext*
97 const traceSetContext)
98 {
99 unsigned int i;
100 ProcessingDataLTTVStandard* processingData;
101
102 processingData= malloc(sizeof(ProcessingDataLTTVStandard));
103 syncState->processingData= processingData;
104 processingData->traceSetContext= traceSetContext;
105
106 if (syncState->stats)
107 {
108 processingData->stats= calloc(1, sizeof(ProcessingStatsLTTVStandard));
109 }
110 else
111 {
112 processingData->stats= NULL;
113 }
114
115 processingData->traceNumTable= g_hash_table_new(&g_direct_hash, NULL);
116 processingData->hookListList= g_array_sized_new(FALSE, FALSE,
117 sizeof(GArray*), syncState->traceNb);
118 processingData->pendingRecv= malloc(sizeof(GHashTable*) *
119 syncState->traceNb);
120
121 for(i= 0; i < syncState->traceNb; i++)
122 {
123 g_hash_table_insert(processingData->traceNumTable,
124 processingData->traceSetContext->traces[i]->t, (gpointer) i);
125 }
126
127 for(i= 0; i < syncState->traceNb; i++)
128 {
129 processingData->pendingRecv[i]= g_hash_table_new_full(&g_direct_hash,
130 NULL, NULL, &gdnDestroyEvent);
131 }
132
133 registerHooks(processingData->hookListList, traceSetContext,
134 &processEventLTTVStandard, syncState);
135 }
136
137
138 /*
139 * Call the partial processing destroyer, obtain and adjust the factors from
140 * downstream
141 *
142 * Args:
143 * syncState container for synchronization data.
144 */
145 static void finalizeProcessingLTTVStandard(SyncState* const syncState)
146 {
147 unsigned int i;
148 GArray* factors;
149 double minOffset, minDrift;
150 unsigned int refFreqTrace;
151 ProcessingDataLTTVStandard* processingData;
152
153 processingData= (ProcessingDataLTTVStandard*) syncState->processingData;
154
155 partialDestroyProcessingLTTVStandard(syncState);
156
157 factors= syncState->matchingModule->finalizeMatching(syncState);
158
159 /* The offsets are adjusted so the lowest one is 0. This is done because
160 * of a Lttv specific limitation: events cannot have negative times. By
161 * having non-negative offsets, events cannot be moved backwards to
162 * negative times.
163 */
164 minOffset= 0;
165 for (i= 0; i < syncState->traceNb; i++)
166 {
167 minOffset= MIN(g_array_index(factors, Factors, i).offset, minOffset);
168 }
169
170 for (i= 0; i < syncState->traceNb; i++)
171 {
172 g_array_index(factors, Factors, i).offset-= minOffset;
173 }
174
175 /* Because the timestamps are corrected at the TSC level (not at the
176 * LttTime level) all trace frequencies must be made equal. We choose to
177 * use the frequency of the system with the lowest drift
178 */
179 minDrift= INFINITY;
180 refFreqTrace= 0;
181 for (i= 0; i < syncState->traceNb; i++)
182 {
183 if (g_array_index(factors, Factors, i).drift < minDrift)
184 {
185 minDrift= g_array_index(factors, Factors, i).drift;
186 refFreqTrace= i;
187 }
188 }
189 g_assert(syncState->traceNb == 0 || minDrift != INFINITY);
190
191 // Write the factors to the LttTrace structures
192 for (i= 0; i < syncState->traceNb; i++)
193 {
194 LttTrace* t;
195 Factors* traceFactors;
196
197 t= processingData->traceSetContext->traces[i]->t;
198 traceFactors= &g_array_index(factors, Factors, i);
199
200 t->drift= traceFactors->drift;
201 t->offset= traceFactors->offset;
202 t->start_freq=
203 processingData->traceSetContext->traces[refFreqTrace]->t->start_freq;
204 t->freq_scale=
205 processingData->traceSetContext->traces[refFreqTrace]->t->freq_scale;
206 t->start_time_from_tsc =
207 ltt_time_from_uint64(tsc_to_uint64(t->freq_scale, t->start_freq,
208 t->drift * t->start_tsc + t->offset));
209 }
210
211 g_array_free(factors, TRUE);
212
213 lttv_traceset_context_compute_time_span(processingData->traceSetContext,
214 &processingData->traceSetContext->time_span);
215
216 g_debug("traceset start %ld.%09ld end %ld.%09ld\n",
217 processingData->traceSetContext->time_span.start_time.tv_sec,
218 processingData->traceSetContext->time_span.start_time.tv_nsec,
219 processingData->traceSetContext->time_span.end_time.tv_sec,
220 processingData->traceSetContext->time_span.end_time.tv_nsec);
221 }
222
223
224 /*
225 * Print statistics related to processing and downstream modules. Must be
226 * called after finalizeProcessing.
227 *
228 * Args:
229 * syncState container for synchronization data.
230 */
231 static void printProcessingStatsLTTVStandard(SyncState* const syncState)
232 {
233 unsigned int i;
234 ProcessingDataLTTVStandard* processingData;
235
236 if (!syncState->stats)
237 {
238 return;
239 }
240
241 processingData= (ProcessingDataLTTVStandard*) syncState->processingData;
242
243 printf("LTTV processing stats:\n");
244 printf("\treceived frames: %d\n", processingData->stats->totRecv);
245 printf("\treceived frames that are IP: %d\n",
246 processingData->stats->totRecvIp);
247 printf("\treceived and processed packets that are TCP: %d\n",
248 processingData->stats->totInE);
249 printf("\tsent packets that are TCP: %d\n",
250 processingData->stats->totOutE);
251
252 if (syncState->matchingModule->printMatchingStats != NULL)
253 {
254 syncState->matchingModule->printMatchingStats(syncState);
255 }
256
257 printf("Resulting synchronization factors:\n");
258 for (i= 0; i < syncState->traceNb; i++)
259 {
260 LttTrace* t;
261
262 t= processingData->traceSetContext->traces[i]->t;
263
264 printf("\ttrace %u drift= %g offset= %g (%f) start time= %ld.%09ld\n",
265 i, t->drift, t->offset, (double) tsc_to_uint64(t->freq_scale,
266 t->start_freq, t->offset) / NANOSECONDS_PER_SECOND,
267 t->start_time_from_tsc.tv_sec, t->start_time_from_tsc.tv_nsec);
268 }
269 }
270
271
272 /*
273 * Unregister event hooks. Deallocate processingData.
274 *
275 * Args:
276 * syncState: container for synchronization data.
277 * This function deallocates these processingData members:
278 * stats
279 */
280 static void destroyProcessingLTTVStandard(SyncState* const syncState)
281 {
282 ProcessingDataLTTVStandard* processingData;
283
284 processingData= (ProcessingDataLTTVStandard*) syncState->processingData;
285
286 if (processingData == NULL)
287 {
288 return;
289 }
290
291 partialDestroyProcessingLTTVStandard(syncState);
292
293 if (syncState->stats)
294 {
295 free(processingData->stats);
296 }
297
298 free(syncState->processingData);
299 syncState->processingData= NULL;
300 }
301
302
303 /*
304 * Unregister event hooks. Deallocate some of processingData.
305 *
306 * This function can be called right after the events have been processed to
307 * free some data structures that are not needed for finalization.
308 *
309 * Args:
310 * syncState: container for synchronization data.
311 * This function deallocates these members:
312 * traceNumTable
313 * hookListList
314 * pendingRecv
315 */
316 static void partialDestroyProcessingLTTVStandard(SyncState* const syncState)
317 {
318 unsigned int i;
319 ProcessingDataLTTVStandard* processingData;
320
321 processingData= (ProcessingDataLTTVStandard*) syncState->processingData;
322
323 if (processingData == NULL || processingData->traceNumTable == NULL)
324 {
325 return;
326 }
327
328 g_hash_table_destroy(processingData->traceNumTable);
329 processingData->traceNumTable= NULL;
330
331 for(i= 0; i < syncState->traceNb; i++)
332 {
333
334 g_debug("Cleaning up pendingRecv list\n");
335 g_hash_table_destroy(processingData->pendingRecv[i]);
336 }
337 free(processingData->pendingRecv);
338
339 unregisterHooks(processingData->hookListList,
340 processingData->traceSetContext);
341 }
342
343
344 /*
345 * Lttv hook function that will be called for network events
346 *
347 * Args:
348 * hookData: LttvTraceHook* for the type of event that generated the call
349 * callData: LttvTracefileContext* at the moment of the event
350 *
351 * Returns:
352 * FALSE Always returns FALSE, meaning to keep processing hooks for
353 * this event
354 */
355 static gboolean processEventLTTVStandard(void* hookData, void* callData)
356 {
357 LttvTraceHook* traceHook;
358 LttvTracefileContext* tfc;
359 LttEvent* event;
360 LttTime time;
361 LttCycleCount tsc;
362 LttTrace* trace;
363 unsigned long traceNum;
364 struct marker_info* info;
365 SyncState* syncState;
366 ProcessingDataLTTVStandard* processingData;
367
368 traceHook= (LttvTraceHook*) hookData;
369 tfc= (LttvTracefileContext*) callData;
370 syncState= (SyncState*) traceHook->hook_data;
371 processingData= (ProcessingDataLTTVStandard*) syncState->processingData;
372 event= ltt_tracefile_get_event(tfc->tf);
373 time= ltt_event_time(event);
374 tsc= ltt_event_cycle_count(event);
375 trace= tfc->t_context->t;
376 info= marker_get_info_from_id(tfc->tf->mdata, event->event_id);
377
378 g_assert(g_hash_table_lookup_extended(processingData->traceNumTable,
379 trace, NULL, (gpointer*) &traceNum));
380
381 g_debug("XXXX process event: time: %ld.%09ld trace: %ld (%p) name: %s ",
382 (long) time.tv_sec, time.tv_nsec, traceNum, trace,
383 g_quark_to_string(info->name));
384
385 if (info->name == LTT_EVENT_DEV_XMIT)
386 {
387 Event* outE;
388
389 if (!ltt_event_get_unsigned(event,
390 lttv_trace_get_hook_field(traceHook, 1)) == ETH_P_IP ||
391 !ltt_event_get_unsigned(event,
392 lttv_trace_get_hook_field(traceHook, 2)) == IPPROTO_TCP)
393 {
394 return FALSE;
395 }
396
397 if (syncState->stats)
398 {
399 processingData->stats->totOutE++;
400 }
401
402 outE= malloc(sizeof(Event));
403 outE->traceNum= traceNum;
404 outE->time= tsc;
405 outE->type= TCP;
406 outE->destroy= &destroyTCPEvent;
407 outE->event.tcpEvent= malloc(sizeof(TCPEvent));
408 outE->event.tcpEvent->direction= OUT;
409 outE->event.tcpEvent->segmentKey= malloc(sizeof(SegmentKey));
410 outE->event.tcpEvent->segmentKey->connectionKey.saddr=
411 ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook,
412 3));
413 outE->event.tcpEvent->segmentKey->connectionKey.daddr=
414 ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook,
415 4));
416 outE->event.tcpEvent->segmentKey->tot_len=
417 ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook,
418 5));
419 outE->event.tcpEvent->segmentKey->ihl= ltt_event_get_unsigned(event,
420 lttv_trace_get_hook_field(traceHook, 6));
421 outE->event.tcpEvent->segmentKey->connectionKey.source=
422 ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook,
423 7));
424 outE->event.tcpEvent->segmentKey->connectionKey.dest=
425 ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook,
426 8));
427 outE->event.tcpEvent->segmentKey->seq= ltt_event_get_unsigned(event,
428 lttv_trace_get_hook_field(traceHook, 9));
429 outE->event.tcpEvent->segmentKey->ack_seq=
430 ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook,
431 10));
432 outE->event.tcpEvent->segmentKey->doff= ltt_event_get_unsigned(event,
433 lttv_trace_get_hook_field(traceHook, 11));
434 outE->event.tcpEvent->segmentKey->ack= ltt_event_get_unsigned(event,
435 lttv_trace_get_hook_field(traceHook, 12));
436 outE->event.tcpEvent->segmentKey->rst= ltt_event_get_unsigned(event,
437 lttv_trace_get_hook_field(traceHook, 13));
438 outE->event.tcpEvent->segmentKey->syn= ltt_event_get_unsigned(event,
439 lttv_trace_get_hook_field(traceHook, 14));
440 outE->event.tcpEvent->segmentKey->fin= ltt_event_get_unsigned(event,
441 lttv_trace_get_hook_field(traceHook, 15));
442
443 syncState->matchingModule->matchEvent(syncState, outE);
444
445 g_debug("Output event done\n");
446 }
447 else if (info->name == LTT_EVENT_DEV_RECEIVE)
448 {
449 guint32 protocol;
450
451 if (syncState->stats)
452 {
453 processingData->stats->totRecv++;
454 }
455
456 protocol= ltt_event_get_unsigned(event,
457 lttv_trace_get_hook_field(traceHook, 1));
458
459 if (protocol == ETH_P_IP)
460 {
461 Event* inE;
462 void* skb;
463
464 if (syncState->stats)
465 {
466 processingData->stats->totRecvIp++;
467 }
468
469 inE= malloc(sizeof(Event));
470 inE->traceNum= traceNum;
471 inE->time= tsc;
472 inE->event.tcpEvent= NULL;
473 inE->destroy= &destroyEvent;
474
475 skb= (void*) (long) ltt_event_get_long_unsigned(event,
476 lttv_trace_get_hook_field(traceHook, 0));
477 g_hash_table_replace(processingData->pendingRecv[traceNum], skb,
478 inE);
479
480 g_debug("Adding inE %p for skb %p to pendingRecv\n", inE, skb);
481 }
482 else
483 {
484 g_debug("\n");
485 }
486 }
487 else if (info->name == LTT_EVENT_TCPV4_RCV)
488 {
489 Event* inE;
490 void* skb;
491
492 // Search pendingRecv for an event with the same skb
493 skb= (void*) (long) ltt_event_get_long_unsigned(event,
494 lttv_trace_get_hook_field(traceHook, 0));
495
496 inE= (Event*)
497 g_hash_table_lookup(processingData->pendingRecv[traceNum], skb);
498 if (inE == NULL)
499 {
500 // This should only happen in case of lost events
501 g_debug("No matching pending receive event found\n");
502 }
503 else
504 {
505 if (syncState->stats)
506 {
507 processingData->stats->totInE++;
508 }
509
510 // If it's there, remove it and proceed with a receive event
511 g_hash_table_steal(processingData->pendingRecv[traceNum], skb);
512
513 inE->type= TCP;
514 inE->event.tcpEvent= malloc(sizeof(TCPEvent));
515 inE->destroy= &destroyTCPEvent;
516 inE->event.tcpEvent->direction= IN;
517 inE->event.tcpEvent->segmentKey= malloc(sizeof(SegmentKey));
518 inE->event.tcpEvent->segmentKey->connectionKey.saddr=
519 ltt_event_get_unsigned(event,
520 lttv_trace_get_hook_field(traceHook, 1));
521 inE->event.tcpEvent->segmentKey->connectionKey.daddr=
522 ltt_event_get_unsigned(event,
523 lttv_trace_get_hook_field(traceHook, 2));
524 inE->event.tcpEvent->segmentKey->tot_len=
525 ltt_event_get_unsigned(event,
526 lttv_trace_get_hook_field(traceHook, 3));
527 inE->event.tcpEvent->segmentKey->ihl=
528 ltt_event_get_unsigned(event,
529 lttv_trace_get_hook_field(traceHook, 4));
530 inE->event.tcpEvent->segmentKey->connectionKey.source=
531 ltt_event_get_unsigned(event,
532 lttv_trace_get_hook_field(traceHook, 5));
533 inE->event.tcpEvent->segmentKey->connectionKey.dest=
534 ltt_event_get_unsigned(event,
535 lttv_trace_get_hook_field(traceHook, 6));
536 inE->event.tcpEvent->segmentKey->seq=
537 ltt_event_get_unsigned(event,
538 lttv_trace_get_hook_field(traceHook, 7));
539 inE->event.tcpEvent->segmentKey->ack_seq=
540 ltt_event_get_unsigned(event,
541 lttv_trace_get_hook_field(traceHook, 8));
542 inE->event.tcpEvent->segmentKey->doff=
543 ltt_event_get_unsigned(event,
544 lttv_trace_get_hook_field(traceHook, 9));
545 inE->event.tcpEvent->segmentKey->ack=
546 ltt_event_get_unsigned(event,
547 lttv_trace_get_hook_field(traceHook, 10));
548 inE->event.tcpEvent->segmentKey->rst=
549 ltt_event_get_unsigned(event,
550 lttv_trace_get_hook_field(traceHook, 11));
551 inE->event.tcpEvent->segmentKey->syn=
552 ltt_event_get_unsigned(event,
553 lttv_trace_get_hook_field(traceHook, 12));
554 inE->event.tcpEvent->segmentKey->fin=
555 ltt_event_get_unsigned(event,
556 lttv_trace_get_hook_field(traceHook, 13));
557
558 syncState->matchingModule->matchEvent(syncState, inE);
559
560 g_debug("Input event %p for skb %p done\n", inE, skb);
561 }
562 }
563 else if (info->name == LTT_EVENT_NETWORK_IPV4_INTERFACE)
564 {
565 char* name;
566 guint64 address;
567 gint64 up;
568 char addressString[17];
569
570 address= ltt_event_get_long_unsigned(event,
571 lttv_trace_get_hook_field(traceHook, 1));
572 up= ltt_event_get_long_int(event, lttv_trace_get_hook_field(traceHook,
573 2));
574 /* name must be the last field to get or else copy the string, see the
575 * doc for ltt_event_get_string()
576 */
577 name= ltt_event_get_string(event, lttv_trace_get_hook_field(traceHook,
578 0));
579
580 convertIP(addressString, address);
581
582 g_debug("name \"%s\" address %s up %lld\n", name, addressString, up);
583 }
584 else
585 {
586 g_assert_not_reached();
587 }
588
589 return FALSE;
590 }
591
592
593 /*
594 * Write the processing-specific graph lines in the gnuplot script (none at
595 * the moment). Call the downstream module's graph function.
596 *
597 * Args:
598 * stream: stream where to write the data
599 * syncState: container for synchronization data
600 * i: first trace number
601 * j: second trace number, garanteed to be larger than i
602 */
603 static void writeProcessingGraphsPlotsLTTVStandard(FILE* stream, SyncState*
604 const syncState, const unsigned int i, const unsigned int j)
605 {
606 if (syncState->matchingModule->writeMatchingGraphsPlots != NULL)
607 {
608 syncState->matchingModule->writeMatchingGraphsPlots(stream, syncState,
609 i, j);
610 }
611 }
612
613
614 /*
615 * Write the processing-specific options in the gnuplot script. Call the
616 * downstream module's options function.
617 *
618 * Args:
619 * stream: stream where to write the data
620 * syncState: container for synchronization data
621 * i: first trace number
622 * j: second trace number, garanteed to be larger than i
623 */
624 static void writeProcessingGraphsOptionsLTTVStandard(FILE* stream, SyncState*
625 const syncState, const unsigned int i, const unsigned int j)
626 {
627 ProcessingDataLTTVStandard* processingData;
628 LttTrace* traceI, * traceJ;
629
630 processingData= (ProcessingDataLTTVStandard*) syncState->processingData;
631
632 traceI= processingData->traceSetContext->traces[i]->t;
633 traceJ= processingData->traceSetContext->traces[j]->t;
634
635 fprintf(stream,
636 "set x2label \"Clock %1$d (s)\"\n"
637 "set x2range [GPVAL_X_MIN / %2$.1f : GPVAL_X_MAX / %2$.1f]\n"
638 "set x2tics\n"
639 "set y2label \"Clock %3$d (s)\"\n"
640 "set y2range [GPVAL_Y_MIN / %4$.1f : GPVAL_Y_MAX / %4$.1f]\n"
641 "set y2tics\n", i, (double) traceI->start_freq / traceI->freq_scale,
642 j, (double) traceJ->start_freq / traceJ->freq_scale);
643
644 if (syncState->matchingModule->writeMatchingGraphsOptions != NULL)
645 {
646 syncState->matchingModule->writeMatchingGraphsOptions(stream,
647 syncState, i, j);
648 }
649 }
This page took 0.042359 seconds and 3 git commands to generate.