X-Git-Url: http://git.liburcu.org/?a=blobdiff_plain;f=lttv%2Flttv%2Fsync%2Fevent_processing_lttng_standard.c;h=55806dfa8922826c814a4c6ed5c6eee2e265e606;hb=2f961b65e3422f23019286e9531b0a40070278ea;hp=de2d86a4fa8dd8fc4a498cc74ac70d816a2996bb;hpb=10341d26543c63ff318a4cf5cb163bccdc58b19d;p=lttv.git diff --git a/lttv/lttv/sync/event_processing_lttng_standard.c b/lttv/lttv/sync/event_processing_lttng_standard.c index de2d86a4..55806dfa 100644 --- a/lttv/lttv/sync/event_processing_lttng_standard.c +++ b/lttv/lttv/sync/event_processing_lttng_standard.c @@ -22,37 +22,38 @@ #include #endif -#include #include #include +#include #include #include +#include -#include "sync_chain_lttv.h" +#include "sync_chain.h" #include "event_processing_lttng_common.h" #include "event_processing_lttng_standard.h" - -#ifndef g_info -#define g_info(format...) g_log (G_LOG_DOMAIN, G_LOG_LEVEL_INFO, format) -#endif +/* IPv4 Ethertype, taken from , unlikely to change as it's + * defined by IANA: http://www.iana.org/assignments/ethernet-numbers + */ +#define ETH_P_IP 0x0800 // Functions common to all processing modules -static void initProcessingLTTVStandard(SyncState* const syncState, - LttvTracesetContext* const traceSetContext); +static void initProcessingLTTVStandard(SyncState* const syncState, ...); static void destroyProcessingLTTVStandard(SyncState* const syncState); static void finalizeProcessingLTTVStandard(SyncState* const syncState); static void printProcessingStatsLTTVStandard(SyncState* const syncState); -static void writeProcessingGraphsPlotsLTTVStandard(FILE* stream, SyncState* - const syncState, const unsigned int i, const unsigned int j); -static void writeProcessingGraphsOptionsLTTVStandard(FILE* stream, SyncState* - const syncState, const unsigned int i, const unsigned int j); +static void writeProcessingGraphVariablesLTTVStandard(SyncState* const + syncState, const unsigned int i); +static void writeProcessingTraceTraceOptionsLTTVStandard(SyncState* const + syncState, const unsigned int i, const unsigned int j); +static void writeProcessingTraceTimeOptionsLTTVStandard(SyncState* const + syncState, const unsigned int i, const unsigned int j); // Functions specific to this module -static void registerProcessingLTTVStandard() __attribute__((constructor (102))); static gboolean processEventLTTVStandard(void* hookData, void* callData); static void partialDestroyProcessingLTTVStandard(SyncState* const syncState); @@ -63,16 +64,18 @@ static ProcessingModule processingModuleLTTVStandard = { .destroyProcessing= &destroyProcessingLTTVStandard, .finalizeProcessing= &finalizeProcessingLTTVStandard, .printProcessingStats= &printProcessingStatsLTTVStandard, - .writeProcessingGraphsPlots= &writeProcessingGraphsPlotsLTTVStandard, - .writeProcessingGraphsOptions= &writeProcessingGraphsOptionsLTTVStandard, + .graphFunctions= { + .writeVariables= &writeProcessingGraphVariablesLTTVStandard, + .writeTraceTraceOptions= &writeProcessingTraceTraceOptionsLTTVStandard, + .writeTraceTimeOptions= &writeProcessingTraceTimeOptionsLTTVStandard, + }, }; - /* * Processing Module registering function */ -static void registerProcessingLTTVStandard() +void registerProcessingLTTVStandard() { g_queue_push_tail(&processingModules, &processingModuleLTTVStandard); @@ -91,17 +94,39 @@ static void registerProcessingLTTVStandard() * pendingRecv * hookListList * stats - * traceSetContext: set of LTTV traces + * traceSetContext: LttvTracesetContext*, set of LTTV traces */ -static void initProcessingLTTVStandard(SyncState* const syncState, LttvTracesetContext* - const traceSetContext) +static void initProcessingLTTVStandard(SyncState* const syncState, ...) { unsigned int i; ProcessingDataLTTVStandard* processingData; + va_list ap; processingData= malloc(sizeof(ProcessingDataLTTVStandard)); syncState->processingData= processingData; - processingData->traceSetContext= traceSetContext; + va_start(ap, syncState); + processingData->traceSetContext= va_arg(ap, LttvTracesetContext*); + va_end(ap); + syncState->traceNb= + lttv_traceset_number(processingData->traceSetContext->ts); + processingData->hookListList= g_array_sized_new(FALSE, FALSE, + sizeof(GArray*), syncState->traceNb); + + processingData->traceNumTable= g_hash_table_new(&g_direct_hash, NULL); + for(i= 0; i < syncState->traceNb; i++) + { + g_hash_table_insert(processingData->traceNumTable, + processingData->traceSetContext->traces[i]->t, + GUINT_TO_POINTER(i)); + } + + processingData->pendingRecv= malloc(sizeof(GHashTable*) * + syncState->traceNb); + for(i= 0; i < syncState->traceNb; i++) + { + processingData->pendingRecv[i]= g_hash_table_new_full(&g_direct_hash, + NULL, NULL, &gdnDestroyEvent); + } if (syncState->stats) { @@ -112,26 +137,27 @@ static void initProcessingLTTVStandard(SyncState* const syncState, LttvTracesetC processingData->stats= NULL; } - processingData->traceNumTable= g_hash_table_new(&g_direct_hash, NULL); - processingData->hookListList= g_array_sized_new(FALSE, FALSE, - sizeof(GArray*), syncState->traceNb); - processingData->pendingRecv= malloc(sizeof(GHashTable*) * - syncState->traceNb); - - for(i= 0; i < syncState->traceNb; i++) + if (syncState->graphsStream) { - g_hash_table_insert(processingData->traceNumTable, - processingData->traceSetContext->traces[i]->t, (gpointer) i); - } + processingData->graphs= malloc(syncState->traceNb * + sizeof(ProcessingGraphsLTTVStandard)); - for(i= 0; i < syncState->traceNb; i++) + for(i= 0; i < syncState->traceNb; i++) + { + LttTrace* traceI= processingData->traceSetContext->traces[i]->t; + + processingData->graphs[i].startFreq= traceI->start_freq; + processingData->graphs[i].freqScale= traceI->freq_scale; + } + } + else { - processingData->pendingRecv[i]= g_hash_table_new_full(&g_direct_hash, - NULL, NULL, &gdnDestroyEvent); + processingData->graphs= NULL; } - registerHooks(processingData->hookListList, traceSetContext, - &processEventLTTVStandard, syncState); + registerHooks(processingData->hookListList, + processingData->traceSetContext, &processEventLTTVStandard, syncState, + syncState->matchingModule->canMatch); } @@ -213,7 +239,7 @@ static void finalizeProcessingLTTVStandard(SyncState* const syncState) lttv_traceset_context_compute_time_span(processingData->traceSetContext, &processingData->traceSetContext->time_span); - g_debug("traceset start %ld.%09ld end %ld.%09ld\n", + g_debug("traceset start %ld.%09ld end %ld.%09ld", processingData->traceSetContext->time_span.start_time.tv_sec, processingData->traceSetContext->time_span.start_time.tv_nsec, processingData->traceSetContext->time_span.end_time.tv_sec, @@ -222,15 +248,14 @@ static void finalizeProcessingLTTVStandard(SyncState* const syncState) /* - * Print statistics related to processing and downstream modules. Must be - * called after finalizeProcessing. + * Print statistics related to processing Must be called after + * finalizeProcessing. * * Args: * syncState container for synchronization data. */ static void printProcessingStatsLTTVStandard(SyncState* const syncState) { - unsigned int i; ProcessingDataLTTVStandard* processingData; if (!syncState->stats) @@ -244,27 +269,20 @@ static void printProcessingStatsLTTVStandard(SyncState* const syncState) printf("\treceived frames: %d\n", processingData->stats->totRecv); printf("\treceived frames that are IP: %d\n", processingData->stats->totRecvIp); - printf("\treceived and processed packets that are TCP: %d\n", - processingData->stats->totInE); - printf("\tsent packets that are TCP: %d\n", - processingData->stats->totOutE); - - if (syncState->matchingModule->printMatchingStats != NULL) + if (syncState->matchingModule->canMatch[TCP]) { - syncState->matchingModule->printMatchingStats(syncState); + printf("\treceived and processed packets that are TCP: %d\n", + processingData->stats->totRecvTCP); } - - printf("Resulting synchronization factors:\n"); - for (i= 0; i < syncState->traceNb; i++) + if (syncState->matchingModule->canMatch[UDP]) { - LttTrace* t; - - t= processingData->traceSetContext->traces[i]->t; - - printf("\ttrace %u drift= %g offset= %g (%f) start time= %ld.%09ld\n", - i, t->drift, t->offset, (double) tsc_to_uint64(t->freq_scale, - t->start_freq, t->offset) / NANOSECONDS_PER_SECOND, - t->start_time_from_tsc.tv_sec, t->start_time_from_tsc.tv_nsec); + printf("\treceived and processed packets that are UDP: %d\n", + processingData->stats->totRecvUDP); + } + if (syncState->matchingModule->canMatch[TCP]) + { + printf("\tsent packets that are TCP: %d\n", + processingData->stats->totOutE); } } @@ -295,6 +313,11 @@ static void destroyProcessingLTTVStandard(SyncState* const syncState) free(processingData->stats); } + if (syncState->graphsStream) + { + free(processingData->graphs); + } + free(syncState->processingData); syncState->processingData= NULL; } @@ -331,7 +354,7 @@ static void partialDestroyProcessingLTTVStandard(SyncState* const syncState) for(i= 0; i < syncState->traceNb; i++) { - g_debug("Cleaning up pendingRecv list\n"); + g_debug("Cleaning up pendingRecv list"); g_hash_table_destroy(processingData->pendingRecv[i]); } free(processingData->pendingRecv); @@ -357,32 +380,37 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) LttvTraceHook* traceHook; LttvTracefileContext* tfc; LttEvent* event; - LttTime time; LttCycleCount tsc; + LttTime time; + WallTime wTime; LttTrace* trace; unsigned long traceNum; struct marker_info* info; SyncState* syncState; ProcessingDataLTTVStandard* processingData; + gpointer traceNumP; traceHook= (LttvTraceHook*) hookData; tfc= (LttvTracefileContext*) callData; + trace= tfc->t_context->t; syncState= (SyncState*) traceHook->hook_data; processingData= (ProcessingDataLTTVStandard*) syncState->processingData; event= ltt_tracefile_get_event(tfc->tf); - time= ltt_event_time(event); - tsc= ltt_event_cycle_count(event); - trace= tfc->t_context->t; info= marker_get_info_from_id(tfc->tf->mdata, event->event_id); + tsc= ltt_event_cycle_count(event); + time= ltt_event_time(event); + wTime.seconds= time.tv_sec; + wTime.nanosec= time.tv_nsec; g_assert(g_hash_table_lookup_extended(processingData->traceNumTable, - trace, NULL, (gpointer*) &traceNum)); + trace, NULL, &traceNumP)); + traceNum= GPOINTER_TO_INT(traceNumP); - g_debug("XXXX process event: time: %ld.%09ld trace: %ld (%p) name: %s ", - (long) time.tv_sec, time.tv_nsec, traceNum, trace, + g_debug("Process event: time: %ld.%09ld trace: %ld (%p) name: %s ", + time.tv_sec, time.tv_nsec, traceNum, trace, g_quark_to_string(info->name)); - if (info->name == LTT_EVENT_DEV_XMIT) + if (info->name == LTT_EVENT_DEV_XMIT_EXTENDED) { Event* outE; @@ -394,6 +422,11 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) return FALSE; } + if (!syncState->matchingModule->canMatch[TCP]) + { + return FALSE; + } + if (syncState->stats) { processingData->stats->totOutE++; @@ -401,18 +434,20 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) outE= malloc(sizeof(Event)); outE->traceNum= traceNum; - outE->time= tsc; + outE->cpuTime= tsc; + outE->wallTime= wTime; outE->type= TCP; + outE->copy= ©TCPEvent; outE->destroy= &destroyTCPEvent; outE->event.tcpEvent= malloc(sizeof(TCPEvent)); outE->event.tcpEvent->direction= OUT; outE->event.tcpEvent->segmentKey= malloc(sizeof(SegmentKey)); outE->event.tcpEvent->segmentKey->connectionKey.saddr= - ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook, - 3)); + htonl(ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 3))); outE->event.tcpEvent->segmentKey->connectionKey.daddr= - ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook, - 4)); + htonl(ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 4))); outE->event.tcpEvent->segmentKey->tot_len= ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook, 5)); @@ -442,7 +477,7 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) syncState->matchingModule->matchEvent(syncState, outE); - g_debug("Output event done\n"); + g_debug("Output event done"); } else if (info->name == LTT_EVENT_DEV_RECEIVE) { @@ -468,8 +503,10 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) inE= malloc(sizeof(Event)); inE->traceNum= traceNum; - inE->time= tsc; + inE->cpuTime= tsc; + inE->wallTime= wTime; inE->event.tcpEvent= NULL; + inE->copy= ©Event; inE->destroy= &destroyEvent; skb= (void*) (long) ltt_event_get_long_unsigned(event, @@ -477,14 +514,10 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) g_hash_table_replace(processingData->pendingRecv[traceNum], skb, inE); - g_debug("Adding inE %p for skb %p to pendingRecv\n", inE, skb); - } - else - { - g_debug("\n"); + g_debug("Adding inE %p for skb %p to pendingRecv", inE, skb); } } - else if (info->name == LTT_EVENT_TCPV4_RCV) + else if (info->name == LTT_EVENT_TCPV4_RCV_EXTENDED) { Event* inE; void* skb; @@ -498,13 +531,13 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) if (inE == NULL) { // This should only happen in case of lost events - g_debug("No matching pending receive event found\n"); + g_warning("No matching pending receive event found"); } else { if (syncState->stats) { - processingData->stats->totInE++; + processingData->stats->totRecvTCP++; } // If it's there, remove it and proceed with a receive event @@ -512,15 +545,16 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) inE->type= TCP; inE->event.tcpEvent= malloc(sizeof(TCPEvent)); + inE->copy= ©TCPEvent; inE->destroy= &destroyTCPEvent; inE->event.tcpEvent->direction= IN; inE->event.tcpEvent->segmentKey= malloc(sizeof(SegmentKey)); inE->event.tcpEvent->segmentKey->connectionKey.saddr= - ltt_event_get_unsigned(event, - lttv_trace_get_hook_field(traceHook, 1)); + htonl(ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 1))); inE->event.tcpEvent->segmentKey->connectionKey.daddr= - ltt_event_get_unsigned(event, - lttv_trace_get_hook_field(traceHook, 2)); + htonl(ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 2))); inE->event.tcpEvent->segmentKey->tot_len= ltt_event_get_unsigned(event, lttv_trace_get_hook_field(traceHook, 3)); @@ -557,29 +591,82 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) syncState->matchingModule->matchEvent(syncState, inE); - g_debug("Input event %p for skb %p done\n", inE, skb); + g_debug("TCP input event %p for skb %p done", inE, skb); } } - else if (info->name == LTT_EVENT_NETWORK_IPV4_INTERFACE) + else if (info->name == LTT_EVENT_UDPV4_RCV_EXTENDED) { - char* name; - guint64 address; - gint64 up; - char addressString[17]; + Event* inE; + void* skb; - address= ltt_event_get_long_unsigned(event, - lttv_trace_get_hook_field(traceHook, 1)); - up= ltt_event_get_long_int(event, lttv_trace_get_hook_field(traceHook, - 2)); - /* name must be the last field to get or else copy the string, see the - * doc for ltt_event_get_string() - */ - name= ltt_event_get_string(event, lttv_trace_get_hook_field(traceHook, - 0)); + // Search pendingRecv for an event with the same skb + skb= (void*) (long) ltt_event_get_long_unsigned(event, + lttv_trace_get_hook_field(traceHook, 0)); + + inE= (Event*) + g_hash_table_lookup(processingData->pendingRecv[traceNum], skb); + if (inE == NULL) + { + // This should only happen in case of lost events + g_warning("No matching pending receive event found"); + } + else + { + guint64 dataStart; + + if (syncState->stats) + { + processingData->stats->totRecvUDP++; + } - convertIP(addressString, address); + // If it's there, remove it and proceed with a receive event + g_hash_table_steal(processingData->pendingRecv[traceNum], skb); - g_debug("name \"%s\" address %s up %lld\n", name, addressString, up); + inE->type= UDP; + inE->event.udpEvent= malloc(sizeof(UDPEvent)); + inE->copy= ©UDPEvent; + inE->destroy= &destroyUDPEvent; + inE->event.udpEvent->direction= IN; + inE->event.udpEvent->datagramKey= malloc(sizeof(DatagramKey)); + inE->event.udpEvent->datagramKey->saddr= + htonl(ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 1))); + inE->event.udpEvent->datagramKey->daddr= + htonl(ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 2))); + inE->event.udpEvent->unicast= ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 3)) == 0 ? false : true; + inE->event.udpEvent->datagramKey->ulen= + ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 4)); + inE->event.udpEvent->datagramKey->source= + ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 5)); + inE->event.udpEvent->datagramKey->dest= + ltt_event_get_unsigned(event, + lttv_trace_get_hook_field(traceHook, 6)); + dataStart= ltt_event_get_long_unsigned(event, + lttv_trace_get_hook_field(traceHook, 7)); + g_assert_cmpuint(sizeof(inE->event.udpEvent->datagramKey->dataKey), + ==, sizeof(guint64)); + if (inE->event.udpEvent->datagramKey->ulen - 8 >= + sizeof(inE->event.udpEvent->datagramKey->dataKey)) + { + memcpy(inE->event.udpEvent->datagramKey->dataKey, &dataStart, + sizeof(inE->event.udpEvent->datagramKey->dataKey)); + } + else + { + memset(inE->event.udpEvent->datagramKey->dataKey, 0, + sizeof(inE->event.udpEvent->datagramKey->dataKey)); + memcpy(inE->event.udpEvent->datagramKey->dataKey, &dataStart, + inE->event.udpEvent->datagramKey->ulen - 8); + } + + syncState->matchingModule->matchEvent(syncState, inE); + + g_debug("UDP input event %p for skb %p done", inE, skb); + } } else { @@ -591,59 +678,67 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) /* - * Write the processing-specific graph lines in the gnuplot script (none at - * the moment). Call the downstream module's graph function. + * Write the processing-specific variables in the gnuplot script. * * Args: - * stream: stream where to write the data * syncState: container for synchronization data - * i: first trace number - * j: second trace number, garanteed to be larger than i + * i: trace number */ -static void writeProcessingGraphsPlotsLTTVStandard(FILE* stream, SyncState* - const syncState, const unsigned int i, const unsigned int j) +static void writeProcessingGraphVariablesLTTVStandard(SyncState* const + syncState, const unsigned int i) { - if (syncState->matchingModule->writeMatchingGraphsPlots != NULL) - { - syncState->matchingModule->writeMatchingGraphsPlots(stream, syncState, - i, j); - } + ProcessingDataLTTVStandard* processingData= syncState->processingData; + ProcessingGraphsLTTVStandard* traceI= &processingData->graphs[i]; + + fprintf(syncState->graphsStream, "clock_freq_%u= %.3f\n", i, (double) + traceI->startFreq / traceI->freqScale); } /* - * Write the processing-specific options in the gnuplot script. Call the - * downstream module's options function. + * Write the processing-specific options in the gnuplot script. * * Args: - * stream: stream where to write the data * syncState: container for synchronization data * i: first trace number * j: second trace number, garanteed to be larger than i */ -static void writeProcessingGraphsOptionsLTTVStandard(FILE* stream, SyncState* - const syncState, const unsigned int i, const unsigned int j) +static void writeProcessingTraceTraceOptionsLTTVStandard(SyncState* const + syncState, const unsigned int i, const unsigned int j) { - ProcessingDataLTTVStandard* processingData; - LttTrace* traceI, * traceJ; - - processingData= (ProcessingDataLTTVStandard*) syncState->processingData; - - traceI= processingData->traceSetContext->traces[i]->t; - traceJ= processingData->traceSetContext->traces[j]->t; - - fprintf(stream, + fprintf(syncState->graphsStream, + "set key inside right bottom\n" + "set xlabel \"Clock %1$u\"\n" + "set xtics nomirror\n" + "set ylabel \"Clock %2$u\"\n" + "set ytics nomirror\n" "set x2label \"Clock %1$d (s)\"\n" - "set x2range [GPVAL_X_MIN / %2$.1f : GPVAL_X_MAX / %2$.1f]\n" + "set x2range [GPVAL_X_MIN / clock_freq_%1$u : GPVAL_X_MAX / clock_freq_%1$u]\n" "set x2tics\n" - "set y2label \"Clock %3$d (s)\"\n" - "set y2range [GPVAL_Y_MIN / %4$.1f : GPVAL_Y_MAX / %4$.1f]\n" - "set y2tics\n", i, (double) traceI->start_freq / traceI->freq_scale, - j, (double) traceJ->start_freq / traceJ->freq_scale); + "set y2label \"Clock %2$d (s)\"\n" + "set y2range [GPVAL_Y_MIN / clock_freq_%2$u : GPVAL_Y_MAX / clock_freq_%2$u]\n" + "set y2tics\n", i, j); +} - if (syncState->matchingModule->writeMatchingGraphsOptions != NULL) - { - syncState->matchingModule->writeMatchingGraphsOptions(stream, - syncState, i, j); - } + +/* + * Write the processing-specific options in the gnuplot script. + * + * Args: + * syncState: container for synchronization data + * i: first trace number + * j: second trace number, garanteed to be larger than i + */ +static void writeProcessingTraceTimeOptionsLTTVStandard(SyncState* const + syncState, const unsigned int i, const unsigned int j) +{ + fprintf(syncState->graphsStream, + "set key inside right bottom\n" + "set xlabel \"Clock %1$u\"\n" + "set xtics nomirror\n" + "set ylabel \"time (s)\"\n" + "set ytics nomirror\n" + "set x2label \"Clock %1$d (s)\"\n" + "set x2range [GPVAL_X_MIN / clock_freq_%1$u : GPVAL_X_MAX / clock_freq_%1$u]\n" + "set x2tics\n", i); }