diff options
Diffstat (limited to 'vpp/perftool')
| -rw-r--r-- | vpp/perftool/Makefile.am | 44 | ||||
| -rw-r--r-- | vpp/perftool/c2cpel.c | 248 | ||||
| -rw-r--r-- | vpp/perftool/configure.ac | 12 | ||||
| -rw-r--r-- | vpp/perftool/cpel.h | 83 | ||||
| -rw-r--r-- | vpp/perftool/cpel_util.c | 456 | ||||
| -rw-r--r-- | vpp/perftool/cpel_util.h | 68 | ||||
| -rw-r--r-- | vpp/perftool/cpelatency.c | 927 | ||||
| -rw-r--r-- | vpp/perftool/cpeldump.c | 638 | ||||
| -rw-r--r-- | vpp/perftool/cpelinreg.c | 892 | ||||
| -rw-r--r-- | vpp/perftool/cpelstate.c | 822 | ||||
| -rw-r--r-- | vpp/perftool/delsvec.c | 315 | ||||
| -rw-r--r-- | vpp/perftool/linreg.c | 78 | ||||
| -rw-r--r-- | vpp/perftool/new.cpel | bin | 0 -> 1672 bytes | |||
| -rw-r--r-- | vpp/perftool/new.elog | bin | 0 -> 4525 bytes | |||
| -rw-r--r-- | vpp/perftool/props.c | 280 |
15 files changed, 4863 insertions, 0 deletions
diff --git a/vpp/perftool/Makefile.am b/vpp/perftool/Makefile.am new file mode 100644 index 00000000..ac652aa6 --- /dev/null +++ b/vpp/perftool/Makefile.am @@ -0,0 +1,44 @@ +# Copyright (c) 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. + +AUTOMAKE_OPTIONS = foreign +AM_CFLAGS = -Wall + +bin_PROGRAMS = c2cpel cpelatency cpeldump cpelinreg cpelstate + +lib_LTLIBRARIES = libcperf.la + +libcperf_la_SOURCES = delsvec.c linreg.c props.c cpel_util.c + +TOOL_LIBS = libcperf.la -lvppinfra -lm + +c2cpel_SOURCE = c2cpel.c +c2cpel_LDADD = $(TOOL_LIBS) + +cpelatency_SOURCE = cpelatency.c +cpelatency_LDADD = $(TOOL_LIBS) + +cpeldump_SOURCE = cpeldump.c +cpeldump_LDADD = $(TOOL_LIBS) + +cpelinreg_SOURCE = cpelinreg.c +cpelinreg_LDADD = $(TOOL_LIBS) + +cpelstate_SOURCE = cpelstate.c +cpelstate_LDADD = $(TOOL_LIBS) + + + + + + diff --git a/vpp/perftool/c2cpel.c b/vpp/perftool/c2cpel.c new file mode 100644 index 00000000..38e6fe52 --- /dev/null +++ b/vpp/perftool/c2cpel.c @@ -0,0 +1,248 @@ +/* + *------------------------------------------------------------------ + * 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 <vppinfra/elog.h> +#include <pwd.h> +#include <stdarg.h> +#include <time.h> +#include "cpel.h" +#include "cpel_util.h" + +static elog_main_t elog_main; + +/* + * convert_clib_file + */ +void convert_clib_file(char *clib_file) +{ + clib_error_t *error = 0; + int i; + elog_main_t *em = &elog_main; + double starttime, delta; + + error = elog_read_file (&elog_main, clib_file); + + if (error) { + clib_warning("%U", format_clib_error, error); + exit (1); + } + + em = &elog_main; + + starttime = em->events[0].time; + + for (i = 0; i < vec_len (em->events); i++) { + elog_event_t *e; /* clib event */ + evt_t *ep; /* xxx2cpel event */ + u8 *s; + u64 timestamp; + elog_event_type_t *t; + u8 *brief_event_name; + u8 *track_name; + int j; + + e = vec_elt_at_index(em->events, i); + + /* Seconds since start of log */ + delta = e->time - starttime; + + /* u64 nanoseconds since start of log */ + timestamp = delta * 1e9; + + s = format (0, "%U%c", format_elog_event, em, e, 0); + + /* allocate an event instance */ + vec_add2(the_events, ep, 1); + ep->timestamp = timestamp; + + /* convert string event code to a real number */ + t = vec_elt_at_index (em->event_types, e->type); + + /* + * Construct a reasonable event name. + * Truncate the format string at the first whitespace break + * or printf format character. + */ + brief_event_name = format (0, "%s", t->format); + + for (j = 0; j < vec_len (brief_event_name); j++) { + if (brief_event_name[j] == ' ' || + brief_event_name[j] == '%' || + brief_event_name[j] == '(') { + brief_event_name[j] = 0; + break; + } + } + /* Throw away that much of the formatted event */ + vec_delete (s, j+1, 0); + + ep->event_id = find_or_add_event(brief_event_name, "%s"); + + track_name = format (0, "%U%c", format_elog_track, em, e, 0); + + ep->track_id = find_or_add_track (track_name); + + ep->datum = find_or_add_strtab(s); + + vec_free (track_name); + vec_free(brief_event_name); + vec_free(s); + } +} + +u8 *vec_basename (char *s) +{ + u8 * rv; + char *cp = s; + + while (*cp) + cp++; + + cp--; + + while (cp > s && *cp != '/') + cp--; + + if (cp > s) + cp++; + + rv = format (0, "%s", cp); + return rv; +} + + +int event_compare (const void *a0, const void *a1) +{ + evt_t *e0 = (evt_t *)a0; + evt_t *e1 = (evt_t *)a1; + + if (e0->timestamp < e1->timestamp) + return -1; + else if (e0->timestamp > e1->timestamp) + return 1; + return 0; +} + +int main (int argc, char **argv) +{ + int curarg=1; + char **inputfiles = 0; + char *outputfile = 0; + FILE *ofp; + + if (argc < 3) + goto usage; + + while (curarg < argc) { + if (!strncmp(argv[curarg], "--input-file", 3)) { + curarg++; + if (curarg < argc) { + vec_add1 (inputfiles, argv[curarg]); + curarg++; + continue; + } + clib_warning("Missing filename after --input-file\n"); + exit (1); + } + + if (!strncmp(argv[curarg], "--output-file", 3)) { + curarg ++; + if (curarg < argc) { + outputfile = argv[curarg]; + curarg ++; + continue; + } + clib_warning("Missing filename after --output-file\n"); + exit(1); + } + vec_add1 (inputfiles, argv[curarg]); + curarg++; + continue; + + usage: + fformat(stderr, + "c2cpel [--input-file] <filename> --output-file <filename>\n"); + exit(1); + } + + if (vec_len(inputfiles) == 0 || outputfile == 0) + goto usage; + + if (vec_len(inputfiles) > 1) + goto usage; + + cpel_util_init(); + + convert_clib_file (inputfiles[0]); + + ofp = fopen (outputfile, "w"); + if (ofp == NULL) { + clib_unix_warning ("couldn't create %s", outputfile); + exit (1); + } + + alpha_sort_tracks(); + fixup_event_tracks(); + + /* + * Four sections: string-table, event definitions, track defs, events. + */ + if (!write_cpel_header(ofp, 4)) { + clib_warning ("Error writing cpel header to %s...\n", outputfile); + unlink(outputfile); + exit(1); + } + + if (!write_string_table(ofp)) { + clib_warning ("Error writing string table to %s...\n", outputfile); + unlink(outputfile); + exit(1); + } + + if (!write_event_defs(ofp)) { + clib_warning ("Error writing event defs to %s...\n", outputfile); + unlink(outputfile); + exit(1); + } + + if (!write_track_defs(ofp)) { + clib_warning ("Error writing track defs to %s...\n", outputfile); + unlink(outputfile); + exit(1); + } + + if (!write_events(ofp, (u64) 1e9)) { + clib_warning ("Error writing events to %s...\n", outputfile); + unlink(outputfile); + exit(1); + + } + fclose(ofp); + exit (0); +} diff --git a/vpp/perftool/configure.ac b/vpp/perftool/configure.ac new file mode 100644 index 00000000..f4a98697 --- /dev/null +++ b/vpp/perftool/configure.ac @@ -0,0 +1,12 @@ +AC_INIT(perftool, 2.0) +AM_INIT_AUTOMAKE +AM_SILENT_RULES([yes]) + +AC_CHECK_LIB([vppinfra], [clib_mem_get_page_size],, + AC_MSG_ERROR([Please install the vpp-lib package])) +AC_CHECK_HEADER([vppinfra/clib.h],, + AC_MSG_ERROR([Please install the vpp-dev package])) + +AM_PROG_LIBTOOL + +AC_OUTPUT([Makefile]) diff --git a/vpp/perftool/cpel.h b/vpp/perftool/cpel.h new file mode 100644 index 00000000..0bfb1a68 --- /dev/null +++ b/vpp/perftool/cpel.h @@ -0,0 +1,83 @@ +/* + *------------------------------------------------------------------ + * Copyright (c) 2005-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. + */ + +#ifndef _CPEL_H_ +#define _CPEL_H_ 1 + +typedef struct cpel_file_header_ { + unsigned char endian_version; + unsigned char pad; + unsigned short nsections; + unsigned int file_date; +} cpel_file_header_t; + +#define CPEL_FILE_LITTLE_ENDIAN 0x80 +#define CPEL_FILE_VERSION 0x01 +#define CPEL_FILE_VERSION_MASK 0x7F + +typedef struct cpel_section_header_ { + unsigned int section_type; + unsigned int data_length; /* does NOT include type and itself */ +} cpel_section_header_t; + +#define CPEL_SECTION_STRTAB 1 +/* string at offset 0 is the name of the table */ + +#define CPEL_SECTION_SYMTAB 2 +#define CPEL_SECTION_EVTDEF 3 + +typedef struct event_definition_section_header_ { + char string_table_name[64]; + unsigned int number_of_event_definitions; +} event_definition_section_header_t; + +typedef struct event_definition_ { + unsigned int event; + unsigned int event_format; + unsigned int datum_format; +} event_definition_t; + +#define CPEL_SECTION_TRACKDEF 4 + +typedef struct track_definition_section_header_ { + char string_table_name[64]; + unsigned int number_of_track_definitions; +} track_definition_section_header_t; + +typedef struct track_definition_ { + unsigned int track; + unsigned int track_format; +} track_definition_t; + +#define CPEL_SECTION_EVENT 5 + +typedef struct event_section_header_ { + char string_table_name[64]; + unsigned int number_of_events; + unsigned int clock_ticks_per_second; +} event_section_header_t; + +typedef struct event_entry_ { + unsigned int time[2]; + unsigned int track; + unsigned int event_code; + unsigned int event_datum; +} event_entry_t; + +#define CPEL_NUM_SECTION_TYPES 5 + +#endif /* _CPEL_H_ */ + diff --git a/vpp/perftool/cpel_util.c b/vpp/perftool/cpel_util.c new file mode 100644 index 00000000..7ee9b6e2 --- /dev/null +++ b/vpp/perftool/cpel_util.c @@ -0,0 +1,456 @@ +/* + *------------------------------------------------------------------ + * 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 <vppinfra/bitmap.h> +#include <vppinfra/byte_order.h> +#include <pwd.h> +#include <stdarg.h> +#include <time.h> +#include "cpel.h" +#include "cpel_util.h" + +evt_t *the_events; + +track_t *the_tracks; +u32 *track_alpha_map; + +event_definition_t *the_event_definitions; +i64 min_timestamp; + +/* Hash tables, used to find previous instances of the same items */ +uword *the_track_hash; +uword *the_msg_event_hash; +uword *the_strtab_hash; +uword *the_pidtid_hash; +uword *the_pid_to_name_hash; +u8 *the_strtab; + +uword *the_event_id_bitmap; + +/* + * find_or_add_strtab + * Finds or adds a string to the string table + */ +u32 find_or_add_strtab(void *s_arg) +{ + uword *p; + int len; + u8 *this_string; + u8 *scopy=0; + char *s = s_arg; + + p = hash_get_mem(the_strtab_hash, s); + if (p) { + return (p[0]); + } + + /* + * Here's a CLIB bear-trap. We can't add the string-table + * strings to the to the hash table (directly), since it + * expands and moves periodically. All of the hash table + * entries turn into dangling references, yadda yadda. + */ + + len = strlen(s)+1; + vec_add2(the_strtab, this_string, len); + memcpy(this_string, s, len); + + /* Make a copy which won't be moving around... */ + vec_validate(scopy, len); + memcpy(scopy, s, len); + + hash_set_mem(the_strtab_hash, scopy, this_string - the_strtab); + + return(this_string - the_strtab); +} + +/* + * find_or_add_track + * returns index in track table + */ +u32 find_or_add_track(void *s_arg) +{ + uword *p; + track_t *this_track; + u8 *copy_s; + char *s=s_arg; + + p = hash_get_mem(the_track_hash, s); + if (p) { + return (p[0]); + } + vec_add2(the_tracks, this_track, 1); + + this_track->original_index = this_track - the_tracks; + this_track->strtab_offset = find_or_add_strtab(s); + + copy_s = (u8 *)vec_dup(s); + + hash_set_mem(the_track_hash, copy_s, this_track - the_tracks); + return(this_track - the_tracks); +} + +/* + * find_or_add_event + * Adds an event to the event definition vector and add it to + * the event hash table + */ + +u32 find_or_add_event(void *s_arg, char *datum_format) +{ + uword *p; + u8 *copy_s; + event_definition_t *this_event_definition; + u32 event_id; + char *s=s_arg; + + p = hash_get_mem(the_msg_event_hash, s); + if (p) { + return (p[0]); + } + vec_add2(the_event_definitions, this_event_definition, 1); + + /* Allocate a new event-id */ + event_id = clib_bitmap_first_clear (the_event_id_bitmap); + the_event_id_bitmap = clib_bitmap_set(the_event_id_bitmap, event_id, 1); + this_event_definition->event = event_id; + this_event_definition->event_format = find_or_add_strtab(s); + this_event_definition->datum_format = find_or_add_strtab(datum_format); + + copy_s = (u8 *)vec_dup(s); + + hash_set_mem(the_msg_event_hash, copy_s, event_id); + + return(event_id); +} + +/* + * write_string_table + */ +int write_string_table(FILE *ofp) +{ + cpel_section_header_t sh; + + /* Round up string table size */ + while (vec_len(the_strtab) & 0x7) + vec_add1(the_strtab, 0); + + sh.section_type = ntohl(CPEL_SECTION_STRTAB); + sh.data_length = ntohl(vec_len(the_strtab)); + + if (fwrite(&sh, sizeof(sh), 1, ofp) != 1) + return(0); + + if (fwrite(the_strtab, 1, vec_len(the_strtab), ofp) != + vec_len(the_strtab)) + return(0); + + return(1); +} + +/* + * write_cpel_header + */ +int write_cpel_header(FILE *ofp, u32 nsections) +{ + cpel_file_header_t h; + + h.endian_version = CPEL_FILE_VERSION; + h.pad = 0; + h.nsections = ntohs(nsections); + h.file_date = ntohl(time(0)); + if (fwrite(&h, sizeof(h), 1, ofp) != 1) + return (0); + + return(1); +} + +/* + * write_event_defs + */ +int write_event_defs(FILE *ofp) +{ + cpel_section_header_t sh; + event_definition_section_header_t edsh; + event_definition_t *this_event_definition; + int i; + + /* Next, the event definitions */ + sh.section_type = ntohl(CPEL_SECTION_EVTDEF); + sh.data_length = ntohl(vec_len(the_event_definitions) + *sizeof(the_event_definitions[0]) + + sizeof(event_definition_section_header_t)); + + if (fwrite(&sh, sizeof(sh), 1, ofp) != 1) + return(0); + + memset(&edsh, 0, sizeof(edsh)); + + strcpy(edsh.string_table_name, "FileStrtab"); + edsh.number_of_event_definitions = ntohl(vec_len(the_event_definitions)); + + if (fwrite(&edsh, sizeof(edsh), 1, ofp) != 1) + return(0); + + for (i = 0; i < vec_len(the_event_definitions); i++) { + this_event_definition = &the_event_definitions[i]; + /* Endian fixup */ + this_event_definition->event = ntohl(this_event_definition->event); + this_event_definition->event_format = + ntohl(this_event_definition->event_format); + this_event_definition->datum_format = + ntohl(this_event_definition->datum_format); + + if (fwrite(this_event_definition, sizeof(the_event_definitions[0]), + 1, ofp) != 1) + return(0); + } + return(1); +} + +/* + * ntohll + */ +u64 ntohll (u64 x) { + if (clib_arch_is_little_endian) + x = ((((x >> 0) & 0xff) << 56) + | (((x >> 8) & 0xff) << 48) + | (((x >> 16) & 0xff) << 40) + | (((x >> 24) & 0xff) << 32) + | (((x >> 32) & 0xff) << 24) + | (((x >> 40) & 0xff) << 16) + | (((x >> 48) & 0xff) << 8) + | (((x >> 56) & 0xff) << 0)); + + return x; +} + +/* + * write_events + */ +int write_events(FILE *ofp, u64 clock_ticks_per_second) +{ + cpel_section_header_t sh; + event_section_header_t eh; + u32 number_of_events; + int i; + event_entry_t e; + u64 net_timestamp; + evt_t *this_event; + u32 time0, time1; + + number_of_events = vec_len(the_events); + + sh.section_type = ntohl(CPEL_SECTION_EVENT); + sh.data_length = ntohl(number_of_events * sizeof(e) + + sizeof(event_section_header_t)); + + if (fwrite(&sh, sizeof(sh), 1, ofp) != 1) + return(0); + + memset(&eh, 0, sizeof(eh)); + strcpy(eh.string_table_name, "FileStrtab"); + eh.number_of_events = ntohl(number_of_events); + eh.clock_ticks_per_second = ntohl(clock_ticks_per_second); + + if (fwrite(&eh, sizeof(eh), 1, ofp) != 1) + return(0); + + for (i = 0; i < number_of_events; i++) { + this_event = &the_events[i]; + net_timestamp = ntohll(this_event->timestamp); + + time1 = net_timestamp>>32; + time0 = net_timestamp & 0xFFFFFFFF; + + e.time[0] = time0; + e.time[1] = time1; + e.track = ntohl(this_event->track_id); + e.event_code = ntohl(this_event->event_id); + e.event_datum = ntohl(this_event->datum); + + if (fwrite(&e, sizeof(e), 1, ofp) != 1) + return(0); + } + return(1); +} + +/* + * write_track_defs + */ +int write_track_defs(FILE *ofp) +{ + cpel_section_header_t sh; + track_definition_section_header_t tdsh; + track_definition_t record; + track_definition_t *this_track_definition = &record; + int i; + event_definition_section_header_t edsh; + + /* Next, the event definitions */ + sh.section_type = ntohl(CPEL_SECTION_TRACKDEF); + sh.data_length = ntohl(vec_len(the_tracks) + *sizeof(this_track_definition[0]) + + sizeof(track_definition_section_header_t)); + + if (fwrite(&sh, sizeof(sh), 1, ofp) != 1) + return(0); + + memset(&tdsh, 0, sizeof(tdsh)); + + strcpy(tdsh.string_table_name, "FileStrtab"); + tdsh.number_of_track_definitions = ntohl(vec_len(the_tracks)); + + if (fwrite(&tdsh, sizeof(edsh), 1, ofp) != 1) + return(0); + + for (i = 0; i < vec_len(the_tracks); i++) { + this_track_definition->track = ntohl(i); + this_track_definition->track_format = + ntohl(the_tracks[i].strtab_offset); + + if (fwrite(this_track_definition, sizeof(this_track_definition[0]), + 1, ofp) != 1) + return(0); + } + return(1); +} + +void cpel_util_init (void) +{ + u8 *eventstr; + + the_strtab_hash = hash_create_string (0, sizeof (uword)); + the_msg_event_hash = hash_create_string (0, sizeof (uword)); + the_track_hash = hash_create_string (0, sizeof (uword)); + the_pidtid_hash = hash_create_string (0, sizeof(uword)); + the_pid_to_name_hash = hash_create(0, sizeof(uword)); + + /* Must be first, or no supper... */ + find_or_add_strtab("FileStrtab"); + + /* Historical canned events, no longer used. */ + if (0) { + /* event 0 (not used) */ + eventstr = format(0, "PlaceholderNotUsed"); + vec_add1(eventstr, 0); + find_or_add_event(eventstr, "%s"); + vec_free(eventstr); + + /* event 1 (thread on CPU) */ + eventstr = format(0, "THREAD/THRUNNING"); + vec_add1(eventstr, 0); + find_or_add_event(eventstr, "%s"); + vec_free(eventstr); + + /* event 2 (thread ready) */ + eventstr = format(0, "THREAD/THREADY"); + vec_add1(eventstr, 0); + find_or_add_event(eventstr, "%s"); + vec_free(eventstr); + + /* event 3 (function enter) */ + eventstr = format(0, "FUNC/ENTER"); + vec_add1(eventstr, 0); + find_or_add_event(eventstr, "0x%x"); + vec_free(eventstr); + + /* event 4 (function enter) */ + eventstr = format(0, "FUNC/EXIT"); + vec_add1(eventstr, 0); + find_or_add_event(eventstr, "0x%x"); + vec_free(eventstr); + } +} + +/* + * alpha_compare_tracks + */ +static int alpha_compare_tracks(const void *a1, const void *a2) +{ + int i; + track_t *t1 = (track_t *)a1; + track_t *t2 = (track_t *)a2; + u8 *s1 = &the_strtab[t1->strtab_offset]; + u8 *s2 = &the_strtab[t2->strtab_offset]; + + for (i = 0; s1[i] && s2[i]; i++) { + if (s1[i] < s2[i]) + return(-1); + if (s1[i] > s2[i]) + return(1); + } + return(0); +} + +/* + * alpha_sort_tracks + * Alphabetically sort tracks, set up a mapping + * vector so we can quickly map the original track index to + * the new/improved/alpha-sorted index + */ +void alpha_sort_tracks(void) +{ + track_t *this_track; + int i; + + qsort(the_tracks, vec_len(the_tracks), sizeof(track_t), + alpha_compare_tracks); + + vec_validate(track_alpha_map, vec_len(the_tracks)); + _vec_len(track_alpha_map) = vec_len(the_tracks); + + for (i = 0; i < vec_len(the_tracks); i++) { + this_track = &the_tracks[i]; + track_alpha_map[this_track->original_index] = i; + } +} + +/* + * fixup_event_tracks + * Use the track alpha mapping to account for the alphabetic + * sort performed by the previous routine + */ +void fixup_event_tracks(void) +{ + int i; + u32 old_track; + + for (i = 0; i < vec_len(the_events); i++) { + old_track = the_events[i].track_id; + the_events[i].track_id = track_alpha_map[old_track]; + } +} + +/* Indispensable for debugging in gdb... */ + +u32 vl(void *x) +{ + return vec_len(x); +} diff --git a/vpp/perftool/cpel_util.h b/vpp/perftool/cpel_util.h new file mode 100644 index 00000000..b76f7a4b --- /dev/null +++ b/vpp/perftool/cpel_util.h @@ -0,0 +1,68 @@ +/* + *------------------------------------------------------------------ + * 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. + */ + +#ifndef __cpel_util_h__ +#define __cpel_util_h__ + +/* + * Our idea of an event, as opposed to a CPEL event + */ +typedef struct evt_ { + u64 timestamp; + u32 track_id; + u32 event_id; + u32 datum; +} evt_t; + +evt_t *the_events; + +/* + * Track object, so we can sort the tracks alphabetically and + * fix the events later + */ +typedef struct track_ { + u32 original_index; + u32 strtab_offset; +} track_t; + +track_t *the_tracks; +u32 *track_alpha_map; + +event_definition_t *the_event_definitions; +i64 min_timestamp; + +/* Hash tables, used to find previous instances of the same items */ +uword *the_track_hash; +uword *the_msg_event_hash; +uword *the_strtab_hash; +uword *the_pidtid_hash; +uword *the_pid_to_name_hash; +u8 *the_strtab; + +u32 find_or_add_strtab(void *s_arg); +u32 find_or_add_track(void *s_arg); +u32 find_or_add_event(void *s_arg, char *datum_format); +int write_string_table(FILE *ofp); +int write_cpel_header(FILE *ofp, u32 nsections); +int write_event_defs(FILE *ofp); +u64 ntohll (u64 x); +int write_events(FILE *ofp, u64 clock_ticks_per_second); +int write_track_defs(FILE *ofp); +void cpel_util_init (void); +void alpha_sort_tracks(void); +void fixup_event_tracks(void); + +#endif /* __cpel_util_h__ */ diff --git a/vpp/perftool/cpelatency.c b/vpp/perftool/cpelatency.c new file mode 100644 index 00000000..f40a1fb1 --- /dev/null +++ b/vpp/perftool/cpelatency.c @@ -0,0 +1,927 @@ +/* + *------------------------------------------------------------------ + * 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[] = "cpelatency 2.0"; + +#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 */ +uword *the_pidtid_hash; /* ("pid:xxx tid:yy", track-definition) hash */ + +f64 ticks_per_us; +u32 start_event_code = 2; /* default: XR thread ready event */ +u32 end_event_code = 1; /* default: XR thread running event */ +int exclude_kernel_from_summary_stats=1; +int summary_stats_only; +int scatterplot; +u8 *name_filter; +int have_trackdefs; + +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=20; + +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 state_start_ticks; + 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; + u8 *pidstr; + u8 *pidtid_str; + u8 *cp; + int tid, pid; + + 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(stderr, "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); + + if (verbose) { + fprintf(stderr, "adding track '%s'\n", btp->track_str); + } + + thislen = strlen((char *) btp->track_str); + if (thislen > widest_track_format) + widest_track_format = thislen; + + /* convert track_str "eth_server t11(20498)" to "pid:20498 tid:11" */ + cp = btp->track_str; + while (*cp && *cp != '(') + cp++; + if (!*cp) { + fprintf(stderr, "error canonicalizing '%s'\n", btp->track_str); + goto out; + } + pidstr = cp+1; /* remember location of PID */ + + while (cp > btp->track_str && *cp != 't') + cp--; + + if (cp == btp->track_str) { + fprintf(stderr, "error canonicalizing '%s'\n", btp->track_str); + goto out; + } + tid = atol((char *)(cp+1)); + pid = atol((char *) pidstr); + pidtid_str = format(0, "pid:%d tid:%d", pid, tid); + vec_add1(pidtid_str, 0); + + /* + * Note: duplicates are possible due to thread create / + * thread destroy operations. + */ + p = hash_get_mem(the_pidtid_hash, pidtid_str); + if (p) { + vec_free(pidtid_str); + goto out; + } + hash_set_mem(the_pidtid_hash, pidtid_str, btp - bound_tracks); + + out: + tp++; + } + have_trackdefs = 1; + 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; + int nevents; + int i; + uword *p; + event_entry_t *ep; + u64 now; + u32 time0, time1; + u32 track_code; + u8 *this_strtab; + u64 ticks_in_state; + bound_track_t *btp; + bound_track_t *state_track=0; + u8 *pidtid_str; + u8 *pidtid_dup; + u8 *ecp; + u32 event_code; + + 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); + } + this_strtab = (u8 *)p[0]; + + /* + * Some logger implementation that doesn't produce + * trackdef sections, synthesize the bound_tracks vector + */ + if (!have_trackdefs) { + for (i = 0; i < nevents; i++) { + track_code = ntohl(ep->track); + pidtid_dup = format(0, "%d", track_code); + vec_add1(pidtid_dup, 0); + p = hash_get_mem(the_pidtid_hash, pidtid_dup); + if (!p) { + vec_add2(bound_tracks, btp, 1); + btp->track = track_code; + btp->track_str = pidtid_dup; + hash_set(the_trackdef_hash, track_code, btp - bound_tracks); + hash_set_mem(the_pidtid_hash, pidtid_dup, btp - bound_tracks); + } else { + vec_free(pidtid_dup); + } + ep++; + } + } + + ep = (event_entry_t *)(eh+1); + + for (i = 0; i < nevents; i++) { + time0 = ntohl (ep->time[0]); + time1 = ntohl (ep->time[1]); + + now = (((u64) time0)<<32) | time1; + + event_code = ntohl(ep->event_code); + + /* Find the corresponding track via the pidtid hash table */ + if (event_code == start_event_code || event_code == end_event_code) { + if (have_trackdefs) { + pidtid_str = this_strtab + ntohl(ep->event_datum); + pidtid_dup = format(0, (char *) pidtid_str); + vec_add1(pidtid_dup, 0); + ecp = &pidtid_dup[vec_len(pidtid_dup)-1]; + while (*--ecp == ' ') + *ecp = 0; + } else { + pidtid_dup = format(0, "%d", ntohl(ep->track)); + vec_add1(pidtid_dup, 0); + } + + p = hash_get_mem(the_pidtid_hash, pidtid_dup); + if (!p) { + fprintf(stderr, "warning: couldn't find '%s'\n", + pidtid_dup); + vec_free(pidtid_dup); + ep++; + continue; + } + state_track = &bound_tracks[p[0]]; + } + /* Found the start-event code ? */ + if (event_code == start_event_code) { + state_track->state_start_ticks = now; + } else if (event_code == end_event_code) { + /* + * Add a ticks-in-state record, unless + * e.g. the log started with the exit event + */ + if (state_track->state_start_ticks) { + ticks_in_state = now - state_track->state_start_ticks; + vec_add1(state_track->ticks_in_state, ticks_in_state); + state_track->state_start_ticks = 0; + } + /* Otherwise, nothing */ + } + 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 *); + + if (summary_stats_only) + return; + + switch(type) { + case SORT_MAX_TIME: + fprintf(ofp, "Results sorted by max time in state.\n\n"); + compare = track_compare_max; + break; + + case SORT_MAX_OCCURRENCES: + fprintf(ofp, "Results sorted by max occurrences of state.\n\n"); + compare = track_compare_occurrences; + break; + + case SORT_NAME: + compare = track_compare_name; + fprintf(ofp, "Results sorted by process name, thread ID, PID\n\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, "ProcName Thread(PID)"); + 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) + / ticks_per_us); + fprintf(ofp, "%12.3f", + bp->total_ticks_in_state / ticks_per_us); + fprintf(ofp, "%8d\n", 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 time in state: %10.3f (us), Total state occurrences: %.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); + fprintf(ofp, "State start event: %d, state end event: %d\n", + start_event_code, end_event_code); +} + +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], "--start-event", 4)) { + curarg++; + if (curarg < argc) { + start_event_code = atol(argv[curarg]); + curarg ++; + continue; + } + fatal("Missing integer after --start-event\n"); + } + if (!strncmp(argv[curarg], "--end-event", 4)) { + curarg++; + if (curarg < argc) { + end_event_code = atol(argv[curarg]); + curarg ++; + continue; + } + fatal("Missing integer after --end-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, + "cpelatency --input-file <filename> [--output-file <filename>]\n"); + fprintf(stderr, + " [--start-event <decimal>] [--verbose]\n"); + fprintf(stderr, + " [--end-event <decimal>]\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)); + the_pidtid_hash = hash_create_string (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); +} diff --git a/vpp/perftool/cpeldump.c b/vpp/perftool/cpeldump.c new file mode 100644 index 00000000..9011bd03 --- /dev/null +++ b/vpp/perftool/cpeldump.c @@ -0,0 +1,638 @@ +/* + *------------------------------------------------------------------ + * 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" + +char *time_format = "%.03d:%.02d:%.02d:%.03d:%.03d "; +static char version[] = "cpeldump 2.0"; + +#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 */ + +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; +} 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(stderr, "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(stderr, "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(stderr, "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(stderr, "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; + f64 ticks_per_us; + u32 event_code, track_code; + u64 starttime = 0xFFFFFFFFFFFFFFFFULL; + int nevents; + int i; + uword *p; + event_entry_t *ep; + u64 now; + u64 delta; + u32 hours, minutes, seconds, msec, usec; + u32 time0, time1; + double d; + bound_event_t *bp; + bound_event_t generic_event; + bound_track_t *tp=0; + bound_track_t generic_track; + u32 last_track_code; + u8 *s, *evtpad, *trackpad; + u8 *this_strtab; + + generic_event.event_str = (u8 *)"%d"; + generic_event.datum_str = (u8 *)"0x%08x"; + generic_event.is_strtab_ref = 0; + + generic_track.track_str = (u8 *)"%d"; + last_track_code = 0xdeadbeef; + + 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(stderr, "Event section: %d events, %.3f ticks_per_us\n", + nevents, 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); + } + this_strtab = (u8 *)p[0]; + + evtpad = format(0, "%%-%ds ", widest_name_format); + vec_add1(evtpad, 0); + trackpad = format(0, "%%-%ds ", widest_track_format); + vec_add1(trackpad, 0); + + for (i = 0; i < nevents; i++) { + time0 = ntohl (ep->time[0]); + time1 = ntohl (ep->time[1]); + + now = (((u64) time0)<<32) | time1; + + /* Convert from bus ticks to usec */ + d = now; + d /= ticks_per_us; + + now = d; + + if (starttime == 0xFFFFFFFFFFFFFFFFULL) + starttime = now; + + delta = now - starttime; + + /* Delta = time since first event, in usec */ + + hours = delta / USEC_PER_HOUR; + if (hours) + delta -= ((u64) hours * USEC_PER_HOUR); + minutes = delta / USEC_PER_MINUTE; + if (minutes) + delta -= ((u64) minutes * USEC_PER_MINUTE); + seconds = delta / USEC_PER_SECOND; + if (seconds) + delta -= ((u64) seconds * USEC_PER_SECOND); + msec = delta / USEC_PER_MS; + if (msec) + delta -= ((u64) msec * USEC_PER_MS); + + usec = delta; + + /* Output the timestamp */ + fprintf(ofp, time_format, hours, minutes, seconds, msec, usec); + + /* output the track */ + track_code = ntohl(ep->track); + + if (track_code != last_track_code) { + p = hash_get(the_trackdef_hash, track_code); + if (p) { + tp = &bound_tracks[p[0]]; + } else { + tp = &generic_track; + } + } + s = format(0, (char *)tp->track_str, track_code); + vec_add1(s, 0); + fprintf(ofp, (char *)trackpad, s); + vec_free(s); + + /* output the event and datum */ + if (0 && verbose) { + fprintf(stderr, "raw event code %d, raw event datum 0x%x\n", + ntohl(ep->event_code), ntohl(ep->event_datum)); + } + + event_code = ntohl(ep->event_code); + p = hash_get(the_evtdef_hash, event_code); + if (p) { + bp = &bound_events[p[0]]; + } else { + bp = &generic_event; + } + s = format(0, (char *)bp->event_str, ntohl(ep->event_code)); + vec_add1(s, 0); + fprintf(ofp, (char *)evtpad, s); + vec_free(s); + if (bp->is_strtab_ref) { + fprintf(ofp, (char *) bp->datum_str, + &this_strtab[ntohl(ep->event_datum)]); + } else { + fprintf(ofp, (char *) bp->datum_str, ntohl(ep->event_datum)); + } + fputs("\n", ofp); + ep++; + } + vec_free(evtpad); + vec_free(trackpad); + 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(stderr, "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(stderr, "File created %s", ctime(&file_time)); + fprintf(stderr, "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(stderr, + "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); +} + + +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 = 1; + continue; + } + + usage: + fprintf(stderr, + "cpeldump --input-file <filename> [--output-file <filename>]\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)); + +#ifdef TEST_TRACK_INFO + { + bound_track_t *btp; + vec_add2(bound_tracks, btp, 1); + btp->track = 0; + btp->track_str = "cpu %d"; + hash_set(the_trackdef_hash, 0, btp - bound_tracks); + hash_set(the_trackdef_hash, 1, btp - bound_tracks); + } +#endif + + if (cpel_dump((u8 *)cpel, verbose, ofp)) { + if (outputfile) + unlink(outputfile); + } + + fclose(ofp); + return(0); +} diff --git a/vpp/perftool/cpelinreg.c b/vpp/perftool/cpelinreg.c new file mode 100644 index 00000000..115afad7 --- /dev/null +++ b/vpp/perftool/cpelinreg.c @@ -0,0 +1,892 @@ +/* + *------------------------------------------------------------------ + * Copyright (c) 2008-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. + */ + +/* + * Search for O(N**2) functions bracketed by before/after + * events. The "before" event's datum is used as a tag, e.g. which function + * did we call that's strongly O(N). + */ + +#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" + +FILE *g_ifp; +char *g_ifile; + +typedef unsigned long long ulonglong; + +void process_traces (void); +void record_instance (ulong tag, ulonglong time); +void report_actors (void); +void scatterplot_data(void); +int entry_event, exit_event; +int nokey; +char *version = "cpelinreg 2.0"; +int model_these[10]; +int model_index; +int summary_stats; +ulonglong first_start_time; +ulonglong last_end_time; +ulonglong total_time; +ulong scatterkey; +int inline_mokus; + +typedef struct bound_track_ { + u32 track_code; + u32 *start_datum; + u8 *dup_event; + int state; + u64 *start_time; + u64 thread_timestamp; + u64 time_thread_on_cpu; +} bound_track_t; + +bound_track_t *bound_tracks; +uword *the_trackdef_hash; + + +#define MAXSTACK 128 + +typedef struct instance_ { + struct instance_ *next; + ulonglong time; +}instance_t; + +typedef struct actor_ { + struct actor_ *next; + ulong key; + struct instance_ *first; + struct instance_ *last; + double a; + double b; + double min; + double max; + double mean; + double r; + ulong ninst; +} actor_t; + +#define NBUCKETS 1811 + +actor_t *hash[NBUCKETS]; + +actor_t *find_or_create_actor (ulong key) +{ + ulong bucket; + actor_t *ap; + u8 *mem; + + bucket = key % NBUCKETS; + + ap = hash[bucket]; + + if (ap == NULL) { + /* Ensure 8-byte alignment to avoid (double) alignment faults */ + mem = malloc(sizeof(*ap) + 4); + if (((uword)(mem)) & 0x7) + mem += 4; + ap = (actor_t *)mem; + + if (ap == NULL) { + fprintf (stderr, "out of memory...\n"); + exit (1); + } + ap->next = 0; + ap->key = key; + ap->first = 0; + ap->last = 0; + ap->a = 0.00; + ap->b = 0.00; + hash [bucket] = ap; + return (ap); + } + + while (ap) { + if (ap->key == key) + return (ap); + ap = ap->next; + } + + mem = malloc(sizeof(*ap)+4); + if (((uword)(mem) & 0x7)) + mem += 4; + ap = (actor_t *)mem; + + if (ap == NULL) { + fprintf (stderr, "out of memory...\n"); + exit (1); + } + ap->key = key; + ap->first = 0; + ap->last = 0; + ap->a = 0.00; + ap->b = 0.00; + + ap->next = hash[bucket]; + hash[bucket] = ap; + + return (ap); +} + +void record_instance (ulong key, ulonglong time) +{ + actor_t *ap; + instance_t *ip; + + if (nokey) + key = 0; + + ap = find_or_create_actor (key); + + ip = (instance_t *)malloc(sizeof(*ip)); + if (ip == NULL) { + fprintf (stderr, "out of memory...\n"); + exit (1); + } + ip->time = time; + ip->next = 0; + + if (ap->first == 0) { + ap->first = ip; + ap->last = ip; + ap->ninst = 1; + } else { + ap->last->next = ip; + ap->last = ip; + ap->ninst++; + } +} + +#define NINSTANCE 200000 + +double x[NINSTANCE]; +double y[NINSTANCE]; + +int actor_compare (const void *arg1, const void *arg2) +{ + double e10k1, e10k2; + actor_t **a1 = (actor_t **)arg1; + actor_t **a2 = (actor_t **)arg2; + double ninst1, ninst2; + + ninst1 = ((double)((*a1)->ninst)); + ninst2 = ((double)((*a2)->ninst)); + + e10k1 = ninst1 * ((*a1)->mean); + e10k2 = ninst2 * ((*a2)->mean); + + if (e10k1 < e10k2) + return (1); + else if (e10k1 == e10k2) + return (0); + else + return (-1); +} + +void report_actors (void) +{ + int i; + actor_t *ap; + instance_t *ip; + int nactors = 0; + int ninstance; + actor_t **actor_vector; + double e10k; + extern void linreg (double *x, double *y, int nitems, double *a, double *b, + double *minp, double *maxp, double *meanp, double *r); + + for (i = 0; i < NBUCKETS; i++) { + ap = hash[i]; + if (ap == NULL) + continue; + while (ap) { + nactors++; + ninstance = 0; + + ip = ap->first; + + while (ip) { + if (ninstance < NINSTANCE) { + x[ninstance] = ninstance; + y[ninstance] = ((double)ip->time); + ninstance++; + } + ip = ip->next; + } + if (ninstance > 1) { +#if DEBUG > 0 + int j; + + for (j = 0; j < ninstance; j++) { + printf("x[%d] = %10.2f, y[%d] = %10.2f\n", + j, x[j], j, y[j]); + } +#endif + + linreg (x, y, ninstance, &ap->a, &ap->b, &ap->min, + &ap->max, &ap->mean, &ap->r); + } else { + ap->a = 0.00; + ap->b = 0.00; + } + + ap = ap->next; + } + } + + actor_vector = (actor_t **)malloc (nactors*sizeof(*actor_vector)); + nactors = 0; + + for (i = 0; i < NBUCKETS; i++) { + ap = hash[i]; + if (ap == NULL) + continue; + while (ap) { + if ((ap->a != 0.00) || (ap->b != 0.00)) { + actor_vector[nactors++] = ap; + } + ap = ap->next; + } + } + + qsort (actor_vector, nactors, sizeof (actor_t *), actor_compare); + + if (summary_stats) + printf("NInst Offset Slope T(Ninst) Min Max Avg %%InstTime R Key"); + else + printf("NInst Offset Slope T(Ninst) Key"); + + for (i = 0; i < model_index; i++) { + printf ("T @ %-8d ", model_these[i]); + } + + printf ("\n"); + + for (i = 0; i < nactors; i++) { + int j; + double ninst; + double pcttot; + ap = actor_vector[i]; + ninst = ap->ninst; + + e10k = ninst * (ap->a + ap->b*((ninst-1.0)/2.0)); + + if (ap->ninst) { + if (summary_stats) { + pcttot = (e10k / ((double)total_time)) * 100.0; + printf ("%6ld %11.2f %11.2f %11.2f %11.2f %11.2f %11.2f %11.2f %11.2f 0x%08lx ", + ap->ninst, ap->a, ap->b, e10k, ap->min, + ap->max, ap->mean, pcttot, ap->r, ap->key); + } + else + printf ("%6ld %11.2f %11.2f %11.2f 0x%08lx ", + ap->ninst, ap->a, ap->b, e10k, ap->key); + + for (j = 0; j < model_index; j++) { + ninst = model_these[j]; + e10k = ninst * (ap->a + ap->b*((ninst-1.0)/2.0)); + printf ("%10.2f ", e10k); + } + printf ("\n"); + } + } +} + +void scatterplot_data(void) +{ + actor_t *ap; + int i; + instance_t *ip; + double time; + int count=0; + + for (i = 0; i < NBUCKETS; i++) { + ap = hash[i]; + if (ap == NULL) + continue; + while (ap) { + if (ap->key == scatterkey){ + ip = ap->first; + while (ip) { + time = ((double)ip->time); + printf ("%d\t%.0f\n", count++, time); + ip = ip->next; + } + return; + } + ap = ap->next; + } + } +} + + +void fatal(char *s) +{ + fprintf(stderr, "%s", s); + fprintf(stderr, "\n"); + exit(1); +} + +typedef enum { + PASS1=1, +} pass_t; + +typedef struct { + int (*pass1)(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 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 trackdef_pass(cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + int i, nevents; + track_definition_section_header_t *tdh; + track_definition_t *tp; + u32 track_code; + uword *p; + bound_track_t *btp; + + tdh = (track_definition_section_header_t *)(sh+1); + nevents = ntohl(tdh->number_of_track_definitions); + + if (verbose) { + fprintf(stderr, "Track Definition Section: %d definitions\n", + nevents); + } + + 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_code = track_code; + hash_set(the_trackdef_hash, track_code, btp - bound_tracks); + tp++; + } + return (0); +} + + +int event_pass (cpel_section_header_t *sh, int verbose, FILE *ofp) +{ + event_section_header_t *eh; + event_entry_t *ep; + f64 ticks_per_us; + long output_count; + long dup_events = 0; + ulonglong end_time = 0; + double t; + int sp, ancestor; + int nevents, i; + u64 now; + u64 time0, time1; + double d; + u32 last_track_code = 0xdeafb00b; + u32 track_code; + u32 event_code, event_datum; + bound_track_t *tp = 0; + uword *p; + + output_count = 0; + total_time = 0; + + 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); + + time0 = ntohl (ep->time[0]); + time1 = ntohl (ep->time[1]); + + now = (((u64) time0)<<32) | time1; + d = now; + d /= ticks_per_us; + first_start_time = d; + + for (i = 0; i < nevents; i++) { + time0 = ntohl (ep->time[0]); + time1 = ntohl (ep->time[1]); + + now = (((u64) time0)<<32) | time1; + + /* Convert from bus ticks to usec */ + d = now; + d /= ticks_per_us; + + now = d; + + track_code = ntohl(ep->track); + event_code = ntohl(ep->event_code); + event_datum = ntohl(ep->event_datum); + + if (track_code != last_track_code) { + if (tp) { + tp->thread_timestamp += now - tp->time_thread_on_cpu; + tp->time_thread_on_cpu = 0; + } + p = hash_get(the_trackdef_hash, track_code); + if (!p) { + /* synthesize a new track */ + vec_add2(bound_tracks, tp, 1); + tp->track_code = track_code; + hash_set(the_trackdef_hash, track_code, tp - bound_tracks); + } else { + tp = bound_tracks + p[0]; + } + last_track_code = track_code; + tp->time_thread_on_cpu = now; + } + + if (event_code != entry_event && + event_code != exit_event) { + ep++; + continue; + } + + again: + switch (tp->state) { + case 0: /* not in state */ + /* Another exit event? Stack pop */ + if (event_code == exit_event) { + /* Only if we have something on the stack */ + if (vec_len(tp->start_datum) > 0) { + tp->state = 1; + goto again; + } else { + fprintf (stderr, + "End event before start event, key 0x%x.", + ntohl(ep->event_datum)); + fprintf (stderr, " Interpret results carefully...\n"); + } + } + + tp->state = 1; + if (vec_len(tp->start_datum) >= MAXSTACK) { + int j; + + fprintf (stderr, "stack overflow..\n"); + for (j = vec_len(tp->start_datum)-1; j >= 0; j--) { + fprintf(stderr, "stack[%d]: datum 0x%x\n", + j, tp->start_datum[j]); + } + fprintf (stderr, + "Stack overflow... This occurs when " + "(start, datum)...(end, datum) events\n" + "are not properly paired.\n\n" + "A typical scenario looks like this:\n\n" + " ...\n" + " ELOG(..., START_EVENT, datum);\n" + " if (condition)\n" + " return; /*oops, forgot the end event*/\n" + " ELOG(..., END_EVENT, datum);\n" + " ...\n\n" + "The datum stack dump (above) should make it clear\n" + "where to start looking for a sneak path...\n"); + + exit (1); + } + vec_add1(tp->start_datum, event_datum); + vec_add1(tp->start_time, (tp->thread_timestamp + (now - tp->time_thread_on_cpu))); +#ifdef HAVING_TROUBLE + printf ("sp %lld key 0x%x start time %llu\n", + (long long) vec_len(tp->start_time)-1, event_datum, + (unsigned long long) + tp->start_time [vec_len(tp->start_time)-1]); + printf ("timestamp %llu, now %llu, thread on cpu %llu\n", + (unsigned long long) tp->thread_timestamp, + (unsigned long long) now, + (unsigned long long) tp->time_thread_on_cpu); +#endif + + + + /* + * Multiple identical enter events? If the user knows that + * gcc is producing bogus events due to inline functions, + * trash the duplicate. + */ + if (inline_mokus + && vec_len (tp->start_datum) > 1 + && tp->start_datum [vec_len(tp->start_datum)-1] == + tp->start_datum [vec_len(tp->start_datum)-2]) { + vec_add1 (tp->dup_event, 1); + } else { + vec_add1 (tp->dup_event, 0); + } + + + ep++; + continue; + + case 1: /* in state */ + /* Another entry event? Stack push*/ + if (event_code == entry_event) { + tp->state = 0; + goto again; + } + + if (vec_len(tp->start_datum) == 0) { + fprintf (stderr, "Stack underflow...\n"); + exit (1); + } + + sp = vec_len(tp->start_time)-1; + + end_time = tp->thread_timestamp + (now - tp->time_thread_on_cpu); + + if (!tp->dup_event[sp]) { +#ifdef HAVING_TROUBLE + printf ("sp %d key 0x%x charged %llu\n", sp, + tp->start_datum[sp], end_time - tp->start_time[sp]); + printf (" start %llu, end %llu\n", (unsigned long long) tp->start_time[sp], + (unsigned long long) end_time); +#endif + + record_instance (tp->start_datum[sp], (end_time - + tp->start_time[sp])); + + /* Factor out our time from surrounding services, if any */ + for (ancestor = sp-1; ancestor >= 0; ancestor--) { +#ifdef HAVING_TROUBLE + printf ("Factor out %lld from key 0x%08x\n", + (end_time - tp->start_time[sp]), tp->start_datum[ancestor]); +#endif + tp->start_time[ancestor] += (end_time - tp->start_time[sp]); + } + output_count++; + total_time += (end_time - tp->start_time[sp]); + tp->state = 0; + } else { + dup_events++; + } + _vec_len(tp->start_datum) = sp; + _vec_len(tp->start_time) = sp; + _vec_len(tp->dup_event) = sp; + } + + ep++; + } + last_end_time = now; + + if (scatterkey) { + scatterplot_data(); + exit (0); + } + + if (output_count) { + t = (double)total_time; + printf ("%ld instances of state, %.2f microseconds average\n", + output_count, t / output_count); + + printf ("Total instrumented runtime: %.2f microseconds\n", + ((double)total_time)); + printf ("Total runtime: %lld microseconds\n", + last_end_time - first_start_time); + + t /= (double)(last_end_time - first_start_time); + t *= 100.0; + + if (dup_events) { + printf ("Suppressed %ld duplicate state entry events\n", + dup_events); + } + printf ("Instrumented code accounts for %.2f%% of total time.\n\n", + t); + report_actors(); + } else { + printf ("No instances of state...\n"); + } + + 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] = +{ + {unsupported_pass}, /* type 0 -- f**ked */ + {noop_pass}, /* type 1 -- STRTAB */ + {noop_pass}, /* type 2 -- SYMTAB */ + {noop_pass}, /* type 3 -- EVTDEF */ + {trackdef_pass}, /* type 4 -- TRACKDEF */ + {event_pass}, /* 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; + + default: + fprintf(stderr, "Unknown pass %d\n", pass); + return(1); + } + + rv = (*fp)(sh, verbose, ofp); + + return(rv); +} + +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); +} + +int process_file (u8 *cpel, int verbose) +{ + cpel_file_header_t *fh; + cpel_section_header_t *sh; + u16 nsections; + u32 section_size; + int i; + FILE *ofp = stderr; + + /* 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); + } + nsections = ntohs(fh->nsections); + + /* + * Take a passe through the file. + */ + 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); + } + + return(0); +} + +/**************************************************************************** +* main - +****************************************************************************/ + +int main (int argc, char **argv) +{ + int curarg = 1; + u8 *cpel = 0; + int verbose = 0; + + if (argc < 6) + { + fprintf (stderr, "usage: cpelinreg -i <file>\n"); + fprintf (stderr, " -s start-event --e end-event [-nokey]\n"); + fprintf (stderr, " [-m <ninst-to-model>][-xtra-stats]\n"); + fprintf (stderr, " [-keyscatterplot <hex-key>]\n\n"); + fprintf (stderr, "%s\n", version); + exit (1); + } + + while (curarg < argc) { + if (!strncmp (argv[curarg], "-ifile", 2)) { + curarg++; + g_ifile = argv[curarg++]; + continue; + } + if (!strncmp (argv[curarg], "-start", 2)) { + curarg++; + entry_event = atol (argv [curarg++]); + continue; + } + if (!strncmp (argv[curarg], "-end", 2)) { + curarg++; + exit_event = atol (argv [curarg++]); + continue; + } + + if (!strncmp(argv[curarg], "-badinlines", 2)) { + curarg++; + inline_mokus = 1; + continue; + } + + if (!strncmp (argv[curarg], "-x", 2)) { + curarg++; + summary_stats=1; + continue; + } + if (!strncmp (argv[curarg], "-nokey", 2)) { + curarg++; + nokey = 1; + continue; + } + if (!strncmp (argv[curarg], "-keyscatterplot", 2)) { + curarg++; + sscanf (argv[curarg], "%lx", &scatterkey); + curarg++; + continue; + } + + if (!strncmp (argv[curarg], "-model", 2)) { + if (model_index >= sizeof(model_these) / sizeof(int)) { + fprintf (stderr, "Too many model requests\n"); + exit (1); + } + curarg++; + model_these[model_index++] = atol (argv [curarg++]); + continue; + } + if (!strncmp (argv[curarg], "-verbose", 2)) { + verbose++; + curarg++; + continue; + } + + fprintf (stderr, "unknown switch '%s'\n", argv[curarg]); + exit (1); + } + + cpel = (u8 *)mapfile(g_ifile); + + if (cpel == NULL) + { + fprintf (stderr, "Couldn't open %s\n", g_ifile); + exit (1); + } + + printf ("Extracting state info from %s\nentry_event %d, exit_event %d\n", + g_ifile, entry_event, exit_event); + if (nokey) { + printf ("All state instances mapped to a single actor chain\n"); + } + + the_trackdef_hash = hash_create (0, sizeof (uword)); + + process_file(cpel, verbose); + exit (0); +} diff --git a/vpp/perftool/cpelstate.c b/vpp/perftool/cpelstate.c new file mode 100644 index 00000000..3fd9ccb9 --- /dev/null +++ b/vpp/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); +} diff --git a/vpp/perftool/delsvec.c b/vpp/perftool/delsvec.c new file mode 100644 index 00000000..724935d3 --- /dev/null +++ b/vpp/perftool/delsvec.c @@ -0,0 +1,315 @@ +/* + *------------------------------------------------------------------ + * 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. + */ + +/* Break up a delimited string into a vector of substrings */ + +#include <stdio.h> +#include <vppinfra/clib.h> +#include <vppinfra/vec.h> +#include <vppinfra/hash.h> +#include <stdarg.h> + +/* + * #define UNIT_TESTS 1 + * #define MATCH_TRACE 1 + */ + +/* + * delsvec + * break up an input string into a vector of [null-terminated] u8 *'s + * + * Each supplied delimiter character results in a string in the output + * vector, unless the delimiters occur back-to-back. When matched, + * a whitespace character in the delimiter consumes an arbitrary + * run of whitespace. See the unit tests at the end of this file + * for a set of examples. + * + * Returns a u8 **, or NULL if the input fails to match. It is assumed + * that both input and fmt are C strings, not necessarily vectors. + * + * Output strings are both vectors and proper C strings. + */ + +static u8 **string_cache; +static u8 **svec_cache; + +void delsvec_recycle_this_string (u8 *s) +{ + if (s) { + _vec_len (s) = 0; + vec_add1(string_cache, s); + } +} + +void delsvec_recycle_this_svec (u8 **svec) +{ + if (svec) { + if (svec_cache) { + vec_free (svec_cache); + } + _vec_len (svec) = 0; + svec_cache = svec; + } +} + +int pvl (char *a) +{ + return vec_len(a); +} + +u8 **delsvec(void *input_arg, char *fmt) +{ + u8 **rv = 0; + int input_index=0; + u8 *this; + int dirflag=0; + int i; + u8 *input = input_arg; + + if (svec_cache) { + rv = svec_cache; + svec_cache = 0; + } + + while (fmt) { + dirflag=0; + if (vec_len (string_cache) > 0) { + this = string_cache [vec_len(string_cache)-1]; + _vec_len (string_cache) = vec_len (string_cache) - 1; + } else + this = 0; + /* + * '*' means one of two things: match the rest of the input, + * or match as many characters as possible + */ + if (fmt[0] == '*') { + fmt++; + dirflag=1; + /* + * no more format: eat rest of string... + */ + if (!fmt[0]) { + for (;input[input_index]; input_index++) + vec_add1(this, input[input_index]); + if (vec_len(this)) { + vec_add1(this, 0); +#ifdef MATCH_TRACE + printf("final star-match adds: '%s'\n", this); +#endif + vec_add1(rv, this); + } else { + vec_add1(string_cache, this); + } + + return(rv); + } + } + /* + * Left-to-right scan, adding chars until next delimiter char + * appears. + */ + if (!dirflag) { + while (input[input_index]) { + if (input[input_index] == fmt[0]) { + /* If we just (exact) matched a whitespace delimiter */ + if (fmt[0] == ' '){ + /* scan forward eating whitespace */ + while (input[input_index] == ' ' || + input[input_index] == '\t' || + input[input_index] == '\n') + input_index++; + input_index--; + } + goto found; + } + /* If we're looking for whitespace */ + if (fmt[0] == ' ') { + /* and we have whitespace */ + if (input[input_index] == ' ' || + input[input_index] == '\t' || + input[input_index] == '\n') { + /* scan forward eating whitespace */ + while (input[input_index] == ' ' || + input[input_index] == '\t' || + input[input_index] == '\n') { + input_index++; + } + input_index--; + goto found; + } + } + /* Not a delimiter, save it */ + vec_add1(this, input[input_index]); + input_index++; + } + /* + * Fell off the wagon, clean up and bail out + */ + bail: + +#ifdef MATCH_TRACE + printf("failed, fmt[0] = '%c', input[%d]='%s'\n", + fmt[0], input_index, &input[input_index]); +#endif + delsvec_recycle_this_string(this); + for (i = 0; i < vec_len(rv); i++) + delsvec_recycle_this_string(rv[i]); + delsvec_recycle_this_svec(rv); + return(0); + + found: + /* + * Delimiter matched + */ + input_index++; + fmt++; + /* + * If we actually accumulated non-delimiter characters, + * add them to the result vector + */ + if (vec_len(this)) { + vec_add1(this, 0); +#ifdef MATCH_TRACE + printf("match: add '%s'\n", this); +#endif + vec_add1(rv, this); + } else { + vec_add1(string_cache, this); + } + } else { + /* + * right-to-left scan, '*' not at + * the end of the delimiter string + */ + i = input_index; + while (input[++i]) + ; /* scan forward */ + i--; + while (i > input_index) { + if (input[i] == fmt[0]) + goto found2; + + if (fmt[0] == ' ' || fmt[0] == '\t' || + fmt[0] == '\n') { + if (input[i] == ' ' || + input[i] == '\t' || + input[i] == '\n') + goto found2; + } + i--; + } + goto bail; + + found2: + for (; input_index < i; input_index++) { + vec_add1(this, input[input_index]); + } + input_index++; + fmt++; + vec_add1(this, 0); +#ifdef MATCH_TRACE + printf("inner '*' match: add '%s'\n", this); +#endif + vec_add1(rv, this); + } + } + return (rv); +} + +#ifdef UNIT_TESTS + +typedef struct utest_ { + char *string; + char *fmt; +} utest_t; + +utest_t tests[] = { +#ifdef NOTDEF + {"Dec 7 08:56", + " :*"}, + {"Dec 17 08:56", + " :*"}, + {"Dec 7 08:56:41.239 install/inst_repl 0/9/CPU0 t1 [40989] File List:Successfully blobbified file list. Took 1 milliseconds", + " ::. / // [] *"}, + {"RP/0/9/CPU0:Dec 7 08:55:28.550 : sam_server[291]: SAM backs up digest list to memory file", + "///: ::. : []: *"}, + /* Expected to fail */ + {"Dec 7 08:56:41.239 install/inst_repl 0/9/CPU0 t1 [40989] File List:Successfully blobbified file list. Took 1 milliseconds", + "///: ::. : : *"}, + /* Expected to fail */ + {"RP/0/9/CPU0:Dec 7 08:55:28.550 : sam_server[291]: SAM backs up digest list to memory file", + " ::. / // [] *"}, + {"THIS that and + theother", "*+ *"}, + {"Dec 12 15:33:07.103 ifmgr/errors 0/RP0/CPU0 3# t2 Failed to open IM connection: No such file or directory", " ::. / // *"}, + {"Dec 16 21:43:47.328 ifmgr/bulk 0/3/CPU0 t8 Bulk DPC async download complete. Partitions 1, node_count 1, total_out 0, out_offset 0, out_expected 0: No error"," ::. / // *"}, + {"t:0x53034bd6 CPU:00 PROCESS :PROCCREATE_NAME", + ": : :*"}, + {" pid:1", " *"}, + {"t:0x53034cbb CPU:00 THREAD :THCREATE pid:1 tid:1", + ": : : pid: tid:*"}, + {"t:0x5303f950 CPU:00 COMM :REC_PULSE scoid:0x40000003 pid:364659", + ": : : *"}, + {"/hfr-base-3.3.85/lib/libttyconnection.dll 0xfc000000 0x0000306c 0xfc027000 0x000001c8 1", + " *"}, + {"Feb 28 02:38:26.123 seqtrace 0/1/CPU0 t8 :msg_receive:ifmgr/t8:IMC_MSG_MTU_UPDATE:ppp_ma/t1", + " ::. // ::::*"}, + + {"Feb 28 02:38:26.123 seqtrace 0/1/CPU0 t8 :msg_send_event:call:ifmgr/t8:124/0:cdp/t1", + " ::. // :msg_send_event::::*"}, + + {"Feb 28 02:38:26.125 seqtrace 0/1/CPU0 t1 :msg_receive_event:cdp/t1:124/0", + " ::. // :msg_receive_event::*"} + {"t:0x645dd86d CPU:00 USREVENT:EVENT:100, d0:0x00000002 d1:0x00000000", + ": : USREVENT:EVENT:, d0: *"} + {"t:0x5303f950 CPU:00 COMM :REC_PULSE scoid:0x40000003 pid:364659", + ": : : *"}, + {"t:0x2ccf9f5a CPU:00 INT_ENTR:0x80000000 (-2147483648) IP:0x002d8b18", + ": : INT_ENTR: IP:*"} + {"t:0xd473951c CPU:00 KER_EXIT:SCHED_GET/88 ret_val:2 sched_priority:10", + ": : KER_EXIT:SCHED_GET : sched_priority:*"} + {"t:0x00000123 CPU:01 SYSTEM :FUNC_ENTER thisfn:0x40e62048 call_site:0x00000000", + ": : SYSTEM :FUNC_ thisfn: *"}, + {"t:0x5af8de95 CPU:00 INT_HANDLER_ENTR:0x0000004d (77) PID:8200 IP:0x00000000 AREA:0x0bf9b290", ": : INT_HANDLER_*"}, +#endif + {"t:0x6d1ff92f CPU:00 CONTROL: BUFFER sequence = 1053, num_events = 714", + ": : CONTROL*"}, + {"t:0x6d1ff92f CPU:00 CONTROL :TIME msb:0x0000003c lsb(offset):0x6d1ff921", + ": : CONTROL*"}, +}; + +int main (int argc, char **argv) +{ + int i, j; + u8 **svec; + + for (j = 0; j < ARRAY_LEN(tests); j++) { + printf ("input string: '%s'\n", tests[j].string); + printf ("delimiter arg: '%s'\n", tests[j].fmt); + printf ("parse trace:\n"); + svec = delsvec(tests[j].string, tests[j].fmt); + if (!svec) { + printf("index %d failed\n", j); + continue; + } + printf("%d substring vectors\n", vec_len(svec)); + for (i = 0; i < vec_len(svec); i++) { + printf("[%d]: '%s'\n", i, svec[i]); + } + printf ("-------------------\n"); + } + exit(0); +} +#endif diff --git a/vpp/perftool/linreg.c b/vpp/perftool/linreg.c new file mode 100644 index 00000000..084091bb --- /dev/null +++ b/vpp/perftool/linreg.c @@ -0,0 +1,78 @@ +/* + *------------------------------------------------------------------ + * 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. + */ + +/* see "Numerical Recipies in C, 2nd ed." p 665 */ + +#include <stdio.h> +#include <math.h> + +/* + * linreg + * Linear regression of (xi, yi), returns parameters for least-squares + * fit y = a + bx. Also, compute Pearson's R. + */ +void linreg (double *x, double *y, int nitems, double *a, double *b, + double *minp, double *maxp, double *meanp, double *r) +{ + double sx = 0.0; + double sy = 0.0; + double st2 = 0.0; + double min = y[0]; + double max = 0.0; + double ss, meanx, meany, t; + double errx, erry, prodsum, sqerrx, sqerry; + int i; + + *b = 0.0; + + for (i = 0; i < nitems; i++) { + sx += x[i]; + sy += y[i]; + if (y[i] < min) + min = y[i]; + if (y[i] > max) + max = y[i]; + } + ss = nitems; + meanx = sx / ss; + meany = *meanp = sy / ss; + *minp = min; + *maxp = max; + + for (i = 0; i < nitems; i++) { + t = x[i] - meanx; + st2 += t*t; + *b += t*y[i]; + } + + *b /= st2; + *a = (sy-sx*(*b))/ss; + + prodsum = 0.0; + sqerrx = 0.0; + sqerry = 0.0; + + /* Compute numerator of Pearson's R */ + for (i = 0; i < nitems; i++) { + errx = x[i] - meanx; + erry = y[i] - meany; + prodsum += errx * erry; + sqerrx += errx*errx; + sqerry += erry*erry; + } + + *r = prodsum / (sqrt(sqerrx)*sqrt(sqerry)); +} diff --git a/vpp/perftool/new.cpel b/vpp/perftool/new.cpel Binary files differnew file mode 100644 index 00000000..b0f35958 --- /dev/null +++ b/vpp/perftool/new.cpel diff --git a/vpp/perftool/new.elog b/vpp/perftool/new.elog Binary files differnew file mode 100644 index 00000000..2d99bb16 --- /dev/null +++ b/vpp/perftool/new.elog diff --git a/vpp/perftool/props.c b/vpp/perftool/props.c new file mode 100644 index 00000000..84af5b1c --- /dev/null +++ b/vpp/perftool/props.c @@ -0,0 +1,280 @@ +/* + *------------------------------------------------------------------ + * 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 <ctype.h> +#include <malloc.h> +#include <time.h> +#include <string.h> +#include <unistd.h> +#include <stdlib.h> + +static char *sxerox (char *s); + +#define NBUCKETS 97 + +typedef struct prop_ { + struct prop_ *next; + char *name; + char *value; +} prop_t; + +static prop_t *buckets [NBUCKETS]; +static int hash_shifts[4] = {24, 16, 8, 0}; + +/* + * getprop + */ + +char *getprop (char *name) +{ + unsigned char *cp; + unsigned long hash=0; + prop_t *bp; + int i=0; + + for (cp = (unsigned char *) name; *cp; cp++) + hash ^= (*cp)<<(hash_shifts[(i++)&0x3]); + + bp = buckets [hash%NBUCKETS]; + + while (bp && strcmp(bp->name, name)) { + bp = bp->next; + } + + if (bp == NULL) + return (0); + else + return (bp->value); +} + +/* + * getprop_default + */ + +char *getprop_default (char *name, char *def) +{ + char *rv; + rv = getprop (name); + if (rv) + return (rv); + else + return (def); +} + +/* + * addprop + */ + +void addprop (char *name, char *value) +{ + unsigned char *cp; + unsigned long hash=0; + prop_t **bpp; + prop_t *bp; + int i=0; + + bp = (prop_t *)malloc (sizeof (prop_t)); + + bp->next = 0; + bp->name = sxerox (name); + bp->value = sxerox (value); + + for (cp = (unsigned char *)name; *cp; cp++) + hash ^= (*cp)<<(hash_shifts[(i++)&0x3]); + + bpp = &buckets [hash%NBUCKETS]; + + if (*bpp == NULL) + *bpp = bp; + else { + bp->next = *bpp; + *bpp = bp; + } +} + +/* + * sxerox + */ + +static char *sxerox (char *s) +{ + char *rv = (char *) malloc (strlen (s) + 1); + strcpy (rv, s); + return rv; +} + +/* + * readprops + */ + +#define START 0 +#define READNAME 1 +#define READVALUE 2 +#define C_COMMENT 3 +#define CPP_COMMENT 4 + +int readprops (char *filename) +{ + FILE *ifp; + unsigned char c; + int state=START; + int linenum=1; + char namebuf [128]; + char valbuf [512]; + int i; + + ifp = fopen (filename, "r"); + + if (ifp == NULL) + return (-1); + + while (1) { + + readchar: + c = getc (ifp); + + again: + switch (state) { + case START: + if (feof (ifp)) { + fclose (ifp); + return (0); + } + + if (c == ' ' || c == '\t') + goto readchar; + + if (c == '\n') { + linenum++; + goto readchar; + } + if (isalpha (c) || (c == '_')) { + state = READNAME; + goto again; + } + if (c == '/') { + c = getc (ifp); + if (c == '/') { + state = CPP_COMMENT; + goto readchar; + } else if (c == '*') { + state = C_COMMENT; + goto readchar; + } else { + fprintf (stderr, "unknown token '/' line %d\n", + linenum); + exit(1); + } + } + fprintf (stderr, "unknown token '%c' line %d\n", + c, linenum); + exit (1); + break; + + case CPP_COMMENT: + while (1) { + c = getc (ifp); + if (feof (ifp)) + return (0); + if (c == '\n') { + linenum++; + state = START; + goto readchar; + } + } + break; + + case C_COMMENT: + while (1) { + c = getc (ifp); + if (feof (ifp)) { + fprintf (stderr, "unterminated comment, line %d\n", + linenum); + exit (1); + } + if (c == '*') { + staragain: + c = getc (ifp); + if (c == '/') { + state = START; + goto readchar; + } + if (c == '*') + goto staragain; + } + } + break; + + case READNAME: + i = 0; + namebuf[i++] = c; + while (1) { + c = getc (ifp); + if (feof (ifp)) { + fprintf (stderr, "EOF while reading a name, line %d\n", + linenum); + exit (1); + } + if ((!isalnum (c)) && (c != '_')) { + namebuf [i] = 0; + state = READVALUE; + goto again; + } + namebuf [i++] = c; + } + break; + + case READVALUE: + i = 0; + while ((c == ' ') || (c == '\t') || (c == '=')) { + c = getc (ifp); + if (feof (ifp)) { + fprintf (stderr, "EOF while reading a value, line %d\n", + linenum); + exit (1); + } + } + goto firsttime; + while (1) { + c = getc (ifp); + + firsttime: + if (c == '\\') { + c = getc (ifp); + if (feof (ifp)) { + fprintf (stderr, "EOF after '\\', line %d\n", + linenum); + exit (1); + } + valbuf[i++] = c; + continue; + } + if (c == '\n') { + linenum++; + while (valbuf [i-1] == ' ' || valbuf[i-1] == '\t') + i--; + valbuf[i] = 0; + addprop (namebuf, valbuf); + state = START; + goto readchar; + } + valbuf[i++] = c; + } + + } + } +} |