diff options
author | Dave Barach <dave@barachs.net> | 2016-02-11 19:28:19 -0500 |
---|---|---|
committer | Gerrit Code Review <gerrit@fd.io> | 2016-02-12 01:30:48 +0000 |
commit | 52642c3c535128cb96489fed45327bdd55953397 (patch) | |
tree | ce6e2cc9f505fbf04acbc9109adb4c204fb96c8c /perftool/cpelstate.c | |
parent | 3640d537e1c1ea7670b98f0aaf27a48c08984893 (diff) |
Performance tools, initial check-in
Change-Id: I9fb4f4babecbe02d171f38c4d089634e90141937
Signed-off-by: Dave Barach <dave@barachs.net>
Diffstat (limited to 'perftool/cpelstate.c')
-rw-r--r-- | perftool/cpelstate.c | 822 |
1 files changed, 822 insertions, 0 deletions
diff --git a/perftool/cpelstate.c b/perftool/cpelstate.c new file mode 100644 index 00000000000..3fd9ccb9c79 --- /dev/null +++ b/perftool/cpelstate.c @@ -0,0 +1,822 @@ +/* + *------------------------------------------------------------------ + * Copyright (c) 2006-2016 Cisco and/or its affiliates. + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at: + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include <stdio.h> +#include <stdlib.h> +#include <netinet/in.h> +#include <string.h> +#include <sys/types.h> +#include <sys/stat.h> +#include <fcntl.h> +#include <sys/fcntl.h> +#include <sys/mman.h> +#include <unistd.h> +#include <ctype.h> +#include <vppinfra/clib.h> +#include <vppinfra/vec.h> +#include <vppinfra/hash.h> +#include <pwd.h> +#include <stdarg.h> +#include <time.h> +#include "cpel.h" +#include <math.h> + +char *time_format = "%.03d:%.02d:%.02d:%.03d:%.03d "; +static char version[] = "cpelstate 2.0h"; + +#define USEC_PER_MS 1000LL +#define USEC_PER_SECOND (1000*USEC_PER_MS) +#define USEC_PER_MINUTE (60*USEC_PER_SECOND) +#define USEC_PER_HOUR (60*USEC_PER_MINUTE) + +uword *the_strtab_hash; /* (name, base-VA) hash of all string tables */ +uword *the_evtdef_hash; /* (event-id, event-definition) hash */ +uword *the_trackdef_hash; /* (track-id, track-definition) hash */ + +f64 ticks_per_us; +u32 state_event_code = 1; /* default: XR thread-on-cpu */ +int exclude_kernel_from_summary_stats=1; +int summary_stats_only; +int scatterplot; +u8 *name_filter; + +typedef enum { + SORT_MAX_TIME=1, + SORT_MAX_OCCURRENCES, + SORT_NAME, +} sort_t; + +sort_t sort_type = SORT_MAX_TIME; + +int widest_name_format=5; +int widest_track_format=5; + +typedef struct bound_event_ { + u32 event_code; + u8 *event_str; + u8 *datum_str; + u32 is_strtab_ref; +} bound_event_t; + +bound_event_t *bound_events; + +typedef struct bound_track_ { + u32 track; + u8 *track_str; + u64 *ticks_in_state; /* vector of state occurrences */ + f64 mean_ticks_in_state; + f64 variance_ticks_in_state; + f64 total_ticks_in_state; +} bound_track_t; + +bound_track_t *bound_tracks; + +void fatal(char *s) +{ + fprintf(stderr, "%s", s); + exit(1); +} + +typedef enum { + PASS1=1, + PASS2=2, +} pass_t; + +typedef struct { + int (*pass1)(cpel_section_header_t *, int, FILE *); + int (*pass2)(cpel_section_header_t *, int, FILE *); +} section_processor_t; + +int bad_section(cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + fprintf(ofp, "Bad (type 0) section, skipped...\n"); + return(0); +} + +int noop_pass(cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + return(0); +} + +int strtab_pass1(cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + uword *p; + u8 *strtab_data_area = (u8 *)(sh+1); + + /* Multiple string tables with the same name are Bad... */ + p = hash_get_mem(the_strtab_hash, strtab_data_area); + if (p) { + fprintf(ofp, "Duplicate string table name %s", strtab_data_area); + } + /* + * Looks funny, but we really do want key = first string in the + * table, value = address(first string in the table) + */ + hash_set_mem(the_strtab_hash, strtab_data_area, strtab_data_area); + if (verbose) { + fprintf(ofp, "String Table %s\n", strtab_data_area); + } + return(0); +} + +int evtdef_pass1(cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + int i, nevents; + event_definition_section_header_t *edh; + event_definition_t *ep; + u8 *this_strtab; + u32 event_code; + uword *p; + bound_event_t *bp; + int thislen; + + edh = (event_definition_section_header_t *)(sh+1); + nevents = ntohl(edh->number_of_event_definitions); + + if (verbose) { + fprintf(ofp, "Event Definition Section: %d definitions\n", + nevents); + } + + p = hash_get_mem(the_strtab_hash, edh->string_table_name); + if (!p) { + fprintf(ofp, "Fatal: couldn't find string table\n"); + return(1); + } + this_strtab = (u8 *)p[0]; + + ep = (event_definition_t *)(edh+1); + + for (i = 0; i < nevents; i++) { + event_code = ntohl(ep->event); + p = hash_get(the_evtdef_hash, event_code); + if (p) { + fprintf(ofp, "Event %d redefined, retain first definition\n", + event_code); + continue; + } + vec_add2(bound_events, bp, 1); + bp->event_code = event_code; + bp->event_str = this_strtab + ntohl(ep->event_format); + bp->datum_str = this_strtab + ntohl(ep->datum_format); + bp->is_strtab_ref = 0; + /* Decide if the datum format is a %s format => strtab reference */ + { + int j; + int seen_percent=0; + + for (j = 0; j < strlen((char *)(bp->datum_str)); j++) { + if (bp->datum_str[j] == '%'){ + seen_percent=1; + continue; + } + if (seen_percent && bp->datum_str[j] == 's') { + bp->is_strtab_ref = 1; + } + } + } + + hash_set(the_evtdef_hash, event_code, bp - bound_events); + + thislen = strlen((char *)bp->event_str); + if (thislen > widest_name_format) + widest_name_format = thislen; + + ep++; + } + return (0); +} + +int trackdef_pass1(cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + int i, nevents; + track_definition_section_header_t *tdh; + track_definition_t *tp; + u8 *this_strtab; + u32 track_code; + uword *p; + bound_track_t *btp; + int thislen; + + tdh = (track_definition_section_header_t *)(sh+1); + nevents = ntohl(tdh->number_of_track_definitions); + + if (verbose) { + fprintf(ofp, "Track Definition Section: %d definitions\n", + nevents); + } + + p = hash_get_mem(the_strtab_hash, tdh->string_table_name); + if (!p) { + fprintf(ofp, "Fatal: couldn't find string table\n"); + return(1); + } + this_strtab = (u8 *)p[0]; + + tp = (track_definition_t *)(tdh+1); + + for (i = 0; i < nevents; i++) { + track_code = ntohl(tp->track); + p = hash_get(the_trackdef_hash, track_code); + if (p) { + fprintf(ofp, "track %d redefined, retain first definition\n", + track_code); + continue; + } + vec_add2(bound_tracks, btp, 1); + btp->track = track_code; + btp->track_str = this_strtab + ntohl(tp->track_format); + hash_set(the_trackdef_hash, track_code, btp - bound_tracks); + + thislen = strlen((char *)(btp->track_str)); + if (thislen > widest_track_format) + widest_track_format = thislen; + tp++; + } + return (0); +} + +int unsupported_pass (cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + if (verbose) { + fprintf(ofp, "Unsupported type %d section\n", + ntohl(sh->section_type)); + } + return(0); +} + +int event_pass2(cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + event_section_header_t *eh; + u32 track_code; + int nevents; + int i; + uword *p; + event_entry_t *ep; + u64 now; + u32 time0, time1; + bound_track_t generic_track; + u32 last_track_code; + u64 state_start_ticks=0; + u64 ticks_in_state; + bound_track_t *state_track=0; + int in_state=0; + generic_track.track_str = (u8 *) "%d"; + last_track_code = 0xdeafbeef; + + eh = (event_section_header_t *)(sh+1); + nevents = ntohl(eh->number_of_events); + ticks_per_us = ((double)ntohl(eh->clock_ticks_per_second))/1e6; + + if (verbose) { + fprintf(ofp, "%.3f ticks_per_us\n", ticks_per_us); + } + + ep = (event_entry_t *)(eh+1); + + p = hash_get_mem(the_strtab_hash, eh->string_table_name); + if (!p) { + fprintf(ofp, "Fatal: couldn't find string table\n"); + return(1); + } + + for (i = 0; i < nevents; i++) { + time0 = ntohl (ep->time[0]); + time1 = ntohl (ep->time[1]); + + now = (((u64) time0)<<32) | time1; + + /* Found the state-change event ? */ + if (ntohl(ep->event_code) == state_event_code) { + /* + * Add a ticks-in-state record, unless + * this is the "prime mover" event instance + */ + if (in_state) { + ticks_in_state = now - state_start_ticks; + vec_add1(state_track->ticks_in_state, ticks_in_state); + } + /* switch to now-current track */ + state_start_ticks = now; + track_code = ntohl(ep->track); + if (track_code != last_track_code) { + p = hash_get(the_trackdef_hash, track_code); + if (p) { + state_track = &bound_tracks[p[0]]; + } else { + state_track = &generic_track; + } + last_track_code = track_code; + } + in_state = 1; + } + ep++; + } + return(0); +} + +/* + * Note: If necessary, add passes / columns to this table to + * handle section order dependencies. + */ + +section_processor_t processors[CPEL_NUM_SECTION_TYPES+1] = +{ + {bad_section, noop_pass}, /* type 0 -- f**ked */ + {strtab_pass1, noop_pass}, /* type 1 -- STRTAB */ + {unsupported_pass, noop_pass}, /* type 2 -- SYMTAB */ + {evtdef_pass1, noop_pass}, /* type 3 -- EVTDEF */ + {trackdef_pass1, noop_pass}, /* type 4 -- TRACKDEF */ + {noop_pass, event_pass2}, /* type 5 -- EVENTS */ +}; + + +int process_section(cpel_section_header_t *sh, int verbose, FILE *ofp, + pass_t pass) +{ + u32 type; + type = ntohl(sh->section_type); + int rv; + int (*fp)(cpel_section_header_t *, int, FILE *); + + if (type > CPEL_NUM_SECTION_TYPES) { + fprintf(stderr, "Unknown section type %d\n", type); + return(1); + } + switch(pass) { + case PASS1: + fp = processors[type].pass1; + break; + + case PASS2: + fp = processors[type].pass2; + break; + + default: + fprintf(stderr, "Unknown pass %d\n", pass); + return(1); + } + + rv = (*fp)(sh, verbose, ofp); + + return(rv); +} + +int cpel_dump_file_header(cpel_file_header_t *fh, int verbose, FILE *ofp) +{ + time_t file_time; + + if (verbose) { + fprintf(ofp, "CPEL file: %s-endian, version %d\n", + ((fh->endian_version & CPEL_FILE_LITTLE_ENDIAN) ? + "little" : "big"), + fh->endian_version & CPEL_FILE_VERSION_MASK); + + file_time = ntohl(fh->file_date); + + fprintf(ofp, "File created %s", ctime(&file_time)); + fprintf(ofp, "File has %d sections\n", + ntohs(fh->nsections)); + } + + return(0); +} + + +int cpel_dump(u8 *cpel, int verbose, FILE *ofp) +{ + cpel_file_header_t *fh; + cpel_section_header_t *sh; + u16 nsections; + u32 section_size; + int i; + + /* First, the file header */ + fh = (cpel_file_header_t *)cpel; + if (fh->endian_version != CPEL_FILE_VERSION) { + if (fh->endian_version & CPEL_FILE_LITTLE_ENDIAN) { + fprintf(stderr, "Little endian data format not supported\n"); + return(1); + } + fprintf(stderr, "Unsupported file version 0x%x\n", + fh->endian_version); + return(1); + } + cpel_dump_file_header(fh, verbose, ofp); + nsections = ntohs(fh->nsections); + + /* + * Take two passes through the file. PASS1 builds + * data structures, PASS2 actually dumps the file. + * Just in case the sections are in an unobvious order. + */ + sh = (cpel_section_header_t *)(fh+1); + for (i = 0; i < nsections; i++) { + section_size = ntohl(sh->data_length); + + if(verbose) { + fprintf(ofp, "Section type %d, size %d\n", ntohl(sh->section_type), + section_size); + } + + if(process_section(sh, verbose, ofp, PASS1)) + return(1); + + sh++; + sh = (cpel_section_header_t *)(((u8 *)sh)+section_size); + } + + sh = (cpel_section_header_t *)(fh+1); + for (i = 0; i < nsections; i++) { + if(process_section(sh, verbose, ofp, PASS2)) + return(1); + section_size = ntohl(sh->data_length); + sh++; + sh = (cpel_section_header_t *)(((u8 *)sh)+section_size); + } + return(0); +} + +void compute_state_statistics(int verbose, FILE *ofp) +{ + int i, j; + bound_track_t *bp; + f64 fticks; + + /* Across the bound tracks */ + for (i = 0; i < vec_len(bound_tracks); i++) { + bp = &bound_tracks[i]; + bp->mean_ticks_in_state = 0.0; + bp->variance_ticks_in_state = 0.0; + bp->total_ticks_in_state = 0.0; + for (j = 0; j < vec_len(bp->ticks_in_state); j++) { + bp->total_ticks_in_state += (f64) bp->ticks_in_state[j]; + } + /* Compute mean */ + if (vec_len(bp->ticks_in_state)) { + bp->mean_ticks_in_state = bp->total_ticks_in_state / + ((f64) vec_len(bp->ticks_in_state)); + } + /* Accumulate sum: (Xi-Xbar)**2 */ + for (j = 0; j < vec_len(bp->ticks_in_state); j++) { + fticks = bp->ticks_in_state[j]; + bp->variance_ticks_in_state += + (fticks - bp->mean_ticks_in_state)* + (fticks - bp->mean_ticks_in_state); + } + /* Compute s**2, the unbiased estimator of sigma**2 */ + if (vec_len(bp->ticks_in_state) > 1) { + bp->variance_ticks_in_state /= (f64) + (vec_len(bp->ticks_in_state)-1); + } + } +} + +int track_compare_max (const void *arg1, const void *arg2) +{ + bound_track_t *a1 = (bound_track_t *)arg1; + bound_track_t *a2 = (bound_track_t *)arg2; + f64 v1, v2; + + v1 = a1->total_ticks_in_state; + v2 = a2->total_ticks_in_state; + + if (v1 < v2) + return (1); + else if (v1 == v2) + return (0); + else return (-1); +} + +int track_compare_occurrences (const void *arg1, const void *arg2) +{ + bound_track_t *a1 = (bound_track_t *)arg1; + bound_track_t *a2 = (bound_track_t *)arg2; + f64 v1, v2; + + v1 = (f64) vec_len(a1->ticks_in_state); + v2 = (f64) vec_len(a2->ticks_in_state); + + if (v1 < v2) + return (1); + else if (v1 == v2) + return (0); + else return (-1); +} + +int track_compare_name (const void *arg1, const void *arg2) +{ + bound_track_t *a1 = (bound_track_t *)arg1; + bound_track_t *a2 = (bound_track_t *)arg2; + + return (strcmp((char *)(a1->track_str), (char *)(a2->track_str))); +} + +void sort_state_statistics(sort_t type, FILE *ofp) +{ + int (*compare)(const void *, const void *)=0; + + if (summary_stats_only) + return; + + switch(type) { + case SORT_MAX_TIME: + fprintf(ofp, "Results sorted by max time in state.\n"); + compare = track_compare_max; + break; + + case SORT_MAX_OCCURRENCES: + fprintf(ofp, "Results sorted by max occurrences of state.\n"); + compare = track_compare_occurrences; + break; + + case SORT_NAME: + compare = track_compare_name; + fprintf(ofp, "Results sorted by process-id/name/thread ID\n"); + break; + + default: + fatal("sort type not set?"); + } + + qsort (bound_tracks, vec_len(bound_tracks), + sizeof (bound_track_t), compare); +} + +void print_state_statistics(int verbose, FILE *ofp) +{ + int i,j; + u8 *trackpad; + bound_track_t *bp; + f64 total_time = 0.0; + f64 total_switches = 0.0; + + trackpad = format(0, "%%-%ds ", widest_track_format); + vec_add1(trackpad, 0); + + if (!summary_stats_only) { + fprintf(ofp, (char *)trackpad, "ProcThread"); + fprintf(ofp, " Mean(us) Stdev(us) Total(us) N\n"); + } + + for (i = 0; i < vec_len(bound_tracks); i++) { + bp = &bound_tracks[i]; + if (bp->mean_ticks_in_state == 0.0) + continue; + + if (name_filter && + strncmp((char *)(bp->track_str), (char *)name_filter, + strlen((char *)name_filter))) + continue; + + /* + * Exclude kernel threads (e.g. idle thread) from + * state statistics + */ + if (exclude_kernel_from_summary_stats && + !strncmp((char *)(bp->track_str), "kernel ", 7)) + continue; + + total_switches += (f64) vec_len(bp->ticks_in_state); + + if (!summary_stats_only) { + fprintf(ofp, (char *) trackpad, bp->track_str); + fprintf(ofp, "%10.3f +- %10.3f", + bp->mean_ticks_in_state / ticks_per_us, + sqrt(bp->variance_ticks_in_state) + / (f64) ticks_per_us); + fprintf(ofp, "%12.3f", + bp->total_ticks_in_state / ticks_per_us); + fprintf(ofp, "%8d\n", (int)vec_len(bp->ticks_in_state)); + } + + if (scatterplot) { + for (j = 0; j < vec_len(bp->ticks_in_state); j++) { + fprintf(ofp, "%.3f\n", + (f64)bp->ticks_in_state[j] / ticks_per_us); + } + } + + total_time += bp->total_ticks_in_state; + } + + if (!summary_stats_only) + fprintf(ofp, "\n"); + fprintf(ofp, "Note: the following statistics %s kernel-thread activity.\n", + exclude_kernel_from_summary_stats ? "exclude" : "include"); + if (name_filter) + fprintf(ofp, + "Note: only pid/proc/threads matching '%s' are included.\n", + name_filter); + + fprintf(ofp, + "Total runtime: %10.3f (us), Total state switches: %.0f\n", + total_time / ticks_per_us, total_switches); + fprintf(ofp, "Average time in state: %10.3f (us)\n", + (total_time / total_switches) / ticks_per_us); +} + +char *mapfile (char *file) +{ + struct stat statb; + char *rv; + int maphfile; + size_t mapfsize; + + maphfile = open (file, O_RDONLY); + + if (maphfile < 0) + { + fprintf (stderr, "Couldn't read %s, skipping it...\n", file); + return (NULL); + } + + if (fstat (maphfile, &statb) < 0) + { + fprintf (stderr, "Couldn't get size of %s, skipping it...\n", file); + return (NULL); + } + + /* Don't try to mmap directories, FIFOs, semaphores, etc. */ + if (! (statb.st_mode & S_IFREG)) { + fprintf (stderr, "%s is not a regular file, skipping it...\n", file); + return (NULL); + } + + mapfsize = statb.st_size; + + if (mapfsize < 3) + { + fprintf (stderr, "%s zero-length, skipping it...\n", file); + close (maphfile); + return (NULL); + } + + rv = mmap (0, mapfsize, PROT_READ, MAP_SHARED, maphfile, 0); + + if (rv == 0) + { + fprintf (stderr, "%s problem mapping, I quit...\n", file); + exit (-1); + } + close (maphfile); + return (rv); +} + +/* + * main + */ +int main (int argc, char **argv) +{ + char *cpel_file = 0; + char *outputfile = 0; + FILE *ofp; + char *cpel; + int verbose=0; + int curarg=1; + + while (curarg < argc) { + if (!strncmp(argv[curarg], "--input-file", 3)) { + curarg++; + if (curarg < argc) { + cpel_file = argv[curarg]; + curarg++; + continue; + } + fatal("Missing filename after --input-file\n"); + } + if (!strncmp(argv[curarg], "--output-file", 3)) { + curarg ++; + if (curarg < argc) { + outputfile = argv[curarg]; + curarg ++; + continue; + } + fatal("Missing filename after --output-file\n"); + } + if (!strncmp(argv[curarg], "--verbose", 3)) { + curarg++; + verbose++; + continue; + } + if (!strncmp(argv[curarg], "--scatterplot", 4)) { + curarg++; + scatterplot=1; + continue; + } + + if (!strncmp(argv[curarg], "--state-event", 4)) { + curarg++; + if (curarg < argc) { + state_event_code = atol(argv[curarg]); + curarg ++; + continue; + } + fatal("Missing integer after --state-event\n"); + } + if (!strncmp(argv[curarg], "--max-time-sort", 7)) { + sort_type = SORT_MAX_TIME; + curarg++; + continue; + } + if (!strncmp(argv[curarg], "--max-occurrence-sort", 7)) { + sort_type = SORT_MAX_OCCURRENCES; + curarg++; + continue; + } + if (!strncmp(argv[curarg], "--name-sort", 3)) { + sort_type = SORT_NAME; + curarg++; + continue; + } + if (!strncmp(argv[curarg], "--kernel-included", 3)) { + exclude_kernel_from_summary_stats = 0; + curarg++; + continue; + } + if (!strncmp(argv[curarg], "--summary", 3)) { + summary_stats_only=1; + curarg++; + continue; + } + if (!strncmp(argv[curarg], "--filter", 3)) { + curarg ++; + if (curarg < argc) { + name_filter = (u8 *)argv[curarg]; + curarg ++; + continue; + } + fatal("Missing filter string after --filter\n"); + } + + + usage: + fprintf(stderr, + "cpelstate --input-file <filename> [--output-file <filename>]\n"); + fprintf(stderr, + " [--state-event <decimal>] [--verbose]\n"); + fprintf(stderr, + " [--max-time-sort(default) | --max-occurrence-sort |\n"); + + fprintf(stderr, + " --name-sort-sort] [--kernel-included]\n"); + + fprintf(stderr, + " [--summary-stats-only] [--scatterplot]\n"); + + fprintf(stderr, "%s\n", version); + exit(1); + } + + if (cpel_file == 0) + goto usage; + + cpel = mapfile(cpel_file); + if (cpel == 0) { + fprintf(stderr, "Couldn't map %s...\n", cpel_file); + exit(1); + } + + if (!outputfile) { + ofp = fdopen(1, "w"); + if (ofp == NULL) { + fprintf(stderr, "Couldn't fdopen(1)?\n"); + exit(1); + } + } else { + ofp = fopen(outputfile, "w"); + if (ofp == NULL) { + fprintf(stderr, "Couldn't create %s...\n", outputfile); + exit(1); + } + } + + the_strtab_hash = hash_create_string (0, sizeof (uword)); + the_evtdef_hash = hash_create (0, sizeof (uword)); + the_trackdef_hash = hash_create (0, sizeof (uword)); + + if (cpel_dump((u8 *) cpel, verbose, ofp)) { + if (outputfile) + unlink(outputfile); + } + + compute_state_statistics(verbose, ofp); + sort_state_statistics(sort_type, ofp); + print_state_statistics(verbose, ofp); + + fclose(ofp); + return(0); +} |