#include #include #include #include #include #include #include #include #include #include #include #include /* This code is licensed under the GPL version 2 * You'll find a copy on http://www.gnu.org/copyleft/gpl.html * * Author: Thomas Renninger (mail@renninger.de) * Copyright: Thomas Renninger - 2005, SuSE Linux GmbH/Novell AG */ /* Buffer size must be the same as defined * in kernel */ #define LOGGER_BUF 1024 /* Define polling interval here (us). If dynamic timer tick is enabled polling of about 5 seconds should be enough. If a HZ value of 1000 is running you should poll about each 100ms. */ #define SLEEP_TIME 500000 /* If time is calculated based on TSC in the kernel * you have to enable this one (measures are probably * wrong if entering C3 and deeper, it's mainly for * verifying whether the timeing works. * Adjust the freq_*Hz values to your machine's frequency */ //#define TSC_TIME 1 #ifdef TSC_TIME static unsigned long freq_HZ = 800*1000*1000; static unsigned long freq_KHz = 800*1000; static unsigned long freq_MHz = 800; #endif /* Device configuration. I use /dev/cpu/X/cst to catch * the debug/logging output from the kernel per cpu * The amount of cpu's depends on the amount of directories * in /proc/acpi/processor */ #define DEV_MAJOR 242 const static char *device_dir = "/dev/cpu"; const static char *device_name = "cst"; const static char *acpi_proc_dir = "/proc/acpi/processor/"; #define DEBUG 1 #ifdef DEBUG #define myPrint(string, args...) printf(""string, ##args); #else #define myPrint(string, args...) {}; #endif #define myError(string, args...) if(1) { \ fprintf(stderr, "ERROR in Function %s - line %d - errno: %s\n" \ string, __FUNCTION__, __LINE__, strerror(errno), ##args); \ exit(255); \ } #define MAX_C_STATES 8 typedef struct c_result_struct{ unsigned long long total_time; unsigned long max_time; unsigned long avg_time; unsigned long usage; unsigned long failed; }c_result_struct; static c_result_struct c_state_results[MAX_C_STATES] = {{0,0,0,0,0},}; static unsigned long total_switches = 0; static int get_cpus_online(); static time_t start; static time_t end; typedef struct c_logger_struct{ uint8_t c_state; unsigned long time_used; int bm_activity; }c_logger_struct; static int cpus; static int full = 0; /* return amount of logged c-state changes */ int get_c_state_logs(char *filename, c_logger_struct *c_logger){ int fd, x; c_logger_struct *c_logger_tmp; int err = 0; fd = open(filename, O_RDONLY); if (fd < 0){ myError("Could not open file %s\n", filename); } err = read (fd, c_logger, sizeof(c_logger_struct) * LOGGER_BUF); if (err < 0){ myError("Could not read from device %s\n", filename); } if (err % sizeof(c_logger_struct) != 0){ myError("Read %d bytes, seems not to be a c_logger_struct - modulo: %d\n", err, (int)(err % sizeof(c_logger_struct))); } // If transition fails (or because inaccurate measures) // time stayed in C-state could be ((unsigned long) -1) // correct it here to 0 and increment failed transitions. c_logger_tmp = c_logger; for (x = 0; x < (err/sizeof(c_logger_struct)) && x < LOGGER_BUF; x++){ if (c_logger_tmp->time_used == (unsigned long) -1){ c_state_results[c_logger_tmp->c_state].failed++; c_logger_tmp->time_used = 0; } myPrint ("%04d - %d - %10lu\t - %08X\n", x, c_logger_tmp->c_state, c_logger_tmp->time_used, c_logger_tmp->bm_activity); c_logger_tmp++; } close(fd); return err/sizeof(c_logger_struct); } int calc_c_state_stats(const c_logger_struct *c_state_logs, int states){ int x; const c_logger_struct *c_state_temp = c_state_logs; unsigned long long total_measure_time[MAX_C_STATES] = {0,}; for (x = 0; x < LOGGER_BUF && c_state_temp != NULL && x < states;x++){ /* cmp. with uint8_t does not work here, prog just exits ? if (c_state_temp->c_state > MAX_C_STATES) myError ("Logged c-state exceeds MAX_C_STATES"); */ if (c_state_temp->time_used > c_state_results[c_state_temp->c_state].max_time) c_state_results[c_state_temp->c_state].max_time = c_state_temp->time_used; total_measure_time[c_state_temp->c_state] += c_state_temp->time_used; c_state_results[c_state_temp->c_state].usage++; c_state_temp++; total_switches++; /* avg_time calculated outside when all measurements are added */ } for (x = 0; x < MAX_C_STATES;x++){ #ifdef TSC_TIME /* shift total_time to not overflow too quickly */ c_state_results[x].total_time += (total_measure_time[x] >> 16); #else c_state_results[x].total_time += total_measure_time[x]; #endif } return 0; } void exit_handler(int sig){ int x; end = time(NULL); double diff = difftime(end, start); unsigned long long total_measure_time = 0; unsigned long total_cstate = 0, max = 0, total_measure_sec = 0; float avg = 0; for (x = 0; x < MAX_C_STATES; x++){ if (!c_state_results[x].total_time) continue; if (x == 0) printf ("Active C0/C1 state:\n"); else printf ("Sleep C%d state:\n", x); #ifdef TSC_TIME total_cstate = c_state_results[x].total_time/(freq_KHz >> 16); max = c_state_results[x].max_time/freq_MHz; #else /* (3.579 ticks per us) */ total_cstate = c_state_results[x].total_time/3579; max = c_state_results[x].max_time/3.6; #endif if (c_state_results[x].usage) avg = (total_cstate * 1000)/c_state_results[x].usage; printf ("Total(ms): %lu\n", (total_cstate)); printf ("Usage: %lu\n", c_state_results[x].usage); printf ("Failures: %lu\n", c_state_results[x].failed); printf ("Maximum(us): %lu\n", max); printf ("Average(us): %.f\n", avg); total_measure_time += c_state_results[x].total_time; } #ifdef TSC_TIME total_measure_sec = total_measure_time/(freq_HZ >> 16); printf ("Measures based on TSC reads\n\n"); #else total_measure_sec = total_measure_time/3579000; printf ("Measures based on ACPI PM timer reads\n\n"); #endif printf ("Total switches between C-states: %lu\n", total_switches/2); if (total_measure_sec) printf ("Average switches between C-states per second: %lu per second\n", total_switches/(total_measure_sec * 2)); printf ("Total measure time (s): %lu\n", total_measure_sec); printf ("Total measure time (based on starting measures) (s): %.0f\n\n", diff); if (full) printf ("Buffer was full, values could be missing. Time will be inacurate.\n"); #ifdef DEBUG if (sig > 0) #endif exit (0); } /* Returns the device name for a cpu * e.g. /dev/cpu/0/cst */ int get_cpu_device_name(int cpu, char *buffer, int buf_length){ char *device_cpu_dir; if (cpu > cpus) return -1; device_cpu_dir = malloc(sizeof(char) * buf_length); snprintf(device_cpu_dir, buf_length-1, "%s/%d", device_dir, cpu); snprintf(buffer, buf_length-1, "%s/%d/%s", device_dir, cpu, device_name); free (device_cpu_dir); return 0; } int get_cpus_online(){ DIR *cpu_dir; struct dirent *cpu_dirs; cpus = 0; cpu_dir = opendir(acpi_proc_dir); if (cpu_dirs == NULL) myError("Cannot open dir %s\n", acpi_proc_dir); for (cpu_dirs = readdir(cpu_dir); cpu_dirs != NULL; cpu_dirs = readdir(cpu_dir)){ if (cpu_dirs->d_name[0] == '.') continue; else cpus++; } closedir(cpu_dir); // . and .. are also directory entries return cpus; } void setup_device_nodes(){ int x; char device_file[31] = ""; char device_cpu_dir[31] = ""; if (cpus < 1){ myError("Could not detect a CPU. Make sure the" "acpi processor module is loaded.\n"); } struct stat buf; if (stat(device_dir, &buf)){ if (mkdir (device_dir, 0755)){ myError("Could not create directory %s\n", device_dir); } } for (x = 0; x < cpus; x++){ snprintf(device_cpu_dir, 30, "%s/%d", device_dir, x); snprintf(device_file, 30, "%s/%d/%s", device_dir, x, device_name); if (stat(device_cpu_dir, &buf)){ if (mkdir (device_cpu_dir, 0755)){ myError("Could not create directory %s\n", device_cpu_dir); } } if (stat(device_file, &buf)){ if (mknod (device_file, 0666 | S_IFCHR, makedev(DEV_MAJOR, 0))){ myError("Could not create character device %s\n", device_file); } else{ myPrint ("Creating character device %s" " successfully.\n", device_file); } } else if (!S_ISCHR(buf.st_mode)){ myError("%s does already exist, " "but is no block device.\n", device_file); } else{ myPrint ("Character device %s" " already exists.\n", device_file); } } } int main (int argc, char **argv){ int x, err = 0; signal (SIGTERM, exit_handler); signal (SIGQUIT, exit_handler); signal (SIGINT, exit_handler); char device_file[31] = ""; c_logger_struct c_state_logs[LOGGER_BUF] = {{0,0,0},}; cpus = get_cpus_online(); setup_device_nodes(); // throw away old buffered data from kernel... for (x = 0; x < cpus; x++){ get_cpu_device_name(x, device_file, 30); err = get_c_state_logs(device_file, c_state_logs); } memset(c_state_logs, 0, sizeof(c_state_logs)); start = time (NULL); while(1){ for (x = 0; x < cpus; x++){ get_cpu_device_name(x, device_file, 30); err = get_c_state_logs(device_file, c_state_logs); if (err == LOGGER_BUF){ myPrint("Buffer run full. This may happen" "on high HZ values or when C states" "are switched very often. Increase" "the buffer to get accurate measures.\n" "Current Buffer size: %d\n", LOGGER_BUF); } err = calc_c_state_stats(c_state_logs, err); } #ifdef DEBUG // only invoked in debug case -> prints out current log summary exit_handler(-1); #endif usleep(SLEEP_TIME); } return err; }