X-Git-Url: http://git.lttng.org./?a=blobdiff_plain;f=ltt%2Fbranches%2Fpoly%2Flttv%2Flttv%2Fbatchtest.c;h=bc68f3730307d6480c976d6b6848dbee87128dee;hb=235c78f0716f71ac54fb6ffe7f9803e86d96bdaa;hp=c48f9d771226d045b421281deafe94235f3a1693;hpb=eed2ef37f908daf7b3f884b5d8f91dad03f10526;p=lttv.git diff --git a/ltt/branches/poly/lttv/lttv/batchtest.c b/ltt/branches/poly/lttv/lttv/batchtest.c index c48f9d77..bc68f373 100644 --- a/ltt/branches/poly/lttv/lttv/batchtest.c +++ b/ltt/branches/poly/lttv/lttv/batchtest.c @@ -35,8 +35,6 @@ #include #include #include -#include -#include #define __UNUSED__ __attribute__((__unused__)) @@ -76,6 +74,9 @@ static gboolean a_test5, a_test6, a_test7, + a_test8, + a_test9, + a_test10, a_test_all; static GQuark QUARK_BLOCK_START, @@ -99,8 +100,11 @@ static void lttv_trace_option(void __UNUSED__ *hook_data) LttTrace *trace; trace = ltt_trace_open(a_trace); - if(trace == NULL) g_critical("cannot open trace %s", a_trace); - lttv_traceset_add(traceset, lttv_trace_new(trace)); + if(trace == NULL) { + g_critical("cannot open trace %s", a_trace); + } else { + lttv_traceset_add(traceset, lttv_trace_new(trace)); + } } static double get_time() @@ -166,19 +170,46 @@ gboolean trace_event(void __UNUSED__ *hook_data, void *call_data) LttEvent *e = ltt_tracefile_get_event(tfs->parent.tf); ltt_event_position(e, a_event_position); ltt_event_position_get(a_event_position, &tf, &nb_block, &offset, &tsc); - fprintf(stderr,"Event %s %lu.%09lu [%u %u tsc %llu]\n", - g_quark_to_string(ltt_eventtype_name(ltt_event_eventtype(e))), + fprintf(stderr,"Event %s %lu.%09lu [%u 0x%x tsc %llu]\n", + g_quark_to_string(marker_get_info_from_id(ltt_tracefile_get_trace(tf), + ltt_event_id(e))->name), tfs->parent.timestamp.tv_sec, tfs->parent.timestamp.tv_nsec, nb_block, offset, tsc); return FALSE; } +static LttTime count_previous_time = { 0, 0 }; gboolean count_event(void *hook_data, void __UNUSED__ *call_data) { + LttvTracefileState *tfs = (LttvTracefileState *)call_data; + LttTracefile *tracefile = tfs->parent.tf; + guint nb_block, offset; + LttTracefile *tf_pos; + guint64 tsc; + LttEvent * event = ltt_tracefile_get_event(tracefile); + LttTime time; guint *pcount = (guint *)hook_data; (*pcount)++; + + time = ltt_event_time(event); + ltt_event_position(event, a_event_position); + ltt_event_position_get(a_event_position, &tf_pos, &nb_block, &offset, &tsc); + + if(ltt_time_compare(time, count_previous_time) < 0) { + g_warning("Time decreasing trace %s tracefile %s cpu %u position %u/0x%x", + g_quark_to_string(ltt_trace_name(ltt_tracefile_get_trace(tracefile))), + g_quark_to_string(ltt_tracefile_name(tracefile)), + tfs->cpu, nb_block, offset); + g_warning("last time %lu.%lu vs current %lu.%lu", + count_previous_time.tv_sec, count_previous_time.tv_nsec, + time.tv_sec, time.tv_nsec); + } + count_previous_time = time; + + + return FALSE; } @@ -197,8 +228,10 @@ gboolean save_state_copy_event(void *hook_data, void *call_data) FILE *fp; + LttTrace *trace = ((LttvTracefileContext *)tfs)->t_context->t; + if(ts->nb_event == 0 && - ltt_eventtype_name(ltt_event_eventtype(e)) + marker_get_info_from_id(trace, e->event_id)->name == QUARK_BLOCK_START) { if(a_save_sample != NULL) { filename = g_string_new(""); @@ -248,27 +281,43 @@ gboolean save_state_event(void *hook_data, void *call_data) } +static void sanitize_name(gchar *name) +{ + while(*name != '\0') { + if(*name == '/') *name = '_'; + name++; + } + +} + -static void compute_tracefile(LttTracefile *tracefile) +static void compute_tracefile(LttTracefile *tracefile, void *hook_data) { GString *filename; - guint i, j, nb_equal, nb_block, offset; + guint nb_equal, nb_block, offset; guint64 tsc; FILE *fp; LttTime time, previous_time; - LttEvent *event = ltt_event_new(); - LttFacility *facility; - LttEventType *event_type; + LttEvent *event = ltt_tracefile_get_event(tracefile); + //LttEventType *event_type; + struct marker_info *minfo; int err; + gchar mod_name[PATH_MAX]; /* start_count is always initialized in this function _if_ there is always * a block_start before a block_end. */ - long long unsigned cycle_count, start_count=0, delta_cycle; + //long long unsigned cycle_count, start_count=0, delta_cycle; filename = g_string_new(""); - g_string_printf(filename, "%s.%u.%u.trace", a_dump_tracefiles, i, j); + strcpy(mod_name, g_quark_to_string(ltt_tracefile_name(tracefile))); + + sanitize_name(mod_name); + + g_warning("test %s test", g_quark_to_string(ltt_tracefile_name(tracefile))); + g_string_printf(filename, "%s.%s.%u.trace", a_dump_tracefiles, + mod_name, ltt_tracefile_cpu(tracefile)); fp = fopen(filename->str, "w"); if(fp == NULL) g_error("Cannot open %s", filename->str); g_string_free(filename, TRUE); @@ -280,20 +329,28 @@ static void compute_tracefile(LttTracefile *tracefile) do { LttTracefile *tf_pos; - facility = ltt_event_facility(event); - event_type = ltt_event_eventtype(event); + //event_type = ltt_event_eventtype(event); + minfo = marker_get_info_from_id(ltt_tracefile_get_trace(tracefile), + ltt_event_id(event)); time = ltt_event_time(event); ltt_event_position(event, a_event_position); ltt_event_position_get(a_event_position, &tf_pos, &nb_block, &offset, &tsc); - fprintf(fp,"%s.%s: %llu %lu.%09lu position %u/%u\n", - ltt_facility_name(facility), ltt_eventtype_name(event_type), + //fprintf(fp,"%s.%s: %llu %lu.%09lu position %u/%u\n", + fprintf(fp, "%s: %llu %lu.%09lu position %u/%u, tracefile %s\n", + g_quark_to_string(minfo->name), tsc, (unsigned long)time.tv_sec, (unsigned long)time.tv_nsec, - nb_block, offset); + nb_block, offset, + g_quark_to_string(ltt_tracefile_name(tracefile))); if(ltt_time_compare(time, previous_time) < 0) { - g_warning("Time decreasing trace %d tracefile %d position %u/%u", - i, j, nb_block, offset); + g_warning("Time decreasing trace %s tracefile %s cpu %u position %u/0x%x", + g_quark_to_string(ltt_trace_name(ltt_tracefile_get_trace(tracefile))), + g_quark_to_string(ltt_tracefile_name(tracefile)), + ltt_tracefile_cpu(tracefile), nb_block, offset); + g_warning("last time %lu.%lu vs current %lu.%lu", + previous_time.tv_sec, previous_time.tv_nsec, + time.tv_sec, time.tv_nsec); } #if 0 //FIXME @@ -319,7 +376,8 @@ static void compute_tracefile(LttTracefile *tracefile) } else { #endif //0 - if(ltt_time_compare(time, previous_time) == 0) nb_equal++; + if(ltt_time_compare(time, previous_time) == 0) + nb_equal++; else if(nb_equal > 0) { g_warning("Consecutive %d events with time %lu.%09lu", nb_equal + 1, previous_time.tv_sec, previous_time.tv_nsec); @@ -331,7 +389,6 @@ static void compute_tracefile(LttTracefile *tracefile) close: fclose(fp); - ltt_event_destroy(event); } static gboolean process_traceset(void __UNUSED__ *hook_data, @@ -354,28 +411,25 @@ static gboolean process_traceset(void __UNUSED__ *hook_data, LttTrace *trace; - long long unsigned start_nsec, end_nsec, delta_nsec, added_nsec, added_nsec2; - - double cycle_per_nsec, nsec_per_cycle; - - long long interpolated_nsec, interpolated_nsec2, end_nsec_sec, end_nsec_nsec; - - LttTime start_time; - LttTime max_time = { G_MAXULONG, G_MAXULONG }; a_event_position = ltt_event_position_new(); - GData *tracefiles_groups; + GData **tracefiles_groups; + struct compute_tracefile_group_args args; + + args.func = compute_tracefile; + args.func_args = NULL; + if(a_dump_tracefiles != NULL) { for(i = 0 ; i < lttv_traceset_number(traceset) ; i++) { trace = lttv_trace(lttv_traceset_get(traceset, i)); tracefiles_groups = ltt_trace_get_tracefiles_groups(trace); - g_datalist_foreach(&tracefiles_groups, + g_datalist_foreach(tracefiles_groups, (GDataForeachFunc)compute_tracefile_group, - compute_tracefile); + &args); } } @@ -395,7 +449,7 @@ static gboolean process_traceset(void __UNUSED__ *hook_data, lttv_hooks_add(event_hook, count_event, &count, LTTV_PRIO_DEFAULT); t = run_one_test(ts, ltt_time_zero, max_time); lttv_hooks_remove_data(event_hook, count_event, &count); - g_warning( + g_message( "Processing trace while counting events (%u events in %g seconds)", count, t); } @@ -406,7 +460,7 @@ static gboolean process_traceset(void __UNUSED__ *hook_data, lttv_state_add_event_hooks(ts); t = run_one_test(ts, ltt_time_zero, max_time); lttv_state_remove_event_hooks(ts); - g_warning("Processing trace while updating state (%g seconds)", t); + g_message("Processing trace while updating state (%g seconds)", t); } /* Run through all events computing the state and writing it out @@ -446,14 +500,14 @@ static gboolean process_traceset(void __UNUSED__ *hook_data, lttv_stats_add_event_hooks(tscs); t = run_one_test(ts, ltt_time_zero, max_time); lttv_stats_remove_event_hooks(tscs); - g_warning("Processing trace while counting stats (%g seconds)", t); + g_message("Processing trace while counting stats (%g seconds)", t); if(lttv_profile_memory) { g_message("Memory summary after computing stats"); g_mem_profile(); } - lttv_stats_sum_traceset(tscs); + lttv_stats_sum_traceset(tscs, ltt_time_infinite); if(lttv_profile_memory) { g_message("Memory summary after summing stats"); @@ -482,7 +536,7 @@ static gboolean process_traceset(void __UNUSED__ *hook_data, t = run_one_test(ts, ltt_time_zero, max_time); lttv_state_remove_event_hooks(ts); lttv_stats_remove_event_hooks(tscs); - g_warning( + g_message( "Processing trace while counting state and stats (%g seconds)", t); if(lttv_profile_memory) { @@ -521,7 +575,7 @@ static gboolean process_traceset(void __UNUSED__ *hook_data, if(a_save_state_copy) lttv_hooks_remove_data(event_hook,save_state_copy_event, &save_state); - g_warning("Processing trace while updating/saving state (%g seconds)", t); + g_message("Processing trace while updating/saving state (%g seconds)", t); if(lttv_profile_memory) { g_message("Memory summary after computing/saving state"); @@ -541,7 +595,7 @@ static gboolean process_traceset(void __UNUSED__ *hook_data, t = run_one_test(ts, save_state.write_time[j], save_state.write_time[j]); lttv_state_remove_event_hooks(ts); - g_warning("Seeking to %lu.%lu (%g seconds)", + g_message("Seeking to %lu.%lu (%g seconds)", save_state.write_time[j].tv_sec, save_state.write_time[j].tv_nsec, t); @@ -561,6 +615,171 @@ static gboolean process_traceset(void __UNUSED__ *hook_data, } } + /* Seek at specified interval, using states computed in 6, making + * sure that there is no more than the number of events between + * state save interval to read before getting there. + */ + + if((a_test8 && a_test6) || a_test_all) { + g_message("Running test 8 : check save interval"); + LttTime time = tc->time_span.start_time; + LttTime interval; + interval.tv_sec = 0; + interval.tv_nsec = 175674987; + guint count; + + while(ltt_time_compare(time, tc->time_span.end_time) < 0) { + //g_message("Seeking at time %u.%u", time.tv_sec, time.tv_nsec); + lttv_process_traceset_seek_time(&ts->parent, ltt_time_zero); + lttv_state_traceset_seek_time_closest(ts, time); + /* We add no hook to the traceset, not necessary */ + count = lttv_process_traceset_middle(&ts->parent, + time, G_MAXUINT, NULL); + g_info("Number of events to jump over : %u", count); + + if(count > LTTV_STATE_SAVE_INTERVAL) + g_warning("Oops! Save interval is %u and it took %u events to seek to a time %lu.%lu supposed to be closer from the last saved state.", + LTTV_STATE_SAVE_INTERVAL, count, time.tv_sec, time.tv_nsec); + time = ltt_time_add(time, interval); + } + + } + + if(a_test9 || a_test_all) { + double t0, t1; + /* Run seek_forward and seek_backward test */ + guint count; + LttvTracesetContext *tsc = &ts->parent; + LttvTracesetContextPosition *saved_pos = + lttv_traceset_context_position_new(tsc); + g_message("Running test 9 : seek_forward and seek_backward"); + lttv_process_traceset_seek_time(tsc, ltt_time_zero); + + count = lttv_process_traceset_seek_n_forward(tsc, 500, NULL, NULL, NULL, NULL, NULL, NULL); + g_assert(count == 500); + lttv_traceset_context_position_save(tsc, saved_pos); + t0 = get_time(); + count = lttv_process_traceset_seek_n_forward(tsc, 150000, NULL, NULL, NULL, NULL, NULL, NULL); + t1 = get_time(); + g_message("Seek forward 150000 events in %g seconds", t1 - t0); + g_assert(count == 150000); + t0 = get_time(); + count = lttv_process_traceset_seek_n_backward(tsc, 150000, + seek_back_default_offset, lttv_process_traceset_seek_time, NULL, + NULL, NULL, NULL, NULL, NULL); + t1 = get_time(); + g_message("Seek backward 150000 events in %g seconds", t1 - t0); + g_assert(count == 150000); + if(lttv_traceset_context_ctx_pos_compare(tsc, saved_pos)) { + g_warning("Problem with seek_n ! Positions differ. (1)"); + } + + lttv_process_traceset_seek_n_forward(tsc, 500, NULL, NULL, NULL, NULL, NULL, NULL); + lttv_traceset_context_position_save(tsc, saved_pos); + lttv_process_traceset_seek_n_forward(tsc, 15000, NULL, NULL, NULL, NULL, NULL, NULL); + lttv_process_traceset_seek_n_backward(tsc, 15005, + seek_back_default_offset, lttv_process_traceset_seek_time, NULL, + NULL, NULL, NULL, NULL, NULL); + lttv_process_traceset_seek_n_forward(tsc, 5, NULL, NULL, NULL, NULL, NULL, NULL); + if(lttv_traceset_context_ctx_pos_compare(tsc, saved_pos)) { + g_warning("Problem with seek_n ! Positions differ. (2)"); + } + + lttv_process_traceset_seek_time(tsc, ltt_time_infinite); + + count = lttv_process_traceset_seek_n_forward(tsc, 15000, NULL, NULL, NULL, NULL, NULL, NULL); + if(count > 0) + g_warning("Problem with seek_n ! Forward at end of traceset."); + + lttv_process_traceset_seek_time(tsc, ltt_time_infinite); + + lttv_traceset_context_position_save(tsc, saved_pos); + t0 = get_time(); + lttv_process_traceset_seek_n_backward(tsc, 300, + seek_back_default_offset, lttv_process_traceset_seek_time, NULL, + NULL, NULL, NULL, NULL, NULL); + t1 = get_time(); + g_message("Seek backward 300 events in %g seconds", t1 - t0); + count = lttv_process_traceset_seek_n_forward(tsc, 299, NULL, NULL, NULL, NULL, NULL, NULL); + count = lttv_process_traceset_seek_n_forward(tsc, 1, NULL, NULL, NULL, NULL, NULL, NULL); + + if(lttv_traceset_context_ctx_pos_compare(tsc, saved_pos)) { + g_warning("Problem with seek_n ! Positions differ. (4)"); + } + + lttv_traceset_context_position_save(tsc, saved_pos); + t0 = get_time(); + lttv_process_traceset_seek_n_backward(tsc, 10, + seek_back_default_offset, lttv_process_traceset_seek_time, NULL, + NULL, NULL, NULL, NULL, NULL); + t1 = get_time(); + g_message("Seek backward 10 events in %g seconds", t1 - t0); + t0 = get_time(); + count = lttv_process_traceset_seek_n_forward(tsc, 10, NULL, NULL, NULL, NULL, NULL, NULL); + t1 = get_time(); + g_message("Seek forward 10 events in %g seconds", t1 - t0); + + + /* try a volountary error */ + lttv_process_traceset_seek_time(tsc, ltt_time_infinite); + + lttv_traceset_context_position_save(tsc, saved_pos); + lttv_process_traceset_seek_n_backward(tsc, 301, + seek_back_default_offset, lttv_process_traceset_seek_time, NULL, + NULL, NULL, NULL, NULL, NULL); + count = lttv_process_traceset_seek_n_forward(tsc, 299, NULL, NULL, NULL, NULL, NULL, NULL); + count = lttv_process_traceset_seek_n_forward(tsc, 1, NULL, NULL, NULL, NULL, NULL, NULL); + + if(lttv_traceset_context_ctx_pos_compare(tsc, saved_pos) == 0) { + g_warning("Problem with seek_n ! Positions _should_ differ. (5)"); + } + + /* Try a seek by closest time : Hint : try this one with and without states + * computed. */ + lttv_process_traceset_seek_time(tsc, ltt_time_zero); + count = lttv_process_traceset_seek_n_forward(tsc, 200000, NULL, NULL, NULL, NULL, NULL, NULL); + lttv_traceset_context_position_save(tsc, saved_pos); + t0 = get_time(); + lttv_process_traceset_seek_n_backward(tsc, 100301, + seek_back_default_offset, + (seek_time_fct)lttv_state_traceset_seek_time_closest, NULL, + NULL, NULL, NULL, NULL, NULL); + t1 = get_time(); + g_message("Seek backward 100301 events (with seek closest) in %g seconds", + t1 - t0); + count = lttv_process_traceset_seek_n_forward(tsc, 100301, NULL, NULL, NULL, NULL, NULL, NULL); + + if(lttv_traceset_context_ctx_pos_compare(tsc, saved_pos)) { + g_warning("Problem with seek_n with state seek time! Positions differ. (6)"); + } + + lttv_traceset_context_position_destroy(saved_pos); + } + + if(a_test10 || a_test_all) { + g_message("Running test 10 : check seek traceset context position"); + LttvTracesetContext *tsc = &ts->parent; + LttvTracesetContextPosition *saved_pos = + lttv_traceset_context_position_new(tsc); + + lttv_process_traceset_seek_time(tsc, ltt_time_zero); + lttv_process_traceset_seek_n_forward(tsc, 200000, NULL, NULL, NULL, NULL, NULL, NULL); + lttv_traceset_context_position_save(tsc, saved_pos); + if(lttv_traceset_context_ctx_pos_compare(tsc, saved_pos) != 0) + g_critical("Error in seek position. (1)"); + + lttv_process_traceset_seek_time(tsc, ltt_time_infinite); + lttv_process_traceset_seek_n_backward(tsc, 500, + seek_back_default_offset, lttv_process_traceset_seek_time, NULL, + NULL, NULL, NULL, NULL, NULL); + lttv_traceset_context_position_save(tsc, saved_pos); + + if(lttv_traceset_context_ctx_pos_compare(tsc, saved_pos) != 0) + g_critical("Error in seek position. (2)"); + + lttv_traceset_context_position_destroy(saved_pos); + } + if(a_trace_event) lttv_hooks_remove_data(event_hook, trace_event, NULL); g_free(save_state.write_time); @@ -666,6 +885,20 @@ static void init() lttv_option_add("test7", '7', "Test seeking to positions written out in 3", "", LTTV_OPT_NONE, &a_test7, NULL, NULL); + a_test8 = FALSE; + lttv_option_add("test8", '8', "Test seeking to positions using saved states computed at 6 : check if number of events fits", + "", LTTV_OPT_NONE, &a_test8, NULL, NULL); + + a_test9 = FALSE; + lttv_option_add("test9", '9', "Test seeking backward/forward positions", + "", LTTV_OPT_NONE, &a_test9, NULL, NULL); + + a_test10 = FALSE; + lttv_option_add("test10", ' ', "Test seeking traceset by position", + "", LTTV_OPT_NONE, &a_test10, NULL, NULL); + + + a_test_all = FALSE; lttv_option_add("testall", 'a', "Run all tests ", "", LTTV_OPT_NONE, &a_test_all, NULL, NULL); @@ -740,6 +973,9 @@ static void destroy() lttv_option_remove("test5"); lttv_option_remove("test6"); lttv_option_remove("test7"); + lttv_option_remove("test8"); + lttv_option_remove("test9"); + lttv_option_remove("test10"); lttv_option_remove("testall"); lttv_hooks_destroy(before_traceset);