blob: 3fd9ccb9c798100136292f6c593f08a478247df6 [file] [log] [blame]
/*
*------------------------------------------------------------------
* 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);
}