X-Git-Url: http://git.lttng.org./?a=blobdiff_plain;f=ltt%2Fbranches%2Fpoly%2Flttv%2Flttv%2Fstate.c;h=52815dd922dfd4335c287f5e974c74934ad6e944;hb=45653836d75635b5b841d0d03f1f0789348adc56;hp=b333729ca003c9ff5718fbf735bd4443b90210f4;hpb=348c6ba830cba63cc5486e2cea042c8a70cf1fb2;p=lttv.git diff --git a/ltt/branches/poly/lttv/lttv/state.c b/ltt/branches/poly/lttv/lttv/state.c index b333729c..52815dd9 100644 --- a/ltt/branches/poly/lttv/lttv/state.c +++ b/ltt/branches/poly/lttv/lttv/state.c @@ -35,7 +35,8 @@ GQuark LTT_FACILITY_KERNEL, - LTT_FACILITY_PROCESS; + LTT_FACILITY_PROCESS, + LTT_FACILITY_FS; /* Events Quarks */ @@ -49,7 +50,8 @@ GQuark LTT_EVENT_SCHEDCHANGE, LTT_EVENT_FORK, LTT_EVENT_EXIT, - LTT_EVENT_FREE; + LTT_EVENT_FREE, + LTT_EVENT_EXEC; /* Fields Quarks */ @@ -62,7 +64,8 @@ GQuark LTT_FIELD_OUT_STATE, LTT_FIELD_PARENT_PID, LTT_FIELD_CHILD_PID, - LTT_FIELD_PID; + LTT_FIELD_PID, + LTT_FIELD_FILENAME; LttvExecutionMode LTTV_STATE_MODE_UNKNOWN, @@ -82,7 +85,8 @@ LttvProcessStatus LTTV_STATE_EXIT, LTTV_STATE_ZOMBIE, LTTV_STATE_WAIT, - LTTV_STATE_RUN; + LTTV_STATE_RUN, + LTTV_STATE_DEAD; static GQuark LTTV_STATE_TRACEFILES, @@ -171,10 +175,14 @@ restore_init_state(LttvTraceState *self) self->nb_event = 0; /* Seek time to beginning */ - g_tree_destroy(self->parent.ts_context->pqueue); - self->parent.ts_context->pqueue = g_tree_new(compare_tracefile); + // Mathieu : fix : don't seek traceset here : causes inconsistency in seek + // closest. It's the tracecontext job to seek the trace to the beginning + // anyway : the init state might be used at the middle of the trace as well... + //g_tree_destroy(self->parent.ts_context->pqueue); + //self->parent.ts_context->pqueue = g_tree_new(compare_tracefile); - lttv_process_trace_seek_time(&self->parent, ltt_time_zero); + + //lttv_process_trace_seek_time(&self->parent, ltt_time_zero); nb_cpus = ltt_trace_get_num_cpu(self->parent.t); @@ -467,7 +475,8 @@ static void state_save(LttvTraceState *self, LttvAttribute *container) value = lttv_attribute_add(container, LTTV_STATE_RUNNING_PROCESS, LTTV_POINTER); *(value.v_pointer) = running_process; - + + g_info("State save"); nb_tracefile = self->parent.tracefiles->len; @@ -501,7 +510,7 @@ static void state_save(LttvTraceState *self, LttvAttribute *container) guint64 tsc; LttTracefile *tf; ltt_event_position_get(ep, &tf, &nb_block, &offset, &tsc); - g_debug("Block %u offset %u tsc %llu time %lu.%lu", nb_block, offset, + g_info("Block %u offset %u tsc %llu time %lu.%lu", nb_block, offset, tsc, tfcs->parent.timestamp.tv_sec, tfcs->parent.timestamp.tv_nsec); } @@ -553,8 +562,8 @@ static void state_restore(LttvTraceState *self, LttvAttribute *container) nb_tracefile = self->parent.tracefiles->len; - g_tree_destroy(tsc->pqueue); - tsc->pqueue = g_tree_new(compare_tracefile); + //g_tree_destroy(tsc->pqueue); + //tsc->pqueue = g_tree_new(compare_tracefile); for(i = 0 ; i < nb_tracefile ; i++) { tfcs = @@ -578,12 +587,14 @@ static void state_restore(LttvTraceState *self, LttvAttribute *container) g_assert(tfcs->parent.t_context != NULL); LttvTracefileContext *tfc = LTTV_TRACEFILE_CONTEXT(tfcs); + g_tree_remove(tsc->pqueue, tfc); if(ep != NULL) { g_assert(ltt_tracefile_seek_position(tfc->tf, ep) == 0); tfc->timestamp = ltt_event_time(ltt_tracefile_get_event(tfc->tf)); g_assert(ltt_time_compare(tfc->timestamp, ltt_time_infinite) != 0); g_tree_insert(tsc->pqueue, tfc, tfc); + g_info("Restoring state for a tf at time %lu.%lu", tfc->timestamp.tv_sec, tfc->timestamp.tv_nsec); } else { tfc->timestamp = ltt_time_infinite; } @@ -623,7 +634,7 @@ static void state_saved_free(LttvTraceState *self, LttvAttribute *container) /* Free running processes array */ nb_cpus = ltt_trace_get_num_cpu(self->parent.t); - type = lttv_attribute_get_by_name(tracefile_tree, LTTV_STATE_RUNNING_PROCESS, + type = lttv_attribute_get_by_name(container, LTTV_STATE_RUNNING_PROCESS, &value); g_assert(type == LTTV_POINTER); running_process = *(value.v_pointer); @@ -878,6 +889,25 @@ free_name_tables(LttvTraceState *tcs) g_free(name_tables); } +#ifdef HASH_TABLE_DEBUG + +static void test_process(gpointer key, gpointer value, gpointer user_data) +{ + LttvProcessState *process = (LttvProcessState *)value; + + /* Test for process corruption */ + guint stack_len = process->execution_stack->len; +} + +static void hash_table_check(GHashTable *table) +{ + g_hash_table_foreach(table, test_process, NULL); +} + + +#endif + + static void push_state(LttvTracefileState *tfs, LttvExecutionMode t, guint state_id) { @@ -885,6 +915,10 @@ static void push_state(LttvTracefileState *tfs, LttvExecutionMode t, guint cpu = ltt_tracefile_num(tfs->parent.tf); LttvTraceState *ts = (LttvTraceState*)tfs->parent.t_context; + +#ifdef HASH_TABLE_DEBUG + hash_table_check(ts->processes); +#endif LttvProcessState *process = ts->running_process[cpu]; guint depth = process->execution_stack->len; @@ -984,7 +1018,7 @@ lttv_state_create_process(LttvTraceState *tcs, LttvProcessState *parent, //process->last_cpu_index = ltt_tracefile_num(((LttvTracefileContext*)tfs)->tf); process->execution_stack = g_array_sized_new(FALSE, FALSE, sizeof(LttvExecutionState), PREALLOCATED_EXECUTION_STACK); - process->execution_stack = g_array_set_size(process->execution_stack, 1); + process->execution_stack = g_array_set_size(process->execution_stack, 2); es = process->state = &g_array_index(process->execution_stack, LttvExecutionState, 0); es->t = LTTV_STATE_USER_MODE; @@ -992,6 +1026,15 @@ lttv_state_create_process(LttvTraceState *tcs, LttvProcessState *parent, es->entry = *timestamp; //g_assert(timestamp->tv_sec != 0); es->change = *timestamp; + es->s = LTTV_STATE_RUN; + + es = process->state = &g_array_index(process->execution_stack, + LttvExecutionState, 1); + es->t = LTTV_STATE_SYSCALL; + es->n = LTTV_STATE_SUBMODE_NONE; + es->entry = *timestamp; + //g_assert(timestamp->tv_sec != 0); + es->change = *timestamp; es->s = LTTV_STATE_WAIT_FORK; return process; @@ -1169,18 +1212,16 @@ static gboolean schedchange(void *hook_data, void *call_data) if(unlikely(process->state->s == LTTV_STATE_EXIT)) { process->state->s = LTTV_STATE_ZOMBIE; + process->state->change = s->parent.timestamp; } else { if(unlikely(state_out == 0)) process->state->s = LTTV_STATE_WAIT_CPU; else process->state->s = LTTV_STATE_WAIT; - } /* FIXME : we do not remove process here, because the kernel - * still has them : they may be zombies. We need to know - * exactly when release_task is executed on the PID to - * know when the zombie is destroyed. - */ - //else - // exit_process(s, process); - - process->state->change = s->parent.timestamp; + process->state->change = s->parent.timestamp; + } + + if(state_out == 32) + exit_process(s, process); /* EXIT_DEAD */ + /* see sched.h for states */ } process = ts->running_process[cpu] = lttv_state_find_process_or_create( @@ -1206,6 +1247,7 @@ static gboolean process_fork(void *hook_data, void *call_data) guint cpu = ltt_tracefile_num(s->parent.tf); LttvTraceState *ts = (LttvTraceState*)s->parent.t_context; LttvProcessState *process = ts->running_process[cpu]; + LttvProcessState *child_process; /* Parent PID */ f = thf->f1; @@ -1215,18 +1257,45 @@ static gboolean process_fork(void *hook_data, void *call_data) f = thf->f2; child_pid = ltt_event_get_unsigned(e, f); + /* Mathieu : it seems like the process might have been scheduled in before the + * fork, and, in a rare case, might be the current process. This might happen + * in a SMP case where we don't have enough precision on the clocks. + * + * Test reenabled after precision fixes on time. (Mathieu) */ +#if 0 zombie_process = lttv_state_find_process(ts, ANY_CPU, child_pid); if(unlikely(zombie_process != NULL)) { /* Reutilisation of PID. Only now we are sure that the old PID * has been released. FIXME : should know when release_task happens instead. */ + guint num_cpus = ltt_trace_get_num_cpu(ts->parent.t); + guint i; + for(i=0; i< num_cpus; i++) { + g_assert(zombie_process != ts->running_process[i]); + } + exit_process(s, zombie_process); } +#endif //0 g_assert(process->pid != child_pid); // FIXME : Add this test in the "known state" section // g_assert(process->pid == parent_pid); - lttv_state_create_process(ts, process, cpu, child_pid, &s->parent.timestamp); + child_process = lttv_state_find_process(ts, ANY_CPU, child_pid); + if(child_process == NULL) { + lttv_state_create_process(ts, process, cpu, + child_pid, &s->parent.timestamp); + } else { + /* The process has already been created : due to time imprecision between + * multiple CPUs : it has been scheduled in before creation. Note that we + * shouldn't have this kind of imprecision. + * + * Simply put a correct parent. + */ + g_assert(0); /* This is a problematic case : the process has been created + before the fork event */ + child_process->ppid = process->pid; + } return FALSE; } @@ -1265,18 +1334,62 @@ static gboolean process_free(void *hook_data, void *call_data) /* PID of the process to release */ release_pid = ltt_event_get_unsigned(e, thf->f1); + + g_assert(release_pid != 0); process = lttv_state_find_process(ts, ANY_CPU, release_pid); if(likely(process != NULL)) { /* release_task is happening at kernel level : we can now safely release * the data structure of the process */ - exit_process(s, process); + //This test is fun, though, as it may happen that + //at time t : CPU 0 : process_free + //at time t+150ns : CPU 1 : schedule out + //Clearly due to time imprecision, we disable it. (Mathieu) + //If this weird case happen, we have no choice but to put the + //Currently running process on the cpu to 0. + //I re-enable it following time precision fixes. (Mathieu) + //Well, in the case where an process is freed by a process on another CPU + //and still scheduled, it happens that this is the schedchange that will + //drop the last reference count. Do not free it here! + guint num_cpus = ltt_trace_get_num_cpu(ts->parent.t); + guint i; + for(i=0; i< num_cpus; i++) { + //g_assert(process != ts->running_process[i]); + if(process == ts->running_process[i]) { + //ts->running_process[i] = lttv_state_find_process(ts, i, 0); + break; + } + } + if(i == num_cpus) /* process is not scheduled */ + exit_process(s, process); } return FALSE; } + +static gboolean process_exec(void *hook_data, void *call_data) +{ + LttvTracefileState *s = (LttvTracefileState *)call_data; + LttvTraceState *ts = (LttvTraceState*)s->parent.t_context; + LttEvent *e = ltt_tracefile_get_event(s->parent.tf); + LttvTraceHookByFacility *thf = (LttvTraceHookByFacility *)hook_data; + gchar *name; + guint cpu = ltt_tracefile_num(s->parent.tf); + LttvProcessState *process = ts->running_process[cpu]; + + /* PID of the process to release */ + name = ltt_event_get_string(e, thf->f1); + + process->name = g_quark_from_string(name); + + return FALSE; +} + + + + gint lttv_state_hook_add_event_hooks(void *hook_data, void *call_data) { LttvTracesetState *tss = (LttvTracesetState*)(call_data); @@ -1313,8 +1426,8 @@ void lttv_state_add_event_hooks(LttvTracesetState *self) /* Find the eventtype id for the following events and register the associated by id hooks. */ - hooks = g_array_sized_new(FALSE, FALSE, sizeof(LttvTraceHook), 10); - hooks = g_array_set_size(hooks, 10); + hooks = g_array_sized_new(FALSE, FALSE, sizeof(LttvTraceHook), 11); + hooks = g_array_set_size(hooks, 11); ret = lttv_trace_find_hook(ts->parent.t, LTT_FACILITY_KERNEL, LTT_EVENT_SYSCALL_ENTRY, @@ -1376,6 +1489,13 @@ void lttv_state_add_event_hooks(LttvTracesetState *self) process_free, NULL, &g_array_index(hooks, LttvTraceHook, 9)); g_assert(!ret); + ret = lttv_trace_find_hook(ts->parent.t, + LTT_FACILITY_FS, LTT_EVENT_EXEC, + LTT_FIELD_FILENAME, 0, 0, + process_exec, NULL, &g_array_index(hooks, LttvTraceHook, 10)); + g_assert(!ret); + + /* Add these hooks to each event_by_id hooks list */ @@ -1463,12 +1583,10 @@ void lttv_state_remove_event_hooks(LttvTracesetState *self) } } -static guint test_event_count = 0; static gboolean state_save_event_hook(void *hook_data, void *call_data) { guint *event_count = (guint*)hook_data; - test_event_count++; /* Only save at LTTV_STATE_SAVE_INTERVAL */ if(likely((*event_count)++ < LTTV_STATE_SAVE_INTERVAL)) return FALSE; @@ -1508,6 +1626,15 @@ static gboolean state_save_event_hook(void *hook_data, void *call_data) return FALSE; } +static gboolean state_save_after_trace_hook(void *hook_data, void *call_data) +{ + LttvTraceState *tcs = (LttvTraceState *)(call_data); + + *(tcs->max_time_state_recomputed_in_seek) = tcs->parent.time_span.end_time; + + return FALSE; +} + #if 0 static gboolean block_start(void *hook_data, void *call_data) { @@ -1656,6 +1783,10 @@ void lttv_state_save_add_event_hooks(LttvTracesetState *self) } } + + lttv_process_traceset_begin(&self->parent, + NULL, NULL, NULL, NULL, NULL); + } gint lttv_state_save_hook_add_event_hooks(void *hook_data, void *call_data) @@ -1716,7 +1847,19 @@ void lttv_state_save_remove_event_hooks(LttvTracesetState *self) LttvTracefileState *tfs; + LttvHooks *after_trace = lttv_hooks_new(); + + lttv_hooks_add(after_trace, + state_save_after_trace_hook, + NULL, + LTTV_PRIO_STATE); + + + lttv_process_traceset_end(&self->parent, + NULL, after_trace, NULL, NULL, NULL); + lttv_hooks_destroy(after_trace); + nb_trace = lttv_traceset_number(traceset); for(i = 0 ; i < nb_trace ; i++) { @@ -1731,11 +1874,9 @@ void lttv_state_save_remove_event_hooks(LttvTracesetState *self) LttvTracefileContext*, j)); event_count = lttv_hooks_remove(tfs->parent.event, state_save_event_hook); - } g_free(event_count); } - g_info("EVENT COUNT TEST : %u", test_event_count); } gint lttv_state_save_hook_remove_event_hooks(void *hook_data, void *call_data) @@ -1755,6 +1896,8 @@ void lttv_state_traceset_seek_time_closest(LttvTracesetState *self, LttTime t) int min_pos, mid_pos, max_pos; + guint call_rest = 0; + LttvTraceState *tcs; LttvAttributeValue value; @@ -1765,8 +1908,10 @@ void lttv_state_traceset_seek_time_closest(LttvTracesetState *self, LttTime t) LttvAttribute *saved_states_tree, *saved_state_tree, *closest_tree; - g_tree_destroy(self->parent.pqueue); - self->parent.pqueue = g_tree_new(compare_tracefile); + //g_tree_destroy(self->parent.pqueue); + //self->parent.pqueue = g_tree_new(compare_tracefile); + + g_info("Entering seek_time_closest for time %lu.%lu", t.tv_sec, t.tv_nsec); nb_trace = lttv_traceset_number(traceset); for(i = 0 ; i < nb_trace ; i++) { @@ -1800,6 +1945,7 @@ void lttv_state_traceset_seek_time_closest(LttvTracesetState *self, LttTime t) /* restore the closest earlier saved state */ if(min_pos != -1) { lttv_state_restore(tcs, closest_tree); + call_rest = 1; } /* There is no saved state, yet we want to have it. Restart at T0 */ @@ -1814,6 +1960,7 @@ void lttv_state_traceset_seek_time_closest(LttvTracesetState *self, LttTime t) lttv_process_trace_seek_time(&(tcs->parent), t); } } + if(!call_rest) g_info("NOT Calling restore"); } @@ -1985,6 +2132,7 @@ static void module_init() LTTV_STATE_ZOMBIE = g_quark_from_string("zombie"); LTTV_STATE_WAIT = g_quark_from_string("wait for I/O"); LTTV_STATE_RUN = g_quark_from_string("running"); + LTTV_STATE_DEAD = g_quark_from_string("dead"); LTTV_STATE_TRACEFILES = g_quark_from_string("tracefiles"); LTTV_STATE_PROCESSES = g_quark_from_string("processes"); LTTV_STATE_PROCESS = g_quark_from_string("process"); @@ -2001,6 +2149,7 @@ static void module_init() LTT_FACILITY_KERNEL = g_quark_from_string("kernel"); LTT_FACILITY_PROCESS = g_quark_from_string("process"); + LTT_FACILITY_FS = g_quark_from_string("fs"); LTT_EVENT_SYSCALL_ENTRY = g_quark_from_string("syscall_entry"); @@ -2013,6 +2162,7 @@ static void module_init() LTT_EVENT_FORK = g_quark_from_string("fork"); LTT_EVENT_EXIT = g_quark_from_string("exit"); LTT_EVENT_FREE = g_quark_from_string("free"); + LTT_EVENT_EXEC = g_quark_from_string("exec"); LTT_FIELD_SYSCALL_ID = g_quark_from_string("syscall_id"); @@ -2024,6 +2174,7 @@ static void module_init() LTT_FIELD_PARENT_PID = g_quark_from_string("parent_pid"); LTT_FIELD_CHILD_PID = g_quark_from_string("child_pid"); LTT_FIELD_PID = g_quark_from_string("pid"); + LTT_FIELD_FILENAME = g_quark_from_string("filename"); }