/** * \file profile.c * License details are found in the file LICENSE. * * \brief * Profiler code for various process statistics * \author Balazs Gerofi * Copyright (C) 2017 RIKEN AICS */ /* * HISTORY: */ #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include extern char *syscall_name[]; #ifdef PROFILE_ENABLE //#define DEBUG_PRINT_PROFILE #ifdef DEBUG_PRINT_PROFILE #define dkprintf(...) kprintf(__VA_ARGS__) #define ekprintf(...) kprintf(__VA_ARGS__) #else #define dkprintf(...) do { if (0) kprintf(__VA_ARGS__); } while (0) #define ekprintf(...) kprintf(__VA_ARGS__) #endif char *profile_event_names[] = { "page_fault", "page_fault_anon_clr_mem", "page_fault_file", "page_fault_dev_file", "page_fault_file_clr_mem", "mpol_alloc_missed", "mmap_anon_contig_phys", "mmap_anon_no_contig_phys", "mmap_regular_file", "mmap_device_file", "" }; mcs_lock_node_t job_profile_lock = {0, NULL}; struct profile_event *job_profile_events = NULL; int job_nr_processes = -1; int job_nr_processes_left = -1; enum profile_event_type profile_syscall2offload(enum profile_event_type sc) { return (PROFILE_SYSCALL_MAX + sc); } void profile_event_add(enum profile_event_type type, uint64_t tsc) { struct profile_event *event = NULL; if (!cpu_local_var(current)->profile) return; if (!cpu_local_var(current)->profile_events) { if (profile_alloc_events(cpu_local_var(current)) < 0) return; } if (type < PROFILE_EVENT_MAX) { event = &cpu_local_var(current)->profile_events[type]; } else { kprintf("%s: WARNING: unknown event type %d\n", __FUNCTION__, type); return; } ++event->cnt; event->tsc += tsc; } void profile_print_thread_stats(struct thread *thread) { int i; unsigned long flags; if (!thread->profile_events) return; flags = kprintf_lock(); for (i = 0; i < PROFILE_SYSCALL_MAX; ++i) { if (!thread->profile_events[i].cnt && !thread->profile_events[i + PROFILE_SYSCALL_MAX].cnt) continue; __kprintf("TID: %4d (%3d,%20s): %6u %6luk offl: %6u %6luk\n", thread->tid, i, syscall_name[i], thread->profile_events[i].cnt, (thread->profile_events[i].tsc / (thread->profile_events[i].cnt ? thread->profile_events[i].cnt : 1)) / 1000, thread->profile_events[i + PROFILE_SYSCALL_MAX].cnt, (thread->profile_events[i + PROFILE_SYSCALL_MAX].tsc / (thread->profile_events[i + PROFILE_SYSCALL_MAX].cnt ? thread->profile_events[i + PROFILE_SYSCALL_MAX].cnt : 1)) / 1000 ); } for (i = PROFILE_EVENT_MIN; i < PROFILE_EVENT_MAX; ++i) { if (!thread->profile_events[i].cnt) continue; __kprintf("TID: %4d (%24s): %6u %6luk \n", thread->tid, profile_event_names[i - PROFILE_EVENT_MIN], thread->profile_events[i].cnt, (thread->profile_events[i].tsc / (thread->profile_events[i].cnt ? thread->profile_events[i].cnt : 1)) / 1000); } kprintf_unlock(flags); } void profile_print_proc_stats(struct process *proc) { int i; unsigned long flags; if (!proc->profile_events) return; flags = kprintf_lock(); for (i = 0; i < PROFILE_SYSCALL_MAX; ++i) { if (!proc->profile_events[i].cnt && !proc->profile_events[i + PROFILE_SYSCALL_MAX].cnt) continue; __kprintf("PID: %4d (%3d,%20s): %6u %6luk offl: %6u %6luk\n", proc->pid, i, syscall_name[i], proc->profile_events[i].cnt, (proc->profile_events[i].tsc / (proc->profile_events[i].cnt ? proc->profile_events[i].cnt : 1)) / 1000, proc->profile_events[i + PROFILE_SYSCALL_MAX].cnt, (proc->profile_events[i + PROFILE_SYSCALL_MAX].tsc / (proc->profile_events[i + PROFILE_SYSCALL_MAX].cnt ? proc->profile_events[i + PROFILE_SYSCALL_MAX].cnt : 1)) / 1000 ); } for (i = PROFILE_EVENT_MIN; i < PROFILE_EVENT_MAX; ++i) { if (!proc->profile_events[i].cnt) continue; __kprintf("PID: %4d (%24s): %6u %6luk \n", proc->pid, profile_event_names[i - PROFILE_EVENT_MIN], proc->profile_events[i].cnt, (proc->profile_events[i].tsc / (proc->profile_events[i].cnt ? proc->profile_events[i].cnt : 1)) / 1000); } kprintf_unlock(flags); } int profile_accumulate_and_print_job_events(struct process *proc) { int i; unsigned long flags; struct mcs_lock_node mcs_node; mcs_lock_lock(&job_profile_lock, &mcs_node); /* First process? */ if (job_nr_processes == -1) { job_nr_processes = proc->nr_processes; job_nr_processes_left = proc->nr_processes; } --job_nr_processes_left; /* Allocate event counters */ if (!job_profile_events) { job_profile_events = kmalloc(sizeof(*job_profile_events) * PROFILE_EVENT_MAX, IHK_MC_AP_NOWAIT); if (!job_profile_events) { kprintf("%s: ERROR: allocating job profile counters\n", __FUNCTION__); return -ENOMEM; } memset(job_profile_events, 0, sizeof(*job_profile_events) * PROFILE_EVENT_MAX); } /* Accumulate process */ for (i = 0; i < PROFILE_EVENT_MAX; ++i) { if (!proc->profile_events[i].tsc) continue; job_profile_events[i].tsc += proc->profile_events[i].tsc; job_profile_events[i].cnt += proc->profile_events[i].cnt; proc->profile_events[i].tsc = 0; proc->profile_events[i].cnt = 0; } /* Last process? */ if (job_nr_processes_left == 0) { flags = kprintf_lock(); for (i = 0; i < PROFILE_SYSCALL_MAX; ++i) { if (!job_profile_events[i].cnt && !job_profile_events[i + PROFILE_SYSCALL_MAX].cnt) continue; __kprintf("JOB: (%2d) (%3d,%20s): %6u %6luk offl: %6u %6luk\n", job_nr_processes, i, syscall_name[i], job_profile_events[i].cnt, (job_profile_events[i].tsc / (job_profile_events[i].cnt ? job_profile_events[i].cnt : 1)) / 1000, job_profile_events[i + PROFILE_SYSCALL_MAX].cnt, (job_profile_events[i + PROFILE_SYSCALL_MAX].tsc / (job_profile_events[i + PROFILE_SYSCALL_MAX].cnt ? job_profile_events[i + PROFILE_SYSCALL_MAX].cnt : 1)) / 1000 ); job_profile_events[i].tsc = 0; job_profile_events[i].cnt = 0; job_profile_events[i + PROFILE_SYSCALL_MAX].tsc = 0; job_profile_events[i + PROFILE_SYSCALL_MAX].cnt = 0; } for (i = PROFILE_EVENT_MIN; i < PROFILE_EVENT_MAX; ++i) { if (!job_profile_events[i].cnt) continue; __kprintf("JOB: (%2d) (%24s): %6u %6luk \n", job_nr_processes, profile_event_names[i - PROFILE_EVENT_MIN], job_profile_events[i].cnt, (job_profile_events[i].tsc / (job_profile_events[i].cnt ? job_profile_events[i].cnt : 1)) / 1000); job_profile_events[i].tsc = 0; job_profile_events[i].cnt = 0; } kprintf_unlock(flags); /* Reset job process indicators */ job_nr_processes = -1; job_nr_processes_left = -1; } mcs_lock_unlock(&job_profile_lock, &mcs_node); return 0; } void profile_accumulate_events(struct thread *thread, struct process *proc) { int i; struct mcs_lock_node mcs_node; if (!thread->profile_events || !proc->profile_events) return; mcs_lock_lock(&proc->profile_lock, &mcs_node); for (i = 0; i < PROFILE_EVENT_MAX; ++i) { proc->profile_events[i].tsc += thread->profile_events[i].tsc; proc->profile_events[i].cnt += thread->profile_events[i].cnt; thread->profile_events[i].tsc = 0; thread->profile_events[i].cnt = 0; } mcs_lock_unlock(&proc->profile_lock, &mcs_node); } int profile_alloc_events(struct thread *thread) { struct process *proc = thread->proc; struct mcs_lock_node mcs_node; if (!thread->profile_events) { thread->profile_events = kmalloc(sizeof(*thread->profile_events) * PROFILE_EVENT_MAX, IHK_MC_AP_NOWAIT); if (!thread->profile_events) { kprintf("%s: ERROR: allocating thread private profile counters\n", __FUNCTION__); return -ENOMEM; } memset(thread->profile_events, 0, sizeof(*thread->profile_events) * PROFILE_EVENT_MAX); } mcs_lock_lock(&proc->profile_lock, &mcs_node); if (!proc->profile_events) { proc->profile_events = kmalloc(sizeof(*proc->profile_events) * PROFILE_EVENT_MAX, IHK_MC_AP_NOWAIT); if (!proc->profile_events) { kprintf("%s: ERROR: allocating proc private profile counters\n", __FUNCTION__); mcs_lock_unlock(&proc->profile_lock, &mcs_node); return -ENOMEM; } memset(proc->profile_events, 0, sizeof(*thread->profile_events) * PROFILE_EVENT_MAX); } mcs_lock_unlock(&proc->profile_lock, &mcs_node); return 0; } void profile_dealloc_thread_events(struct thread *thread) { kfree(thread->profile_events); } void profile_dealloc_proc_events(struct process *proc) { kfree(proc->profile_events); } void static profile_clear_process(struct process *proc) { if (!proc->profile_events) return; memset(proc->profile_events, 0, sizeof(*proc->profile_events) * PROFILE_EVENT_MAX); } void static profile_clear_thread(struct thread *thread) { if (!thread->profile_events) return; memset(thread->profile_events, 0, sizeof(*thread->profile_events) * PROFILE_EVENT_MAX); } int do_profile(int flag) { struct thread *thread = cpu_local_var(current); struct process *proc = thread->proc; /* Job level? */ if (flag & PROF_JOB) { dkprintf("%s: JOB %d, flag: 0x%lx\n", __FUNCTION__, proc->nr_processes, flag); if (flag & PROF_PRINT) { struct mcs_rwlock_node lock; struct thread *_thread; /* Accumulate events from all threads to process level */ mcs_rwlock_reader_lock_noirq(&proc->threads_lock, &lock); list_for_each_entry(_thread, &proc->threads_list, siblings_list) { profile_accumulate_events(_thread, proc); } mcs_rwlock_reader_unlock_noirq(&proc->threads_lock, &lock); /* Accumulate events to job level */ return profile_accumulate_and_print_job_events(proc); } } /* Process level? */ else if (flag & PROF_PROC) { struct mcs_rwlock_node lock; struct thread *_thread; dkprintf("%s: PID %d, flag: 0x%lx\n", __FUNCTION__, proc->pid, flag); /* Accumulate events from all threads */ mcs_rwlock_reader_lock_noirq(&proc->threads_lock, &lock); list_for_each_entry(_thread, &proc->threads_list, siblings_list) { if (flag & PROF_PRINT) { profile_accumulate_events(_thread, proc); } if (flag & PROF_CLEAR) { profile_clear_thread(_thread); } if (flag & PROF_ON) { _thread->profile = 1; } else if (flag & PROF_OFF) { _thread->profile = 0; } } mcs_rwlock_reader_unlock_noirq(&proc->threads_lock, &lock); if (flag & PROF_PRINT) { profile_print_proc_stats(proc); } if (flag & PROF_CLEAR) { profile_clear_process(proc); } /* Make sure future threads profile as well */ if (flag & PROF_ON) { proc->profile = 1; } else if (flag & PROF_OFF) { proc->profile = 0; } } /* Thread level */ else { dkprintf("%s: TID %d, flag: 0x%lx\n", __FUNCTION__, thread->tid, flag); if (flag & PROF_PRINT) { profile_print_thread_stats(thread); } if (flag & PROF_CLEAR) { profile_clear_thread(thread); } if (flag & PROF_ON) { thread->profile = 1; } else if (flag & PROF_OFF) { thread->profile = 0; } } return 0; } SYSCALL_DECLARE(profile) { int flag = (int)ihk_mc_syscall_arg0(ctx); return do_profile(flag); } #endif // PROFILE_ENABLE