depanalysis: fix segfault, remove some warnings
[lttv.git] / lttv / modules / text / depanalysis.c
1 /* This file is part of the Linux Trace Toolkit viewer
2 * Copyright (C) 2008 Pierre-Marc Fournier
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 #ifdef HAVE_CONFIG_H
20 #include <config.h>
21 #endif
22
23 #include <lttv/lttv.h>
24 #include <lttv/option.h>
25 #include <lttv/module.h>
26 #include <lttv/hook.h>
27 #include <lttv/attribute.h>
28 #include <lttv/iattribute.h>
29 #include <lttv/stats.h>
30 #include <lttv/filter.h>
31 #include <lttv/print.h>
32 #include <ltt/ltt.h>
33 #include <ltt/event.h>
34 #include <ltt/trace.h>
35 #define _GNU_SOURCE
36 #include <stdio.h>
37 #include <glib.h>
38 #include <stdlib.h>
39
40 #include "sstack.h"
41
42 static LttvHooks
43 *before_traceset,
44 *after_traceset,
45 // *before_trace,
46 *event_hook;
47
48 static int depanalysis_range_pid = -1;
49 static int depanalysis_range_pid_searching = -1;
50 static int depanalysis_use_time=0;
51 static int depanalysis_event_limit = -1;
52 static LttTime depanalysis_time1, depanalysis_time2;
53 static char *arg_t1_str,*arg_t2_str;
54 static int statedump_finished = 0;
55
56
57 struct llev_state_info_irq {
58 int irq;
59 };
60
61 struct llev_state_info_softirq {
62 int softirq;
63 };
64
65 struct llev_state_info_syscall {
66 int syscall_id;
67
68 int substate;
69
70 void *private;
71 };
72
73 struct llev_state_info_syscall__open {
74 GQuark filename;
75 };
76
77 struct llev_state_info_syscall__read {
78 GQuark filename;
79 };
80
81 struct llev_state_info_syscall__poll {
82 GQuark filename;
83 };
84
85 struct llev_state_info_preempted {
86 int prev_state;
87 };
88
89 struct hlev_state_info_blocked {
90 int syscall_id;
91 unsigned char trap; /* flag */
92 int substate;
93
94 /* Garray of pointers to struct process_state that reflect the
95 * low-level state stack when respectively entering and exiting the blocked
96 * state.
97 */
98 GArray *llev_state_entry;
99 GArray *llev_state_exit;
100
101 int pid_exit; /* FIXME: it's not pretty to have this here; find this info elsewhere */
102 LttTime time_woken;
103
104 void *private;
105 };
106
107 struct hlev_state_info_blocked__open {
108 GQuark filename;
109 };
110
111 struct hlev_state_info_blocked__read {
112 GQuark filename;
113 };
114
115 struct hlev_state_info_blocked__poll {
116 GQuark filename;
117 };
118
119 struct hlev_state_info_interrupted_irq {
120 int irq;
121 };
122
123 struct hlev_state_info_interrupted_softirq {
124 int softirq;
125 };
126
127 struct summary_tree_node {
128 char *name;
129 GHashTable *children;
130 LttTime duration;
131 GArray *episodes;
132 int id_for_episodes;
133 };
134
135 struct state_info {
136 char name[40];
137 int size_priv;
138 char *tree_path[6];
139 };
140
141 struct state_info llev_state_infos[] = {
142 { "UNKNOWN", 0, { NULL } },
143 { "RUNNING", 0, { NULL } },
144 { "SYSCALL", sizeof(struct llev_state_info_syscall), { NULL } },
145 { "IRQ", sizeof(struct llev_state_info_irq), { NULL } },
146 { "SOFTIRQ", sizeof(struct llev_state_info_softirq), { NULL } },
147 { "TRAP", 0, { NULL } },
148 { "PREEMPTED", sizeof(struct llev_state_info_preempted), { NULL } },
149 };
150
151 struct state_info hlev_state_infos[] = {
152 { "UNKNOWN", 0, { "Total", "Unknown", NULL } },
153 { "RUNNING", 0, { "Total", "Working", NULL } },
154 { "BLOCKED", sizeof(struct hlev_state_info_blocked), { "Total", "Blocked", NULL } },
155 { "INTERRUPTED_IRQ", sizeof(struct hlev_state_info_interrupted_irq), { "Total", "Interrupted", "IRQ", NULL } },
156 { "INTERRUPTED_SOFTIRQ", sizeof(struct hlev_state_info_interrupted_softirq), { "Total", "Interrupted", "SoftIRQ", NULL } },
157 { "INTERRUPTED_CPU", 0, { "Total", "Interrupted", "Preempted", NULL } },
158 { "INTERRUPTED_POST_BLOCK", 0, { "Total", "Interrupted", "Waiting schedule after blocking", NULL } },
159 };
160
161 enum llev_state {
162 LLEV_UNKNOWN=0,
163 LLEV_RUNNING,
164 LLEV_SYSCALL,
165 LLEV_IRQ,
166 LLEV_SOFTIRQ,
167 LLEV_TRAP,
168 LLEV_PREEMPTED,
169 };
170
171 enum llev_syscall_substate {
172 LLEV_SYSCALL__UNDEFINED,
173 LLEV_SYSCALL__OPEN,
174 LLEV_SYSCALL__READ,
175 LLEV_SYSCALL__POLL,
176 };
177
178 enum hlev_event {
179 HLEV_EVENT_TRY_WAKEUP=0,
180 };
181
182 enum hlev_state {
183 HLEV_UNKNOWN=0,
184 HLEV_RUNNING,
185 HLEV_BLOCKED,
186 HLEV_INTERRUPTED_IRQ,
187 HLEV_INTERRUPTED_SOFTIRQ,
188 HLEV_INTERRUPTED_CPU,
189 HLEV_INTERRUPTED_POST_BLOCK,
190 };
191
192 enum hlev_state_blocked {
193 HLEV_BLOCKED__UNDEFINED,
194 HLEV_BLOCKED__OPEN,
195 HLEV_BLOCKED__READ,
196 HLEV_BLOCKED__POLL,
197 };
198
199 struct sstack_event {
200 int event_type;
201 void *private;
202 };
203
204 struct try_wakeup_event {
205 int pid; /* this sould be more precise avec pid may be reused */
206 LttTime time;
207 struct process *waker;
208 };
209
210 struct process_state {
211 int bstate;
212 int cause_type;
213 void *private;
214
215 LttTime time_begin;
216 LttTime time_end;
217 };
218
219 struct process_with_state {
220 struct process *process;
221 struct process_state state;
222 };
223
224 #define PROCESS_STATE_STACK_SIZE 10
225 struct process {
226 int pid;
227 GQuark name;
228 int parent;
229
230 struct sstack *stack;
231 struct process_state *llev_state_stack[PROCESS_STATE_STACK_SIZE];
232 int stack_current;
233 struct process_state *hlev_state;
234 GArray *hlev_history;
235 };
236
237 static inline void *old_process_state_private_data(struct process *p)
238 {
239 return p->llev_state_stack[p->stack_current]->private;
240 }
241
242 static inline struct process_state *process_find_state(struct process *p, enum llev_state st)
243 {
244 int i;
245
246 for(i=p->stack->array->len-1; i>=0; i--) {
247 struct sstack_item *item = g_array_index(p->stack->array, struct sstack_item *, i);
248
249 struct process_with_state *pwstate = item->data_val;
250 if(pwstate->state.bstate == st) {
251 return &pwstate->state;
252 }
253 }
254
255 return NULL;
256 }
257
258 static int find_pos_in_stack(enum llev_state lls, struct process *p)
259 {
260 int i;
261 for(i=p->stack_current; i>=0; i--) {
262 if(p->llev_state_stack[i]->bstate == lls)
263 return i;
264 }
265
266 return -1;
267 }
268
269 static struct process_state *find_in_stack(enum llev_state lls, struct process *p)
270 {
271 int result;
272
273 result = find_pos_in_stack(lls, p);
274
275 if(result >= 0)
276 return p->llev_state_stack[result];
277 else
278 return NULL;
279
280 }
281
282 /* called back from sstack on deletion of a data_val which is
283 * a struct process_with_state
284 */
285
286 static void delete_data_val(struct process_with_state *pwstate)
287 {
288 // FIXME: Free this also
289 //g_free(pwstate->state.private);
290
291 // FIXME: this is really ugly. Don't free the pwstate if the state is LLEV_RUNNING.
292 // LLEV_RUNNING is a special case that's being processed and deleted immediately after
293 // being inserted on the sstack, to prevent state begin accumulated because it couldn't
294 // be processed before the end of the trace. If we free the state, we get invalid memory
295 // reads when looking at it on the state_stack.
296 //if(pwstate->state.bstate != LLEV_RUNNING)
297 // g_free(pwstate);
298 }
299
300 inline void print_time(LttTime t)
301 {
302 //printf("%lu.%lu", t.tv_sec, t.tv_nsec);
303 double f;
304 f = (double)t.tv_sec + ((double)t.tv_nsec)/1000000000.0;
305 printf("%.9f", f);
306 }
307
308 static struct sstack_item *prepare_push_item(struct process *p, enum llev_state st, LttTime t)
309 {
310 struct process_with_state *pwstate = g_malloc(sizeof(struct process_with_state));
311 struct sstack_item *item;
312
313 int wait_for_pop = 0;
314
315 if(st == LLEV_SYSCALL) {
316 /* We need to push LLEV_SYSCALL as wait_for_pop because it depends on some of
317 * its children. If we don't do this, it's going to get processed immediately
318 * by the sstack and we might miss some details about it that will come later.
319 */
320 wait_for_pop = 1;
321 }
322
323 item = sstack_item_new_push(wait_for_pop);
324
325 //printf("pushing in context of %d\n", p->pid);
326
327 pwstate->process = p;
328 pwstate->state.bstate = st;
329 pwstate->state.time_begin = t;
330 pwstate->state.private = g_malloc(llev_state_infos[st].size_priv);
331
332 item->data_val = pwstate;
333 item->delete_data_val = (void (*)(void*))delete_data_val;
334
335 return item;
336 }
337
338 static void *item_private(struct sstack_item *item)
339 {
340 struct process_with_state *pwstate = item->data_val;
341 return pwstate->state.private;
342 }
343
344 static void commit_item(struct process *p, struct sstack_item *item)
345 {
346 sstack_add_item(p->stack, item);
347 }
348
349 static void old_process_push_llev_state(struct process *p, struct process_state *pstate)
350 {
351 if(++p->stack_current >= PROCESS_STATE_STACK_SIZE) {
352 fprintf(stderr, "depanalysis: internal process stack overflow\n");
353 abort();
354 }
355
356 p->llev_state_stack[p->stack_current] = pstate;
357 }
358
359 static void live_complete_process_push_llev_state(struct process *p, enum llev_state st, LttTime t)
360 {
361 struct process_state *pstate = g_malloc(sizeof(struct process_state));
362
363 pstate->bstate = st;
364 pstate->time_begin = t;
365 pstate->private = g_malloc(llev_state_infos[st].size_priv);
366
367 old_process_push_llev_state(p, pstate);
368 }
369
370 static void prepare_pop_item_commit_nocheck(struct process *p, enum llev_state st, LttTime t)
371 {
372 struct process_with_state *pwstate;
373 struct sstack_item *item = sstack_item_new_pop();
374
375 int push_idx;
376
377 if(p->stack->pushes->len > 0)
378 push_idx = g_array_index(p->stack->pushes, int, p->stack->pushes->len-1);
379 else
380 push_idx = -1;
381
382 if(push_idx >= 0) {
383 pwstate = g_array_index(p->stack->array, struct sstack_item *, push_idx)->data_val;
384 pwstate->process = p;
385 pwstate->state.time_end = t;
386 item->data_val = pwstate;
387 /* don't set delete_data_val because we use the same pwstate as push, and we don't want to free it twice */
388 }
389 else {
390
391 pwstate = g_malloc(sizeof(struct process_with_state));
392 pwstate->process = p;
393 item->data_val = pwstate;
394 pwstate->state.time_end = t;
395 pwstate->state.bstate = st;
396 }
397
398 sstack_add_item(p->stack, item);
399
400 }
401
402 static void prepare_pop_item_commit(struct process *p, enum llev_state st, LttTime t)
403 {
404 struct process_with_state *pwstate;
405 struct sstack_item *item = sstack_item_new_pop();
406
407 int push_idx;
408
409 if(p->stack->pushes->len > 0)
410 push_idx = g_array_index(p->stack->pushes, int, p->stack->pushes->len-1);
411 else
412 push_idx = -1;
413
414 if(push_idx >= 0) {
415 /* FIXME: ugly workaround for kernel bug that generates two kernel_arch_syscall_exit on fork.
416 * The bug only occurs upon creation of new processes. But these processes always have
417 * a LLEV_RUNNING at index 0. */
418 if(push_idx >= p->stack->array->len)
419 return;
420
421 pwstate = g_array_index(p->stack->array, struct sstack_item *, push_idx)->data_val;
422
423 if(pwstate->state.bstate != st) {
424 /* FIXME: ugly workaround for kernel bug that generates two kernel_arch_syscall_exit on fork */
425 if(st != LLEV_SYSCALL) {
426 printf("bad pop! at ");
427 print_time(t);
428 printf("\n");
429 print_stack(p->stack);
430 abort();
431 }
432 else {
433 /* case where we have a double syscall_exit */
434 return;
435 }
436 }
437 }
438
439 prepare_pop_item_commit_nocheck(p, st, t);
440 }
441
442
443 static int try_pop_blocked_llev_preempted(struct process *p, LttTime t)
444 {
445 int push_idx;
446 struct process_with_state *pwstate;
447
448 if(p->stack->pushes->len > 0)
449 push_idx = g_array_index(p->stack->pushes, int, p->stack->pushes->len-1);
450 else
451 push_idx = -1;
452
453 if(push_idx >= 0) {
454 pwstate = g_array_index(p->stack->array, struct sstack_item *, push_idx)->data_val;
455
456 if(!(pwstate->state.bstate == LLEV_PREEMPTED && ((struct llev_state_info_preempted *)pwstate->state.private)->prev_state > 0)) {
457 printf("double try wake up\n");
458 return 0;
459 }
460 }
461
462 prepare_pop_item_commit_nocheck(p, LLEV_PREEMPTED, t);
463 return 1;
464 }
465
466 static void old_process_pop_llev_state(struct process *p, struct process_state *pstate)
467 {
468 /* Ensure we are really popping the current state */
469 /* FIXME: pstate->bstate is uninitialized? */
470 // Commenting because it does not work. The way things work now, this check cannot work.
471 //if(p->llev_state_stack[p->stack_current]->bstate != LLEV_UNKNOWN && p->llev_state_stack[p->stack_current]->bstate != pstate->bstate) {
472 // printf("ERROR! bad pop!\n");
473 // abort();
474 //}
475
476 /* Actually change the that position */
477 if(p->stack_current >= 0)
478 p->stack_current--;
479
480 /* If stack empty, we must put something in it */
481 if(p->stack_current == -1) {
482 if(pstate->bstate == LLEV_SYSCALL) {
483 //process_push_llev_state(p, LLEV_RUNNING, pstate->time_end);
484 live_complete_process_push_llev_state(p, LLEV_RUNNING, pstate->time_end);
485 }
486 else {
487 live_complete_process_push_llev_state(p, LLEV_UNKNOWN, pstate->time_end);
488 }
489 }
490 }
491
492 static GHashTable *process_hash_table;
493 static GHashTable *syscall_table;
494 static GHashTable *irq_table;
495 static GHashTable *softirq_table;
496
497 /* Insert the hooks before and after each trace and tracefile, and for each
498 event. Print a global header. */
499
500 static FILE *a_file;
501
502 static GString *a_string;
503
504 static gboolean write_traceset_header(void *hook_data, void *call_data)
505 {
506 LttvTracesetContext *tc = (LttvTracesetContext *)call_data;
507
508 g_info("Traceset header");
509
510 /* Print the trace set header */
511 fprintf(a_file,"Trace set contains %d traces\n\n",
512 lttv_traceset_number(tc->ts));
513
514 return FALSE;
515 }
516
517 GArray *oldstyle_stack_to_garray(struct process_state **oldstyle_stack, int current)
518 {
519 GArray *retval;
520 int i;
521
522 retval = g_array_new(FALSE, FALSE, sizeof(struct process_state *));
523
524 for(i=0; i<current; i++) {
525 g_array_append_val(retval, oldstyle_stack[i]);
526 }
527
528 return retval;
529 }
530
531 static void update_hlev_state(struct process *p, LttTime t)
532 {
533 int i;
534
535 enum hlev_state new_hlev;
536
537 for(i=p->stack_current; i>=0; i--) {
538 enum llev_state st;
539 st = p->llev_state_stack[i]->bstate;
540
541 if(st == LLEV_RUNNING || st == LLEV_TRAP || st == LLEV_SYSCALL) {
542 new_hlev = HLEV_RUNNING;
543 break;
544 }
545 else if(st == LLEV_IRQ) {
546 new_hlev = HLEV_INTERRUPTED_IRQ;
547 break;
548 }
549 else if(st == LLEV_SOFTIRQ) {
550 new_hlev = HLEV_INTERRUPTED_SOFTIRQ;
551 break;
552 }
553 else if(st == LLEV_PREEMPTED) {
554 int prev_state = ((struct llev_state_info_preempted *) old_process_state_private_data(p))->prev_state;
555
556 if(prev_state == 0) {
557 new_hlev = HLEV_INTERRUPTED_CPU;
558 }
559 else if(prev_state == -1) {
560 new_hlev = HLEV_INTERRUPTED_POST_BLOCK;
561 }
562 else {
563 new_hlev = HLEV_BLOCKED;
564 }
565 break;
566 }
567 else if(st == LLEV_UNKNOWN) {
568 new_hlev = HLEV_UNKNOWN;
569 break;
570 }
571 else {
572 abort();
573 }
574 }
575
576 /* If no state change, do nothing */
577 if(p->hlev_state != NULL && new_hlev == p->hlev_state->bstate) {
578 return;
579 }
580
581 p->hlev_state->time_end = t;
582 /* This check is here because we initially put HLEV_UNKNOWN as hlev state, but in the case
583 * of processes newly created, it is immediately replaced by HLEV_BLOCKED. In order to avoid
584 * having a UNKNOWN state of duration 0 in the summary, we don't add it. This isn't as elegant
585 * as it ought to be.
586 */
587 if(ltt_time_compare(p->hlev_state->time_begin, p->hlev_state->time_end) != 0)
588 g_array_append_val(p->hlev_history, p->hlev_state);
589 p->hlev_state = g_malloc(sizeof(struct process_state));
590 p->hlev_state->bstate = new_hlev;
591 p->hlev_state->time_begin = t;
592 p->hlev_state->private = g_malloc(hlev_state_infos[new_hlev].size_priv);
593
594 //printf("depanalysis: now at hlev state %s\n", hlev_state_infos[new_hlev].name);
595
596 /* Set private data */
597 switch(p->hlev_state->bstate) {
598 case HLEV_UNKNOWN:
599 break;
600 case HLEV_RUNNING:
601 break;
602 case HLEV_BLOCKED: {
603 struct hlev_state_info_blocked *hlev_blocked_private = p->hlev_state->private;
604 //struct process_state *ps = find_in_stack(LLEV_SYSCALL, p);
605 int syscall_pos = find_pos_in_stack(LLEV_SYSCALL, p);
606 int trap_pos = find_pos_in_stack(LLEV_TRAP, p);
607
608 /* init vals */
609 hlev_blocked_private->syscall_id = 1;
610 hlev_blocked_private->trap = 0;
611 hlev_blocked_private->substate = HLEV_BLOCKED__UNDEFINED;
612 hlev_blocked_private->private = NULL;
613 hlev_blocked_private->llev_state_entry = oldstyle_stack_to_garray(p->llev_state_stack, p->stack_current);
614 hlev_blocked_private->llev_state_exit = NULL;
615
616 //g_assert(syscall_pos >= 0 || trap_pos >= 0);
617
618 if(trap_pos > syscall_pos) {
619 hlev_blocked_private->trap = 1;
620 }
621
622 /* initial value, may be changed below */
623 hlev_blocked_private->substate = HLEV_BLOCKED__UNDEFINED;
624
625 if(syscall_pos >= 0) {
626 struct process_state *ps = p->llev_state_stack[syscall_pos];
627 struct llev_state_info_syscall *llev_syscall_private = (struct llev_state_info_syscall *) ps->private;
628 hlev_blocked_private->syscall_id = llev_syscall_private->syscall_id;
629
630 if(llev_syscall_private->substate == LLEV_SYSCALL__OPEN) {
631 struct llev_state_info_syscall__open *llev_syscall_open_private;
632 struct hlev_state_info_blocked__open *hlev_blocked_open_private;
633 llev_syscall_open_private = llev_syscall_private->private;
634 hlev_blocked_private->substate = HLEV_BLOCKED__OPEN;
635 hlev_blocked_open_private = g_malloc(sizeof(struct hlev_state_info_blocked__open));
636 hlev_blocked_private->private = hlev_blocked_open_private;
637 hlev_blocked_open_private->filename = llev_syscall_open_private->filename;
638
639 //printf("depanalysis: blocked in an open!\n");
640 }
641 else if(llev_syscall_private->substate == LLEV_SYSCALL__READ) {
642 struct llev_state_info_syscall__read *llev_syscall_read_private;
643 struct hlev_state_info_blocked__read *hlev_blocked_read_private;
644 llev_syscall_read_private = llev_syscall_private->private;
645 hlev_blocked_private->substate = HLEV_BLOCKED__READ;
646 hlev_blocked_read_private = g_malloc(sizeof(struct hlev_state_info_blocked__read));
647 hlev_blocked_private->private = hlev_blocked_read_private;
648 hlev_blocked_read_private->filename = llev_syscall_read_private->filename;
649
650 //printf("depanalysis: blocked in a read!\n");
651 }
652 else if(llev_syscall_private->substate == LLEV_SYSCALL__POLL) {
653 struct llev_state_info_syscall__poll *llev_syscall_poll_private;
654 struct hlev_state_info_blocked__poll *hlev_blocked_poll_private;
655 llev_syscall_poll_private = llev_syscall_private->private;
656 hlev_blocked_private->substate = HLEV_BLOCKED__POLL;
657 hlev_blocked_poll_private = g_malloc(sizeof(struct hlev_state_info_blocked__poll));
658 hlev_blocked_private->private = hlev_blocked_poll_private;
659 hlev_blocked_poll_private->filename = llev_syscall_poll_private->filename;
660
661 //printf("depanalysis: blocked in a read!\n");
662 }
663 }
664 else {
665 hlev_blocked_private->syscall_id = -1;
666 }
667
668 break;
669 }
670 case HLEV_INTERRUPTED_IRQ: {
671 struct hlev_state_info_interrupted_irq *sinfo = p->hlev_state->private;
672 struct process_state *ps = find_in_stack(LLEV_IRQ, p);
673 if(ps == NULL)
674 abort();
675 else
676 sinfo->irq = ((struct llev_state_info_irq *) ps->private)->irq;
677 break;
678 }
679 case HLEV_INTERRUPTED_SOFTIRQ: {
680 struct hlev_state_info_interrupted_softirq *sinfo = p->hlev_state->private;
681 struct process_state *ps = find_in_stack(LLEV_SOFTIRQ, p);
682 if(ps == NULL)
683 abort();
684 else
685 sinfo->softirq = ((struct llev_state_info_softirq *) ps->private)->softirq;
686 break;
687 }
688 default:
689 break;
690 };
691 }
692
693 static gint compare_summary_tree_node_times(gconstpointer a, gconstpointer b)
694 {
695 struct summary_tree_node *n1 = (struct summary_tree_node *) a;
696 struct summary_tree_node *n2 = (struct summary_tree_node *) b;
697
698 return ltt_time_compare(n2->duration, n1->duration);
699 }
700
701 /* Print an item of the simple summary tree, and recurse, printing its children.
702 *
703 * If depth == -1, this is the root: we don't print a label, we only recurse into
704 * the children.
705 */
706
707 static void print_summary_item(struct summary_tree_node *node, int depth)
708 {
709 GList *vals;
710
711 if(depth >= 0) {
712 printf("\t%*s (", strlen(node->name)+2*depth, node->name);
713 print_time(node->duration);
714 printf(") <%d>\n", node->id_for_episodes);
715 }
716
717 if(!node->children)
718 return;
719
720 vals = g_hash_table_get_values(node->children);
721
722 /* sort the values */
723 vals = g_list_sort(vals, compare_summary_tree_node_times);
724
725 while(vals) {
726 print_summary_item((struct summary_tree_node *)vals->data, depth+1);
727 vals = vals->next;
728 }
729
730 /* we must free the list returned by g_hash_table_get_values() */
731 g_list_free(vals);
732 }
733
734 static inline void print_irq(int irq)
735 {
736 printf("IRQ %d [%s]", irq, g_quark_to_string(g_hash_table_lookup(irq_table, &irq)));
737 }
738
739 static inline void print_softirq(int softirq)
740 {
741 printf("SoftIRQ %d [%s]", softirq, g_quark_to_string(g_hash_table_lookup(softirq_table, &softirq)));
742 }
743
744 static inline void print_pid(int pid)
745 {
746 struct process *event_process_info = g_hash_table_lookup(process_hash_table, &pid);
747
748 char *pname;
749
750 if(event_process_info == NULL)
751 pname = "?";
752 else
753 pname = g_quark_to_string(event_process_info->name);
754 printf("%d [%s]", pid, pname);
755 }
756
757 static void modify_path_with_private(GArray *path, struct process_state *pstate)
758 {
759 //GString tmps = g_string_new("");
760 char *tmps;
761
762 // FIXME: fix this leak
763 switch(pstate->bstate) {
764 case HLEV_INTERRUPTED_IRQ:
765 asprintf(&tmps, "IRQ %d [%s]", ((struct hlev_state_info_interrupted_irq *)pstate->private)->irq, g_quark_to_string(g_hash_table_lookup(irq_table, &((struct hlev_state_info_interrupted_irq *)pstate->private)->irq)));
766 g_array_append_val(path, tmps);
767 break;
768 case HLEV_INTERRUPTED_SOFTIRQ:
769 asprintf(&tmps, "SoftIRQ %d [%s]", ((struct hlev_state_info_interrupted_softirq *)pstate->private)->softirq, g_quark_to_string(g_hash_table_lookup(softirq_table, &((struct hlev_state_info_interrupted_softirq *)pstate->private)->softirq)));
770 g_array_append_val(path, tmps);
771 break;
772 case HLEV_BLOCKED: {
773 struct hlev_state_info_blocked *hlev_blocked_private = (struct hlev_state_info_blocked *)pstate->private;
774
775 if(hlev_blocked_private->trap) {
776 char *ptr = "Trap";
777 g_array_append_val(path, ptr);
778 }
779
780 if(hlev_blocked_private->syscall_id == -1) {
781 char *ptr = "Userspace";
782 g_array_append_val(path, ptr);
783 }
784 else {
785 asprintf(&tmps, "Syscall %d [%s]", hlev_blocked_private->syscall_id, g_quark_to_string(g_hash_table_lookup(syscall_table, &hlev_blocked_private->syscall_id)));
786 g_array_append_val(path, tmps);
787 }
788
789 if(((struct hlev_state_info_blocked *)pstate->private)->substate == HLEV_BLOCKED__OPEN) {
790 char *str = g_quark_to_string(((struct hlev_state_info_blocked__open *)((struct hlev_state_info_blocked *)pstate->private)->private)->filename);
791 g_array_append_val(path, str);
792 }
793 else if(((struct hlev_state_info_blocked *)pstate->private)->substate == HLEV_BLOCKED__READ) {
794 char *str;
795 asprintf(&str, "%s", g_quark_to_string(((struct hlev_state_info_blocked__read *)((struct hlev_state_info_blocked *)pstate->private)->private)->filename));
796 g_array_append_val(path, str);
797 /* FIXME: this must be freed at some point */
798 //free(str);
799 }
800 else if(((struct hlev_state_info_blocked *)pstate->private)->substate == HLEV_BLOCKED__POLL) {
801 char *str;
802 asprintf(&str, "%s", g_quark_to_string(((struct hlev_state_info_blocked__poll *)((struct hlev_state_info_blocked *)pstate->private)->private)->filename));
803 g_array_append_val(path, str);
804 /* FIXME: this must be freed at some point */
805 //free(str);
806 }
807 break;
808 }
809 };
810 }
811
812 void print_stack_garray_horizontal(GArray *stack)
813 {
814 /* FIXME: this function doesn't work if we delete the states as we process them because we
815 * try to read those states here to print the low level stack.
816 */
817 int i;
818
819 for(i=0; i<stack->len; i++) {
820 struct process_state *pstate = g_array_index(stack, struct process_state *, i);
821 printf("%s", llev_state_infos[pstate->bstate].name);
822
823 if(pstate->bstate == LLEV_SYSCALL) {
824 struct llev_state_info_syscall *llev_syscall_private = pstate->private;
825 printf(" %d [%s]", llev_syscall_private->syscall_id, g_quark_to_string(g_hash_table_lookup(syscall_table, &llev_syscall_private->syscall_id)));
826 }
827
828 printf(", ");
829
830 }
831 }
832
833 static int dicho_search_state_ending_after(struct process *p, LttTime t)
834 {
835 int under = 0;
836 int over = p->hlev_history->len-1;
837 struct process_state *pstate;
838 int result;
839
840 if(over < 1)
841 return -1;
842
843 /* If the last element is smaller or equal than the time we are searching for,
844 * no match
845 */
846 pstate = g_array_index(p->hlev_history, struct process_state *, over);
847 if(ltt_time_compare(pstate->time_end, t) <= 0) {
848 return -1;
849 }
850 /* no need to check for the equal case */
851
852 pstate = g_array_index(p->hlev_history, struct process_state *, under);
853 result = ltt_time_compare(pstate->time_end, t);
854 if(result >= 1) {
855 /* trivial match at the first element if it is greater or equal
856 * than the time we want
857 */
858 return under;
859 }
860
861 while(1) {
862 int dicho;
863
864 dicho = (under+over)/2;
865 pstate = g_array_index(p->hlev_history, struct process_state *, dicho);
866 result = ltt_time_compare(pstate->time_end, t);
867
868 if(result == -1) {
869 under = dicho;
870 }
871 else if(result == 1) {
872 over = dicho;
873 }
874 else {
875 /* exact match */
876 return dicho+1;
877 }
878
879 if(over-under == 1) {
880 /* we have converged */
881 return over;
882 }
883 }
884
885 }
886
887 /* FIXME: this shouldn't be based on pids in case of reuse
888 * FIXME: should add a list of processes used to avoid loops
889 */
890
891 static struct process_state *find_state_ending_after(int pid, LttTime t)
892 {
893 struct process *p;
894 int result;
895
896
897 p = g_hash_table_lookup(process_hash_table, &pid);
898 if(!p)
899 return NULL;
900
901 result = dicho_search_state_ending_after(p, t);
902
903 if(result == -1)
904 return NULL;
905 else
906 return g_array_index(p->hlev_history, struct process_state *, result);
907 }
908
909 static void print_delay_pid(int pid, LttTime t1, LttTime t2, int offset)
910 {
911 struct process *p;
912 int i;
913
914 p = g_hash_table_lookup(process_hash_table, &pid);
915 if(!p)
916 return;
917
918 i = dicho_search_state_ending_after(p, t1);
919 for(; i<p->hlev_history->len; i++) {
920 struct process_state *pstate = g_array_index(p->hlev_history, struct process_state *, i);
921 if(ltt_time_compare(pstate->time_end, t2) > 0)
922 break;
923
924 if(pstate->bstate == HLEV_BLOCKED) {
925 struct hlev_state_info_blocked *state_private_blocked;
926 state_private_blocked = pstate->private;
927 struct process_state *state_unblocked;
928
929 printf("%*s", 8*offset, "");
930 printf("Blocked in ");
931 print_stack_garray_horizontal(state_private_blocked->llev_state_entry);
932
933 printf("(times: ");
934 print_time(pstate->time_begin);
935 printf("-");
936 print_time(pstate->time_end);
937
938 printf(", dur: %f)\n", 1e-9*ltt_time_to_double(ltt_time_sub(pstate->time_end, pstate->time_begin)));
939
940 state_unblocked = find_state_ending_after(state_private_blocked->pid_exit, state_private_blocked->time_woken);
941 if(state_unblocked) {
942 if(state_unblocked->bstate == HLEV_INTERRUPTED_IRQ) {
943 struct hlev_state_info_interrupted_irq *priv = state_unblocked->private;
944 /* if in irq or softirq, we don't care what the waking process was doing because they are asynchroneous events */
945 printf("%*s", 8*offset, "");
946 printf("Woken up by an IRQ: ");
947 print_irq(priv->irq);
948 printf("\n");
949 }
950 else if(state_unblocked->bstate == HLEV_INTERRUPTED_SOFTIRQ) {
951 struct hlev_state_info_interrupted_softirq *priv = state_unblocked->private;
952 printf("%*s", 8*offset, "");
953 printf("Woken up by a SoftIRQ: ");
954 print_softirq(priv->softirq);
955 printf("\n");
956 }
957 else {
958 LttTime t1prime=t1;
959 LttTime t2prime=t2;
960
961 if(ltt_time_compare(t1prime, pstate->time_begin) < 0)
962 t1prime = pstate->time_begin;
963 if(ltt_time_compare(t2prime, pstate->time_end) > 0)
964 t2prime = pstate->time_end;
965
966 print_delay_pid(state_private_blocked->pid_exit, t1prime, t2prime, offset+1);
967 printf("%*s", 8*offset, "");
968 printf("Woken up in context of ");
969 print_pid(state_private_blocked->pid_exit);
970 if(state_private_blocked->llev_state_exit) {
971 print_stack_garray_horizontal(state_private_blocked->llev_state_exit);
972 }
973 else {
974 }
975 printf(" in high-level state %s", hlev_state_infos[state_unblocked->bstate].name);
976 printf("\n");
977 }
978 }
979 else {
980 printf("%*s", 8*offset, "");
981 printf("Weird... cannot find in what state the waker (%d) was\n", state_private_blocked->pid_exit);
982 }
983
984
985 //print_delay_pid(state_private_blocked->pid_exit, pstate->time_start, pstate->time_end);
986 //printf("\t\t Woken up in context of %d: ", state_private_blocked->pid_exit);
987 //if(state_private_blocked->llev_state_exit) {
988 // print_stack_garray_horizontal(state_private_blocked->llev_state_exit);
989 // printf("here3 (%d)\n", state_private_blocked->llev_state_exit->len);
990 //}
991 //else
992 // printf("the private_blocked %p had a null exit stack\n", state_private_blocked);
993 //printf("\n");
994 }
995 }
996 }
997
998 static void print_range_critical_path(int process, LttTime t1, LttTime t2)
999 {
1000 printf("Critical path for requested range:\n");
1001 printf("Final process is %d\n", process);
1002 print_delay_pid(process, t1, t2, 2);
1003 }
1004
1005 static void print_process_critical_path_summary()
1006 {
1007 struct process *pinfo;
1008 GList *pinfos;
1009 int i,j;
1010
1011 pinfos = g_hash_table_get_values(process_hash_table);
1012 if(pinfos == NULL) {
1013 fprintf(stderr, "error: no process found\n");
1014 return;
1015 }
1016
1017 printf("Process Critical Path Summary:\n");
1018
1019 for(;;) {
1020 struct summary_tree_node base_node = { children: NULL };
1021
1022 struct process_state *hlev_state_cur;
1023
1024 pinfo = (struct process *)pinfos->data;
1025 printf("\tProcess %d [%s]\n", pinfo->pid, g_quark_to_string(pinfo->name));
1026
1027 if(pinfo->hlev_history->len < 1)
1028 goto next_iter;
1029
1030 print_delay_pid(pinfo->pid, g_array_index(pinfo->hlev_history, struct process_state *, 0)->time_begin, g_array_index(pinfo->hlev_history, struct process_state *, pinfo->hlev_history->len - 1)->time_end, 2);
1031
1032 next_iter:
1033
1034 if(pinfos->next)
1035 pinfos = pinfos->next;
1036 else
1037 break;
1038 }
1039 }
1040
1041 gint compare_states_length(gconstpointer a, gconstpointer b)
1042 {
1043 struct process_state **s1 = (struct process_state **)a;
1044 struct process_state **s2 = (struct process_state **)b;
1045 gint val;
1046
1047 val = ltt_time_compare(ltt_time_sub((*s2)->time_end, (*s2)->time_begin), ltt_time_sub((*s1)->time_end, (*s1)->time_begin));
1048 return val;
1049 }
1050
1051 static void print_simple_summary()
1052 {
1053 struct process *pinfo;
1054 GList *pinfos;
1055 GList *pinfos_first;
1056 int i,j;
1057 int id_for_episodes = 0;
1058
1059 /* we save all the nodes here to print the episodes table quickly */
1060 GArray *all_nodes = g_array_new(FALSE, FALSE, sizeof(struct summary_tree_node *));
1061
1062 pinfos_first = g_hash_table_get_values(process_hash_table);
1063 if(pinfos_first == NULL) {
1064 fprintf(stderr, "error: no processes found\n");
1065 return;
1066 }
1067 pinfos = pinfos_first;
1068
1069 printf("Simple summary:\n");
1070
1071 /* For each process */
1072 for(;;) {
1073 struct summary_tree_node base_node = { children: NULL, name: "Root" };
1074
1075 struct process_state *hlev_state_cur;
1076
1077 pinfo = (struct process *)pinfos->data;
1078 printf("\tProcess %d [%s]\n", pinfo->pid, g_quark_to_string(pinfo->name));
1079
1080 /* For each state in the process history */
1081 for(i=0; i<pinfo->hlev_history->len; i++) {
1082 struct process_state *pstate = g_array_index(pinfo->hlev_history, struct process_state *, i);
1083 struct summary_tree_node *node_cur = &base_node;
1084 GArray *tree_path_garray;
1085
1086 /* Modify the path based on private data */
1087 tree_path_garray = g_array_new(FALSE, FALSE, sizeof(char *));
1088 {
1089 int count=0;
1090 char **tree_path_cur2 = hlev_state_infos[pstate->bstate].tree_path;
1091 while(*tree_path_cur2) {
1092 count++;
1093 tree_path_cur2++;
1094 }
1095 g_array_append_vals(tree_path_garray, hlev_state_infos[pstate->bstate].tree_path, count);
1096 }
1097 modify_path_with_private(tree_path_garray, pstate);
1098
1099 /* Walk the path, adding the nodes to the summary */
1100 for(j=0; j<tree_path_garray->len; j++) {
1101 struct summary_tree_node *newnode;
1102 GQuark componentquark;
1103
1104 /* Have a path component we must follow */
1105 if(!node_cur->children) {
1106 /* must create the hash table for the children */
1107 node_cur->children = g_hash_table_new(g_int_hash, g_int_equal);
1108 }
1109
1110 /* try to get the node for the next component */
1111 componentquark = g_quark_from_string(g_array_index(tree_path_garray, char *, j));
1112 newnode = g_hash_table_lookup(node_cur->children, &componentquark);
1113 if(newnode == NULL) {
1114 newnode = g_malloc(sizeof(struct summary_tree_node));
1115 newnode->children = NULL;
1116 newnode->name = g_array_index(tree_path_garray, char *, j);
1117 newnode->duration = ltt_time_zero;
1118 newnode->id_for_episodes = id_for_episodes++;
1119 newnode->episodes = g_array_new(FALSE, FALSE, sizeof(struct process_state *));
1120 g_hash_table_insert(node_cur->children, &componentquark, newnode);
1121
1122 g_array_append_val(all_nodes, newnode);
1123 }
1124 node_cur = newnode;
1125
1126 node_cur->duration = ltt_time_add(node_cur->duration, ltt_time_sub(pstate->time_end, pstate->time_begin));
1127 g_array_append_val(node_cur->episodes, pstate);
1128 }
1129 }
1130
1131 /* print the summary */
1132 print_summary_item(&base_node, -1);
1133
1134 printf("\n");
1135
1136 if(pinfos->next)
1137 pinfos = pinfos->next;
1138 else
1139 break;
1140 }
1141
1142 printf("\n");
1143
1144 printf("Episode list\n");
1145 pinfos = pinfos_first;
1146
1147 /* For all the nodes of the Simple summary tree */
1148 for(i=0; i<all_nodes->len; i++) {
1149 struct summary_tree_node *node = (struct summary_tree_node *)g_array_index(all_nodes, struct summary_tree_node *, i);
1150
1151 /* Sort the episodes from longest to shortest */
1152 g_array_sort(node->episodes, compare_states_length);
1153
1154 printf("\tNode id: <%d>\n", node->id_for_episodes);
1155 /* For each episode of the node */
1156 for(j=0; j<node->episodes->len; j++) {
1157 struct process_state *st = g_array_index(node->episodes, struct process_state *, j);
1158
1159 printf("\t\t");
1160 print_time(st->time_begin);
1161 printf("-");
1162 print_time(st->time_end);
1163 printf(" (%f)\n", 1e-9*ltt_time_to_double(ltt_time_sub(st->time_end,st->time_begin)));
1164 }
1165 }
1166 }
1167
1168 static void print_simple_summary_pid_range(int pid, LttTime t1, LttTime t2)
1169 {
1170 struct process *pinfo;
1171 int i,j;
1172 int id_for_episodes = 0;
1173
1174 /* we save all the nodes here to print the episodes table quickly */
1175 GArray *all_nodes = g_array_new(FALSE, FALSE, sizeof(struct summary_tree_node *));
1176
1177 pinfo = g_hash_table_lookup(process_hash_table, &pid);
1178
1179 {
1180 struct summary_tree_node base_node = { children: NULL, name: "Root" };
1181
1182 struct process_state *hlev_state_cur;
1183
1184 printf("\tProcess %d [%s]\n", pinfo->pid, g_quark_to_string(pinfo->name));
1185
1186 /* For each state in the process history */
1187 for(i=0; i<pinfo->hlev_history->len; i++) {
1188 struct process_state *pstate = g_array_index(pinfo->hlev_history, struct process_state *, i);
1189 struct summary_tree_node *node_cur = &base_node;
1190 GArray *tree_path_garray;
1191
1192 if(ltt_time_compare(pstate->time_end, t1) < 0)
1193 continue;
1194
1195 if(ltt_time_compare(pstate->time_end, t2) > 0)
1196 break;
1197
1198 /* Modify the path based on private data */
1199 tree_path_garray = g_array_new(FALSE, FALSE, sizeof(char *));
1200 {
1201 int count=0;
1202 char **tree_path_cur2 = hlev_state_infos[pstate->bstate].tree_path;
1203 while(*tree_path_cur2) {
1204 count++;
1205 tree_path_cur2++;
1206 }
1207 g_array_append_vals(tree_path_garray, hlev_state_infos[pstate->bstate].tree_path, count);
1208 }
1209 modify_path_with_private(tree_path_garray, pstate);
1210
1211 /* Walk the path, adding the nodes to the summary */
1212 for(j=0; j<tree_path_garray->len; j++) {
1213 struct summary_tree_node *newnode;
1214 GQuark componentquark;
1215
1216 /* Have a path component we must follow */
1217 if(!node_cur->children) {
1218 /* must create the hash table for the children */
1219 node_cur->children = g_hash_table_new(g_int_hash, g_int_equal);
1220 }
1221
1222 /* try to get the node for the next component */
1223 componentquark = g_quark_from_string(g_array_index(tree_path_garray, char *, j));
1224 newnode = g_hash_table_lookup(node_cur->children, &componentquark);
1225 if(newnode == NULL) {
1226 newnode = g_malloc(sizeof(struct summary_tree_node));
1227 newnode->children = NULL;
1228 newnode->name = g_array_index(tree_path_garray, char *, j);
1229 newnode->duration = ltt_time_zero;
1230 newnode->id_for_episodes = id_for_episodes++;
1231 newnode->episodes = g_array_new(FALSE, FALSE, sizeof(struct process_state *));
1232 g_hash_table_insert(node_cur->children, &componentquark, newnode);
1233
1234 g_array_append_val(all_nodes, newnode);
1235 }
1236 node_cur = newnode;
1237
1238 node_cur->duration = ltt_time_add(node_cur->duration, ltt_time_sub(pstate->time_end, pstate->time_begin));
1239 g_array_append_val(node_cur->episodes, pstate);
1240 }
1241 }
1242
1243 /* print the summary */
1244 print_summary_item(&base_node, -1);
1245
1246 printf("\n");
1247 }
1248
1249 printf("\n");
1250
1251 printf("Episode list\n");
1252
1253 /* For all the nodes of the Simple summary tree */
1254 for(i=0; i<all_nodes->len; i++) {
1255 struct summary_tree_node *node = (struct summary_tree_node *)g_array_index(all_nodes, struct summary_tree_node *, i);
1256
1257 /* Sort the episodes from longest to shortest */
1258 g_array_sort(node->episodes, compare_states_length);
1259
1260 printf("\tNode id: <%d>\n", node->id_for_episodes);
1261 /* For each episode of the node */
1262 for(j=0; j<node->episodes->len; j++) {
1263 struct process_state *st = g_array_index(node->episodes, struct process_state *, j);
1264
1265 printf("\t\t");
1266 print_time(st->time_begin);
1267 printf("-");
1268 print_time(st->time_end);
1269 printf(" (%f)\n", 1e-9*ltt_time_to_double(ltt_time_sub(st->time_end,st->time_begin)));
1270 }
1271 }
1272 }
1273
1274 static void flush_process_sstacks(void)
1275 {
1276 GList *pinfos;
1277
1278 pinfos = g_hash_table_get_values(process_hash_table);
1279 while(pinfos) {
1280 struct process *pinfo = (struct process *)pinfos->data;
1281
1282 sstack_force_flush(pinfo->stack);
1283
1284 pinfos = pinfos->next;
1285 }
1286
1287 g_list_free(pinfos);
1288 }
1289
1290 struct family_item {
1291 int pid;
1292 LttTime creation;
1293 };
1294
1295 void print_range_reports(int pid, LttTime t1, LttTime t2)
1296 {
1297 GArray *family = g_array_new(FALSE, FALSE, sizeof(struct family_item));
1298 int i;
1299
1300 /* reconstruct the parental sequence */
1301 for(;;) {
1302 struct process *pinfo;
1303 struct family_item fi;
1304 LttTime cur_beg;
1305
1306 pinfo = g_hash_table_lookup(process_hash_table, &pid);
1307 if(pinfo == NULL)
1308 abort();
1309
1310 fi.pid = pid;
1311 cur_beg = g_array_index(pinfo->hlev_history, struct process_state *, 0)->time_begin;
1312 fi.creation = cur_beg;
1313 g_array_append_val(family, fi);
1314
1315 if(ltt_time_compare(cur_beg, t1) == -1) {
1316 /* current pid starts before the interesting time */
1317 break;
1318 }
1319 if(pinfo->parent == -1) {
1320 printf("unable to go back, we don't know the parent of %d\n", fi.pid);
1321 abort();
1322 }
1323 /* else, we go on */
1324 pid = pinfo->parent;
1325
1326 }
1327
1328 printf("Simple summary for range:\n");
1329 for(i=family->len-1; i>=0; i--) {
1330 LttTime iter_t1, iter_t2;
1331 int iter_pid = g_array_index(family, struct family_item, i).pid;
1332
1333 if(i == family->len-1)
1334 iter_t1 = t1;
1335 else
1336 iter_t1 = g_array_index(family, struct family_item, i).creation;
1337
1338 if(i == 0)
1339 iter_t2 = t2;
1340 else
1341 iter_t2 = g_array_index(family, struct family_item, i-1).creation;
1342
1343 printf("This section of summary concerns pid %d between ");
1344 print_time(iter_t1);
1345 printf(" and ");
1346 print_time(iter_t2);
1347 printf(".\n");
1348 print_simple_summary_pid_range(iter_pid, iter_t1, iter_t2);
1349 }
1350 print_range_critical_path(depanalysis_range_pid, t1, t2);
1351 }
1352
1353 static gboolean write_traceset_footer(void *hook_data, void *call_data)
1354 {
1355 LttvTracesetContext *tc = (LttvTracesetContext *)call_data;
1356
1357 g_info("TextDump traceset footer");
1358
1359 fprintf(a_file,"End trace set\n\n");
1360
1361 // if(LTTV_IS_TRACESET_STATS(tc)) {
1362 // lttv_stats_sum_traceset((LttvTracesetStats *)tc, ltt_time_infinite);
1363 // print_stats(a_file, (LttvTracesetStats *)tc);
1364 // }
1365
1366 /* After processing all the events, we need to flush the sstacks
1367 * because some unfinished states may remain in them. We want them
1368 * event though there are incomplete.
1369 */
1370 flush_process_sstacks();
1371
1372 /* print the reports */
1373 print_simple_summary();
1374 print_process_critical_path_summary();
1375 printf("depanalysis_use_time = %d\n", depanalysis_use_time);
1376 if(depanalysis_use_time == 3) {
1377 if(depanalysis_range_pid == -1 && depanalysis_range_pid_searching >= 0)
1378 depanalysis_range_pid = depanalysis_range_pid_searching;
1379
1380 if(depanalysis_range_pid >= 0) {
1381 print_range_reports(depanalysis_range_pid, depanalysis_time1, depanalysis_time2);
1382 }
1383 else
1384 printf("range critical path: could not find the end of the range\n");
1385 }
1386
1387 return FALSE;
1388 }
1389
1390 #if 0
1391 static gboolean write_trace_header(void *hook_data, void *call_data)
1392 {
1393 LttvTraceContext *tc = (LttvTraceContext *)call_data;
1394 #if 0 //FIXME
1395 LttSystemDescription *system = ltt_trace_system_description(tc->t);
1396
1397 fprintf(a_file," Trace from %s in %s\n%s\n\n",
1398 ltt_trace_system_description_node_name(system),
1399 ltt_trace_system_description_domain_name(system),
1400 ltt_trace_system_description_description(system));
1401 #endif //0
1402 return FALSE;
1403 }
1404 #endif
1405
1406
1407 static int write_event_content(void *hook_data, void *call_data)
1408 {
1409 gboolean result;
1410
1411 // LttvIAttribute *attributes = LTTV_IATTRIBUTE(lttv_global_attributes());
1412
1413 LttvTracefileContext *tfc = (LttvTracefileContext *)call_data;
1414
1415 LttvTracefileState *tfs = (LttvTracefileState *)call_data;
1416
1417 LttEvent *e;
1418
1419 guint cpu = tfs->cpu;
1420 LttvTraceState *ts = (LttvTraceState*)tfc->t_context;
1421 LttvProcessState *process = ts->running_process[cpu];
1422
1423 e = ltt_tracefile_get_event(tfc->tf);
1424
1425 lttv_event_to_string(e, a_string, TRUE, 1, tfs);
1426
1427 // if(a_state) {
1428 g_string_append_printf(a_string, " %s ",
1429 g_quark_to_string(process->state->s));
1430 // }
1431
1432 g_string_append_printf(a_string,"\n");
1433
1434 fputs(a_string->str, a_file);
1435 return FALSE;
1436 }
1437
1438 static int field_get_value_int(struct LttEvent *e, struct marker_info *info, GQuark f)
1439 {
1440 struct marker_field *marker_field;
1441 int found=0;
1442
1443 for_each_marker_field(marker_field, info) {
1444 if (marker_field->name == f) {
1445 found = 1;
1446 break;
1447 }
1448 }
1449 g_assert(found);
1450 return ltt_event_get_long_unsigned(e, marker_field);
1451 }
1452
1453 static char *field_get_value_string(struct LttEvent *e, struct marker_info *info, GQuark f)
1454 {
1455 struct marker_field *marker_field;
1456 int found=0;
1457
1458 for_each_marker_field(marker_field, info) {
1459 if (marker_field->name == f) {
1460 found = 1;
1461 break;
1462 }
1463 }
1464 g_assert(found);
1465 return ltt_event_get_string(e, marker_field);
1466 }
1467
1468 void process_delayed_stack_action(struct process *pinfo, struct sstack_item *item)
1469 {
1470 //printf("processing delayed stack action on pid %d at ", pinfo->pid);
1471 //if(((struct process_with_state *) item->data_val)->state.time_begin.tv_nsec == 987799696)
1472 // printf("HERE!!!\n");
1473 //print_time(((struct process_with_state *) item->data_val)->state.time_begin);
1474 //printf("\n");
1475 //printf("stack before:\n");
1476 //print_stack(pinfo->stack);
1477
1478 if(item->data_type == SSTACK_TYPE_PUSH) {
1479 struct process_with_state *pwstate = item->data_val;
1480 //printf("pushing\n");
1481 old_process_push_llev_state(pinfo, &pwstate->state);
1482 update_hlev_state(pinfo, pwstate->state.time_begin);
1483 }
1484 else if(item->data_type == SSTACK_TYPE_POP) {
1485 struct process_with_state *pwstate = item->data_val;
1486 //printf("popping\n");
1487 old_process_pop_llev_state(pinfo, &pwstate->state);
1488 update_hlev_state(pinfo, pwstate->state.time_end);
1489 }
1490 else if(item->data_type == SSTACK_TYPE_EVENT) {
1491 struct sstack_event *se = item->data_val;
1492 if(se->event_type == HLEV_EVENT_TRY_WAKEUP) {
1493 /* FIXME: should change hlev event from BLOCKED to INTERRUPTED CPU when receiving TRY_WAKEUP */
1494 struct try_wakeup_event *twe = se->private;
1495
1496 /* FIXME: maybe do some more rigorous checking here */
1497 if(pinfo->hlev_state->bstate == HLEV_BLOCKED) {
1498 struct hlev_state_info_blocked *hlev_blocked_private = pinfo->hlev_state->private;
1499
1500 hlev_blocked_private->pid_exit = twe->pid;
1501 hlev_blocked_private->time_woken = twe->time;
1502 hlev_blocked_private->llev_state_exit = oldstyle_stack_to_garray(twe->waker->llev_state_stack, twe->waker->stack_current);
1503 //printf("set a non null exit stack on %p, and stack size is %d\n", hlev_blocked_private, hlev_blocked_private->llev_state_exit->len);
1504
1505 /*
1506 if(p->stack_current >= 0 && p->llev_state_stack[p->stack_current]->bstate == LLEV_PREEMPTED) {
1507 old_process_pop_llev_state(pinfo, p->llev_state_stack[p->stack_current]);
1508 update_hlev_state(pinfo
1509 old_process_push_llev_state
1510 }*/
1511
1512 }
1513 }
1514 }
1515
1516 //printf("stack after:\n");
1517 //print_stack(pinfo->stack);
1518 }
1519
1520 static struct process *get_or_init_process_info(struct LttEvent *e, GQuark name, int pid, int *new)
1521 {
1522 gconstpointer val;
1523
1524 val = g_hash_table_lookup(process_hash_table, &pid);
1525 if(val == NULL) {
1526 struct process *pinfo;
1527 int i;
1528
1529 /* Initialize new pinfo for newly discovered process */
1530 pinfo = g_malloc(sizeof(struct process));
1531 pinfo->pid = pid;
1532 pinfo->parent = -1; /* unknown parent */
1533 pinfo->hlev_history = g_array_new(FALSE, FALSE, sizeof(struct process_state *));
1534 pinfo->stack = sstack_new();
1535 pinfo->stack_current=-1;
1536 pinfo->stack->process_func = process_delayed_stack_action;
1537 pinfo->stack->process_func_arg = pinfo;
1538 for(i=0; i<PROCESS_STATE_STACK_SIZE; i++) {
1539 pinfo->llev_state_stack[i] = g_malloc(sizeof(struct process_state));
1540 }
1541
1542 pinfo->hlev_state = g_malloc(sizeof(struct process_state));
1543 pinfo->hlev_state->bstate = HLEV_UNKNOWN;
1544 pinfo->hlev_state->time_begin = e->event_time;
1545 pinfo->hlev_state->private = NULL;
1546
1547 /* set the name */
1548 pinfo->name = name;
1549
1550 g_hash_table_insert(process_hash_table, &pinfo->pid, pinfo);
1551 if(new)
1552 *new = 1;
1553 return pinfo;
1554 }
1555 else {
1556 if(new)
1557 *new = 0;
1558 return val;
1559
1560 }
1561 }
1562
1563 static int differentiate_swappers(int pid, LttEvent *e)
1564 {
1565 if(pid == 0)
1566 return pid+e->tracefile->cpu_num+2000000;
1567 else
1568 return pid;
1569 }
1570
1571 static int process_event(void *hook_data, void *call_data)
1572 {
1573 LttvTracefileContext *tfc = (LttvTracefileContext *)call_data;
1574 LttvTracefileState *tfs = (LttvTracefileState *)call_data;
1575 LttEvent *e;
1576 struct marker_info *info;
1577
1578 /* Extract data from event structures and state */
1579 guint cpu = tfs->cpu;
1580 LttvTraceState *ts = (LttvTraceState*)tfc->t_context;
1581 LttvProcessState *process = ts->running_process[cpu];
1582 LttTrace *trace = ts->parent.t;
1583 struct process *pinfo;
1584
1585 e = ltt_tracefile_get_event(tfs->parent.tf);
1586
1587 info = marker_get_info_from_id(tfc->tf->mdata, e->event_id);
1588
1589 //if(depanalysis_use_time && (ltt_time_compare(e->timestamp, arg_t1) == -1 || ltt_time_compare(e->timestamp, arg_t2) == 1)) {
1590 // return;
1591 //}
1592 /* Set the pid for the dependency analysis at each event, until we are passed the range. */
1593 if(depanalysis_use_time == 3) {
1594 if(ltt_time_compare(e->event_time, depanalysis_time2) <= 0) {
1595 depanalysis_range_pid = process->pid;
1596 }
1597 else {
1598 /* Should stop processing and print results */
1599 }
1600 }
1601
1602 /* Code to limit the event count */
1603 if(depanalysis_event_limit > 0) {
1604 depanalysis_event_limit--;
1605 }
1606 else if(depanalysis_event_limit == 0) {
1607 write_traceset_footer(hook_data, call_data);
1608 printf("exit due to event limit reached\n");
1609 exit(0);
1610 }
1611
1612 /* write event like textDump for now, for debugging purposes */
1613 //write_event_content(hook_data, call_data);
1614
1615 if(tfc->tf->name == LTT_CHANNEL_SYSCALL_STATE && info->name == LTT_EVENT_SYS_CALL_TABLE) {
1616 GQuark q;
1617 int *pint = g_malloc(sizeof(int));
1618
1619 *pint = field_get_value_int(e, info, LTT_FIELD_ID);
1620 q = g_quark_from_string(field_get_value_string(e, info, LTT_FIELD_SYMBOL));
1621 g_hash_table_insert(syscall_table, pint, q);
1622 }
1623 else if(tfc->tf->name == LTT_CHANNEL_IRQ_STATE && info->name == LTT_EVENT_LIST_INTERRUPT) {
1624 GQuark q;
1625 int *pint = g_malloc(sizeof(int));
1626
1627 *pint = field_get_value_int(e, info, LTT_FIELD_IRQ_ID);
1628 q = g_quark_from_string(field_get_value_string(e, info, LTT_FIELD_ACTION));
1629 g_hash_table_insert(irq_table, pint, q);
1630 }
1631 else if(tfc->tf->name == LTT_CHANNEL_SOFTIRQ_STATE && info->name == LTT_EVENT_SOFTIRQ_VEC) {
1632 GQuark q;
1633 int *pint = g_malloc(sizeof(int));
1634
1635 *pint = field_get_value_int(e, info, LTT_FIELD_ID);
1636 q = g_quark_from_string(field_get_value_string(e, info, LTT_FIELD_SYMBOL));
1637 g_hash_table_insert(softirq_table, pint, q);
1638 }
1639
1640
1641 /* Only look at events after the statedump is finished.
1642 * Before that, the pids in the LttvProcessState are not reliable
1643 */
1644 if(statedump_finished == 0) {
1645 if(tfc->tf->name == LTT_CHANNEL_GLOBAL_STATE && info->name == LTT_EVENT_STATEDUMP_END)
1646 statedump_finished = 1;
1647 else
1648 return FALSE;
1649
1650 }
1651
1652 pinfo = get_or_init_process_info(e, process->name, differentiate_swappers(process->pid, e), NULL);
1653
1654 /* the state machine
1655 * Process the event in the context of each process
1656 */
1657
1658 if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_IRQ_ENTRY) {
1659 struct process *event_process_info = pinfo;
1660 struct sstack_item *item;
1661
1662 item = prepare_push_item(event_process_info, LLEV_IRQ, e->event_time);
1663 ((struct llev_state_info_irq *) item_private(item))->irq = field_get_value_int(e, info, LTT_FIELD_IRQ_ID);
1664 commit_item(event_process_info, item);
1665 }
1666 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_IRQ_EXIT) {
1667 struct process *event_process_info = pinfo;
1668
1669 prepare_pop_item_commit(event_process_info, LLEV_IRQ, e->event_time);
1670 }
1671 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_SCHED_SCHEDULE) {
1672 int next_pid = field_get_value_int(e, info, LTT_FIELD_NEXT_PID);
1673 int prev_pid = field_get_value_int(e, info, LTT_FIELD_PREV_PID);
1674 if(next_pid != 0) {
1675 struct process *event_process_info = get_or_init_process_info(e, process->name, differentiate_swappers(next_pid, e), NULL);
1676 prepare_pop_item_commit(event_process_info, LLEV_PREEMPTED, e->event_time);
1677 }
1678 if(prev_pid != 0) {
1679 struct sstack_item *item;
1680 struct process *event_process_info = get_or_init_process_info(e, process->name, differentiate_swappers(prev_pid, e), NULL);
1681
1682 item = prepare_push_item(event_process_info, LLEV_PREEMPTED, e->event_time);
1683 ((struct llev_state_info_preempted *) item_private(item))->prev_state = field_get_value_int(e, info, LTT_FIELD_PREV_STATE);
1684 commit_item(event_process_info, item);
1685 }
1686 }
1687 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_TRAP_ENTRY) {
1688 struct process *event_process_info = pinfo;
1689 struct sstack_item *item;
1690
1691 item = prepare_push_item(event_process_info, LLEV_TRAP, e->event_time);
1692 commit_item(event_process_info, item);
1693 }
1694 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_TRAP_EXIT) {
1695 struct process *event_process_info = pinfo;
1696
1697 prepare_pop_item_commit(event_process_info, LLEV_TRAP, e->event_time);
1698 }
1699 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_SYSCALL_ENTRY) {
1700 struct process *event_process_info = pinfo;
1701 struct sstack_item *item;
1702
1703 item = prepare_push_item(event_process_info, LLEV_SYSCALL, e->event_time);
1704 ((struct llev_state_info_syscall *) item_private(item))->syscall_id = field_get_value_int(e, info, LTT_FIELD_SYSCALL_ID);
1705 ((struct llev_state_info_syscall *) item_private(item))->substate = LLEV_SYSCALL__UNDEFINED;
1706 commit_item(event_process_info, item);
1707 }
1708 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_SYSCALL_EXIT) {
1709 struct process *event_process_info = pinfo;
1710
1711 prepare_pop_item_commit(event_process_info, LLEV_SYSCALL, e->event_time);
1712 }
1713 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_SOFT_IRQ_ENTRY) {
1714 struct process *event_process_info = pinfo;
1715 struct sstack_item *item;
1716
1717 item = prepare_push_item(event_process_info, LLEV_SOFTIRQ, e->event_time);
1718 ((struct llev_state_info_softirq *) item_private(item))->softirq = field_get_value_int(e, info, LTT_FIELD_SOFT_IRQ_ID);
1719 commit_item(event_process_info, item);
1720 }
1721 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_SOFT_IRQ_EXIT) {
1722 struct process *event_process_info = pinfo;
1723
1724 prepare_pop_item_commit(event_process_info, LLEV_SOFTIRQ, e->event_time);
1725 }
1726 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_PROCESS_FORK) {
1727 int pid = differentiate_swappers(field_get_value_int(e, info, LTT_FIELD_CHILD_PID), e);
1728 struct process *event_process_info = get_or_init_process_info(e, process->name, differentiate_swappers(field_get_value_int(e, info, LTT_FIELD_CHILD_PID), e), NULL);
1729 struct sstack_item *item;
1730
1731 event_process_info->parent = process->pid;
1732 //printf("At ");
1733 //print_time(e->event_time);
1734 //printf(", fork in process %d (%s), creating child %d\n", differentiate_swappers(process->pid, e), g_quark_to_string(process->name), pid);
1735
1736 item = prepare_push_item(event_process_info, LLEV_RUNNING, e->event_time);
1737 commit_item(event_process_info, item);
1738 item = prepare_push_item(event_process_info, LLEV_SYSCALL, e->event_time);
1739 /* FIXME: this sets fork() as syscall, it's pretty inelegant */
1740 ((struct llev_state_info_syscall *) item_private(item))->syscall_id = 57;
1741 ((struct llev_state_info_syscall *) item_private(item))->substate = LLEV_SYSCALL__UNDEFINED;
1742 commit_item(event_process_info, item);
1743
1744 item = prepare_push_item(event_process_info, LLEV_PREEMPTED, e->event_time);
1745 /* Consider fork as BLOCKED */
1746 ((struct llev_state_info_preempted *) item_private(item))->prev_state = 1;
1747 commit_item(event_process_info, item);
1748
1749 //printf("process %d now has a stack of height %d\n", differentiate_swappers(process->pid, e), get_or_init_process_info(e, process->name, differentiate_swappers(process->pid, cpu), NULL)->stack_current-1);
1750
1751 }
1752 else if(tfc->tf->name == LTT_CHANNEL_FS && info->name == LTT_EVENT_EXEC) {
1753 struct process *event_process_info = pinfo;
1754
1755 guint cpu = tfs->cpu;
1756 LttvProcessState *process_state = ts->running_process[cpu];
1757 event_process_info->name = process_state->name;
1758 }
1759 else if(tfc->tf->name == LTT_CHANNEL_FS && info->name == LTT_EVENT_OPEN) {
1760 struct process_state *pstate = process_find_state(pinfo, LLEV_SYSCALL);
1761 struct llev_state_info_syscall *llev_syscall_private;
1762 struct llev_state_info_syscall__open *llev_syscall_open_private;
1763
1764 /* TODO: this is too easy */
1765 if(pstate == NULL)
1766 goto next_iter;
1767
1768 llev_syscall_private = (struct llev_state_info_syscall *)pstate->private;
1769
1770 //printf("depanalysis: found an open with state %d in pid %d\n", pstate->bstate, process->pid);
1771 if(pstate->bstate == LLEV_UNKNOWN)
1772 goto next_iter;
1773
1774 g_assert(pstate->bstate == LLEV_SYSCALL);
1775 g_assert(llev_syscall_private->substate == LLEV_SYSCALL__UNDEFINED);
1776
1777 llev_syscall_private->substate = LLEV_SYSCALL__OPEN;
1778 //printf("setting substate LLEV_SYSCALL__OPEN on syscall_private %p\n", llev_syscall_private);
1779 llev_syscall_private->private = g_malloc(sizeof(struct llev_state_info_syscall__open));
1780 llev_syscall_open_private = llev_syscall_private->private;
1781
1782 llev_syscall_open_private->filename = g_quark_from_string(field_get_value_string(e, info, LTT_FIELD_FILENAME));
1783
1784 }
1785 else if(tfc->tf->name == LTT_CHANNEL_FS && info->name == LTT_EVENT_READ) {
1786 struct process_state *pstate = process_find_state(pinfo, LLEV_SYSCALL);
1787 struct llev_state_info_syscall *llev_syscall_private;
1788 struct llev_state_info_syscall__read *llev_syscall_read_private;
1789 GQuark pfileq;
1790 int fd;
1791
1792 /* TODO: this is too easy */
1793 if(pstate == NULL)
1794 goto next_iter;
1795
1796 llev_syscall_private = (struct llev_state_info_syscall *)pstate->private;
1797
1798 //printf("depanalysis: found an read with state %d in pid %d\n", pstate->bstate, process->pid);
1799 if(pstate->bstate == LLEV_UNKNOWN)
1800 goto next_iter;
1801
1802 g_assert(pstate->bstate == LLEV_SYSCALL);
1803 g_assert(llev_syscall_private->substate == LLEV_SYSCALL__UNDEFINED);
1804
1805 llev_syscall_private->substate = LLEV_SYSCALL__READ;
1806 //printf("setting substate LLEV_SYSCALL__READ on syscall_private %p\n", llev_syscall_private);
1807 llev_syscall_private->private = g_malloc(sizeof(struct llev_state_info_syscall__read));
1808 llev_syscall_read_private = llev_syscall_private->private;
1809
1810 fd = field_get_value_int(e, info, LTT_FIELD_FD);
1811 pfileq = g_hash_table_lookup(process->fds, fd);
1812 if(pfileq) {
1813 llev_syscall_read_private->filename = pfileq;
1814 }
1815 else {
1816 char *tmp;
1817 asprintf(&tmp, "Unknown filename, fd %d", fd);
1818 llev_syscall_read_private->filename = g_quark_from_string(tmp);
1819 free(tmp);
1820 }
1821 }
1822 else if(tfc->tf->name == LTT_CHANNEL_FS && info->name == LTT_EVENT_POLL_EVENT) {
1823 struct process_state *pstate = process_find_state(pinfo, LLEV_SYSCALL);
1824 struct llev_state_info_syscall *llev_syscall_private;
1825 struct llev_state_info_syscall__poll *llev_syscall_poll_private;
1826 GQuark pfileq;
1827 int fd;
1828
1829 /* TODO: this is too easy */
1830 if(pstate == NULL)
1831 goto next_iter;
1832
1833 llev_syscall_private = (struct llev_state_info_syscall *)pstate->private;
1834
1835 //printf("depanalysis: found an poll with state %d in pid %d\n", pstate->bstate, process->pid);
1836 if(pstate->bstate == LLEV_UNKNOWN)
1837 goto next_iter;
1838
1839 /* poll doesn't have a single event that gives the syscall args. instead, there can be an arbitrary
1840 * number of fs_pollfd or fd_poll_event events
1841 * We use the fd_poll_event event, which occurs for each fd that had activity causing a return of the poll()
1842 * For now we only use the first.
1843 * We should do something about this. FIXME
1844 */
1845 if(llev_syscall_private->substate == LLEV_SYSCALL__POLL)
1846 goto next_iter;
1847
1848 g_assert(pstate->bstate == LLEV_SYSCALL);
1849 g_assert(llev_syscall_private->substate == LLEV_SYSCALL__UNDEFINED);
1850
1851 llev_syscall_private->substate = LLEV_SYSCALL__POLL;
1852 //printf("setting substate LLEV_SYSCALL__POLL on syscall_private %p\n", llev_syscall_private);
1853 llev_syscall_private->private = g_malloc(sizeof(struct llev_state_info_syscall__poll));
1854 llev_syscall_poll_private = llev_syscall_private->private;
1855
1856 fd = field_get_value_int(e, info, LTT_FIELD_FD);
1857 pfileq = g_hash_table_lookup(process->fds, fd);
1858 if(pfileq) {
1859 llev_syscall_poll_private->filename = pfileq;
1860 }
1861 else {
1862 char *tmp;
1863 asprintf(&tmp, "Unknown filename, fd %d", fd);
1864 llev_syscall_poll_private->filename = g_quark_from_string(tmp);
1865 free(tmp);
1866 }
1867 }
1868 else if(tfc->tf->name == LTT_CHANNEL_KERNEL && info->name == LTT_EVENT_SCHED_TRY_WAKEUP) {
1869 struct sstack_event *se = g_malloc(sizeof(struct sstack_event));
1870 struct try_wakeup_event *twe = g_malloc(sizeof(struct try_wakeup_event));
1871 struct sstack_item *item = sstack_item_new_event();
1872 int target = field_get_value_int(e, info, LTT_FIELD_PID);
1873 struct process *target_pinfo;
1874 int result;
1875
1876 se->event_type = HLEV_EVENT_TRY_WAKEUP;
1877 se->private = twe;
1878 //printf("pushing try wake up event in context of %d\n", pinfo->pid);
1879
1880 twe->pid = differentiate_swappers(process->pid, e);
1881 twe->time = e->event_time;
1882 twe->waker = pinfo;
1883
1884 /* FIXME: the target could not yet have an entry in the hash table, we would then lose data */
1885 target_pinfo = g_hash_table_lookup(process_hash_table, &target);
1886 if(!target_pinfo)
1887 goto next_iter;
1888
1889 item->data_val = se;
1890 item->delete_data_val = (void (*)(void *))delete_data_val;
1891
1892 sstack_add_item(target_pinfo->stack, item);
1893
1894 /* Now pop the blocked schedule out of the target */
1895 result = try_pop_blocked_llev_preempted(target_pinfo, e->event_time);
1896
1897 if(result) {
1898 struct sstack_item *item;
1899 struct process *event_process_info = target_pinfo;
1900
1901 item = prepare_push_item(event_process_info, LLEV_PREEMPTED, e->event_time);
1902 ((struct llev_state_info_preempted *) item_private(item))->prev_state = -1; /* special value meaning post-block sched out */
1903 commit_item(event_process_info, item);
1904 }
1905
1906 }
1907
1908 next_iter:
1909 skip_state_machine:
1910 return FALSE;
1911 }
1912
1913 void print_sstack_private(struct sstack_item *item)
1914 {
1915 struct process_with_state *pwstate = item->data_val;
1916
1917 if(pwstate && item->data_type == SSTACK_TYPE_PUSH)
1918 printf("\tstate: %s", llev_state_infos[pwstate->state.bstate].name);
1919
1920 printf(" (");
1921 print_time(pwstate->state.time_begin);
1922 printf("-");
1923 print_time(pwstate->state.time_end);
1924 printf("\n");
1925
1926 }
1927
1928 static LttTime ltt_time_from_string(const char *str)
1929 {
1930 LttTime retval;
1931
1932 char *decdot = strchr(str, '.');
1933
1934 if(decdot) {
1935 *decdot = '\0';
1936 retval.tv_nsec = atol(decdot+1);
1937 }
1938 else {
1939 retval.tv_nsec = 0;
1940 }
1941
1942 retval.tv_sec = atol(str);
1943
1944 return retval;
1945 }
1946
1947 static void arg_t1(void *hook_data)
1948 {
1949 printf("arg_t1\n");
1950 depanalysis_use_time |= 1;
1951 depanalysis_time1 = ltt_time_from_string(arg_t1_str);
1952 }
1953
1954 static void arg_t2(void *hook_data)
1955 {
1956 depanalysis_use_time |= 2;
1957 depanalysis_time2 = ltt_time_from_string(arg_t2_str);
1958 }
1959
1960 static void arg_pid(void *hook_data)
1961 {
1962 }
1963
1964 static void arg_limit(void *hook_data)
1965 {
1966 }
1967
1968 static void init()
1969 {
1970 gboolean result;
1971
1972 print_sstack_item_data = print_sstack_private;
1973
1974 LttvAttributeValue value;
1975
1976 LttvIAttribute *attributes = LTTV_IATTRIBUTE(lttv_global_attributes());
1977
1978 a_file = stdout;
1979
1980 lttv_option_add("dep-time-start", 0, "dependency analysis time of analysis start", "time",
1981 LTTV_OPT_STRING, &arg_t1_str, arg_t1, NULL);
1982 lttv_option_add("dep-time-end", 0, "dependency analysis time of analysis end", "time",
1983 LTTV_OPT_STRING, &arg_t2_str, arg_t2, NULL);
1984 lttv_option_add("dep-pid", 0, "dependency analysis pid", "pid",
1985 LTTV_OPT_INT, &depanalysis_range_pid_searching, arg_pid, NULL);
1986 lttv_option_add("limit-events", 0, "dependency limit event count", "count",
1987 LTTV_OPT_INT, &depanalysis_event_limit, arg_limit, NULL);
1988
1989 process_hash_table = g_hash_table_new(g_int_hash, g_int_equal);
1990 syscall_table = g_hash_table_new(g_int_hash, g_int_equal);
1991 irq_table = g_hash_table_new(g_int_hash, g_int_equal);
1992 softirq_table = g_hash_table_new(g_int_hash, g_int_equal);
1993
1994 a_string = g_string_new("");
1995
1996 result = lttv_iattribute_find_by_path(attributes, "hooks/event",
1997 LTTV_POINTER, &value);
1998 g_assert(result);
1999 event_hook = *(value.v_pointer);
2000 g_assert(event_hook);
2001 lttv_hooks_add(event_hook, process_event, NULL, LTTV_PRIO_DEFAULT);
2002
2003 // result = lttv_iattribute_find_by_path(attributes, "hooks/trace/before",
2004 // LTTV_POINTER, &value);
2005 // g_assert(result);
2006 // before_trace = *(value.v_pointer);
2007 // g_assert(before_trace);
2008 // lttv_hooks_add(before_trace, write_trace_header, NULL, LTTV_PRIO_DEFAULT);
2009 //
2010 result = lttv_iattribute_find_by_path(attributes, "hooks/traceset/before",
2011 LTTV_POINTER, &value);
2012 g_assert(result);
2013 before_traceset = *(value.v_pointer);
2014 g_assert(before_traceset);
2015 lttv_hooks_add(before_traceset, write_traceset_header, NULL,
2016 LTTV_PRIO_DEFAULT);
2017
2018 result = lttv_iattribute_find_by_path(attributes, "hooks/traceset/after",
2019 LTTV_POINTER, &value);
2020 g_assert(result);
2021 after_traceset = *(value.v_pointer);
2022 g_assert(after_traceset);
2023 lttv_hooks_add(after_traceset, write_traceset_footer, NULL,
2024 LTTV_PRIO_DEFAULT);
2025 }
2026
2027 static void destroy()
2028 {
2029 lttv_option_remove("dep-time-start");
2030 lttv_option_remove("dep-time-end");
2031 lttv_option_remove("dep-pid");
2032 lttv_option_remove("limit-events");
2033
2034 g_hash_table_destroy(process_hash_table);
2035 g_hash_table_destroy(syscall_table);
2036 g_hash_table_destroy(irq_table);
2037 g_hash_table_destroy(softirq_table);
2038
2039 g_string_free(a_string, TRUE);
2040
2041 lttv_hooks_remove_data(event_hook, write_event_content, NULL);
2042 // lttv_hooks_remove_data(before_trace, write_trace_header, NULL);
2043 lttv_hooks_remove_data(before_traceset, write_traceset_header, NULL);
2044 lttv_hooks_remove_data(after_traceset, write_traceset_footer, NULL);
2045 }
2046
2047 LTTV_MODULE("depanalysis", "Dependency analysis test", \
2048 "Produce a dependency analysis of a trace", \
2049 init, destroy, "stats", "batchAnalysis", "option", "print")
2050
This page took 0.091943 seconds and 4 git commands to generate.