X-Git-Url: https://git.lttng.org/?a=blobdiff_plain;f=lttv%2Flttv%2Fsync%2Fevent_processing_lttng_standard.c;h=76a754b82e2a9650109d86944a2220b67dde2cdf;hb=48b641c1f6320eca569b2894f253d9d815250d45;hp=218e7abf33751c99d772314ed73eb0d0998c1273;hpb=fea7219b7d953f8c2677f497f010495cfa095b00;p=lttv.git diff --git a/lttv/lttv/sync/event_processing_lttng_standard.c b/lttv/lttv/sync/event_processing_lttng_standard.c index 218e7abf..76a754b8 100644 --- a/lttv/lttv/sync/event_processing_lttng_standard.c +++ b/lttv/lttv/sync/event_processing_lttng_standard.c @@ -25,31 +25,29 @@ #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 - - // 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))); @@ -63,12 +61,14 @@ static ProcessingModule processingModuleLTTVStandard = { .destroyProcessing= &destroyProcessingLTTVStandard, .finalizeProcessing= &finalizeProcessingLTTVStandard, .printProcessingStats= &printProcessingStatsLTTVStandard, - .writeProcessingGraphsPlots= &writeProcessingGraphsPlotsLTTVStandard, - .writeProcessingGraphsOptions= &writeProcessingGraphsOptionsLTTVStandard, + .graphFunctions= { + .writeVariables= &writeProcessingGraphVariablesLTTVStandard, + .writeTraceTraceOptions= &writeProcessingTraceTraceOptionsLTTVStandard, + .writeTraceTimeOptions= &writeProcessingTraceTimeOptionsLTTVStandard, + }, }; - /* * Processing Module registering function */ @@ -91,47 +91,69 @@ 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; - - if (syncState->stats) - { - processingData->stats= calloc(1, sizeof(ProcessingStatsLTTVStandard)); - } - else - { - processingData->stats= NULL; - } - - processingData->traceNumTable= g_hash_table_new(&g_direct_hash, NULL); + 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->pendingRecv= malloc(sizeof(GHashTable*) * - 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, (gpointer) 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); } - registerHooks(processingData->hookListList, traceSetContext, - &processEventLTTVStandard, syncState); + if (syncState->stats) + { + processingData->stats= calloc(1, sizeof(ProcessingStatsLTTVStandard)); + } + else + { + processingData->stats= NULL; + } + + if (syncState->graphsStream) + { + processingData->graphs= malloc(syncState->traceNb * + sizeof(ProcessingGraphsLTTVStandard)); + + 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->graphs= NULL; + } + + registerHooks(processingData->hookListList, + processingData->traceSetContext, &processEventLTTVStandard, syncState, + syncState->matchingModule->canMatch); } @@ -213,7 +235,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 +244,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 +265,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 +309,11 @@ static void destroyProcessingLTTVStandard(SyncState* const syncState) free(processingData->stats); } + if (syncState->graphsStream) + { + free(processingData->graphs); + } + free(syncState->processingData); syncState->processingData= NULL; } @@ -331,7 +350,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,8 +376,9 @@ 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; @@ -367,19 +387,21 @@ static gboolean processEventLTTVStandard(void* hookData, void* callData) 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)); - 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_EXTENDED) @@ -394,6 +416,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 +428,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 +471,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 +497,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,11 +508,7 @@ 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_EXTENDED) @@ -498,13 +525,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 +539,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 +585,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++; + } + + // If it's there, remove it and proceed with a receive event + g_hash_table_steal(processingData->pendingRecv[traceNum], skb); + + 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); + } - convertIP(addressString, address); + syncState->matchingModule->matchEvent(syncState, inE); - g_debug("name \"%s\" address %s up %lld\n", name, addressString, up); + g_debug("UDP input event %p for skb %p done", inE, skb); + } } else { @@ -591,59 +672,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); }