mirrors/emacs
1
Fork 0
mirror of git://git.sv.gnu.org/emacs.git synced 2025-12-29 08:31:35 -08:00
Code Issues Projects Releases Wiki Activity

Merge nb's eventcnv changes and rewrite guide/debug and topic/telemetry accordingly.

Browse source 
Copied from Perforce
 Change: 180103
 ServerID: perforce.ravenbrook.com
This commit is contained in:
Gareth Rees 2012-10-26 14:35:10 +01:00
commit cec0b453ee
9 changed files with 1244 additions and 357 deletions
Download patch file Download diff file Expand all files Collapse all files

2
mps/code/clock.h
View file

@ -120,7 +120,7 @@ __extension__ typedef unsigned long long EventClock;
#define EVENT_CLOCK_PRINT(stream, clock) \
fprintf(stream, "%08lX%08lX", \
(unsigned long)((clock) >> 32), \
(unsigned long)(clock))
(unsigned long)((clock) & 0xffffffff))
#define EVENT_CLOCK_WRITE(stream, clock) \
WriteF(stream, "$W$W", (WriteFW)((clock) >> 32), (WriteFW)clock, NULL)

2
mps/code/event.c
View file

@ -178,6 +178,8 @@ void EventInit(void)
EventKindControl = (Word)mps_lib_telemetry_control();
EventInternSerial = (Serial)1; /* 0 is reserved */
(void)EventInternString(MPSVersion()); /* emit version */
EVENT6(EventInit, EVENT_VERSION_MAJOR, EVENT_VERSION_MEDIAN,
EVENT_VERSION_MINOR, EventCodeMAX, EventNameMAX, MPS_WORD_WIDTH);
} else {
++eventUserCount;
}

271
mps/code/eventcnv.c
View file

@ -2,7 +2,7 @@
* Copyright (c) 2001 Ravenbrook Limited. See end of file for license.
*
* This is a command-line tool that converts a binary format telemetry output
* stream from the MPS into several textual formats.
* stream from the MPS into a textual format.
*
* The default MPS library will write a telemetry stream to a file called
* "mpsio.log" when the environment variable MPS_TELEMETRY_CONTROL is set
@ -22,20 +22,16 @@
*/
#include "config.h"
#include "eventdef.h"
#include "eventcom.h"
#include "eventpro.h"
#include "mpmtypes.h"
#include "testlib.h" /* for ulongest_t and associated print formats */
#include <stddef.h> /* for size_t */
#include <stdio.h> /* for printf */
#include <stdarg.h> /* for va_list */
#include <stdlib.h> /* for EXIT_FAILURE */
#include <assert.h> /* for assert */
#include <string.h> /* for strcmp */
#include <math.h> /* for sqrt */
#include "mpstd.h"
#ifdef MPS_BUILD_MV
@ -44,20 +40,12 @@
#pragma warning( disable : 4996 )
#endif
typedef unsigned int uint;
typedef unsigned long ulong;
#define DEFAULT_TELEMETRY_FILENAME "mpsio.log"
#define TELEMETRY_FILENAME_ENVAR "MPS_TELEMETRY_FILENAME"
static EventClock eventTime; /* current event time */
static char *prog; /* program name */
/* style: '\0' for human-readable, 'L' for Lisp, 'C' for CDF. */
static char style = '\0';
/* everror -- error signalling */
static void everror(const char *format, ...)
@ -80,7 +68,7 @@ static void everror(const char *format, ...)
static void usage(void)
{
fprintf(stderr,
"Usage: %s [-f logfile] [-S[LC]] [-h]\n"
"Usage: %s [-f logfile] [-h]\n"
"See \"Telemetry\" in the reference manual for instructions.\n",
prog);
}
@ -99,7 +87,7 @@ static void usageError(void)
static char *parseArgs(int argc, char *argv[])
{
char *name = "mpsio.log";
char *name = NULL;
int i = 1;
if (argc >= 1)
@ -117,9 +105,6 @@ static char *parseArgs(int argc, char *argv[])
else
name = argv[i];
break;
case 'S': /* style */
style = argv[i][2]; /* '\0' for human-readable, 'L' for Lisp, */
break; /* 'C' for CDF. */
case '?': case 'h': /* help */
usage();
exit(EXIT_SUCCESS);
@ -135,119 +120,39 @@ static char *parseArgs(int argc, char *argv[])
/* Printing routines */
static void printHex(ulongest_t val)
{
printf(" %"PRIXLONGEST, (ulongest_t)val);
}
#define printParamP(p) printHex((ulongest_t)p)
#define printParamA(a) printHex((ulongest_t)a)
#define printParamU(u) printHex((ulongest_t)u)
#define printParamW(w) printHex((ulongest_t)w)
#define printParamB(b) printHex((ulongest_t)b)
/* printStr -- print an EventString */
static void printParamD(double d)
{
printf(" %.10G", d);
}
static void printStr(const char *str, Bool quotes)
static void printParamS(const char *str)
{
size_t i;
if (quotes) putchar('"');
putchar(' ');
putchar('"');
for (i = 0; str[i] != '\0'; ++i) {
char c = str[i];
if (quotes && (c == '"' || c == '\\')) putchar('\\');
if (c == '"' || c == '\\') putchar('\\');
putchar(c);
}
if (quotes) putchar('"');
putchar('"');
}
/* printAddr -- print an Addr or its label */
static void printAddr(EventProc proc, Addr addr)
{
UNUSED(proc);
printf(style != 'C' ?
" %0"PRIwWORD PRIXLONGEST :
" %"PRIuLONGEST,
(ulongest_t)addr);
}
/* printParam* -- printing functions for event parameter types */
static void printParamA(EventProc proc, char *styleConv, Addr addr)
{
if (style != 'L') {
if (style == 'C') putchar(',');
printAddr(proc, addr);
} else
printf(styleConv, (ulongest_t)addr);
}
static void printParamP(EventProc proc, char *styleConv, void *p)
{
UNUSED(proc);
printf(styleConv, (ulongest_t)p);
}
static void printParamU(EventProc proc, char *styleConv, unsigned u)
{
UNUSED(proc);
printf(styleConv, (ulongest_t)u);
}
static void printParamW(EventProc proc, char *styleConv, Word w)
{
UNUSED(proc);
printf(styleConv, (ulongest_t)w);
}
static void printParamD(EventProc proc, char *styleConv, double d)
{
UNUSED(proc);
UNUSED(styleConv);
switch (style) {
case '\0':
printf(" %#8.3g", d); break;
case 'C':
printf(", %.10G", d); break;
case 'L':
printf(" %#.10G", d); break;
}
}
static void printParamS(EventProc proc, char *styleConv, const char *s)
{
UNUSED(proc);
UNUSED(styleConv);
if (style == 'C') putchar(',');
putchar(' ');
printStr(s, (style == 'C' || style == 'L'));
}
static void printParamB(EventProc proc, char *styleConv, Bool b)
{
UNUSED(proc);
printf(styleConv, (ulongest_t)b);
}
/* readLog -- read and parse log
*
* This is the heart of eventcnv: It reads an event log using
* EventRead. It updates the counters. It looks up the format,
* parses the arguments, and prints a representation of the event.
* Each argument is printed using printArg (see RELATION, below),
* except for some event types that are handled specially.
*/
/* readLog -- read and parse log */
static void readLog(EventProc proc)
{
char *styleConv = NULL; /* suppress uninit warning */
/* Init style. */
switch (style) {
case '\0':
styleConv = " %8"PRIXLONGEST; break;
case 'C':
styleConv = ", %"PRIuLONGEST; break;
case 'L':
styleConv = " %"PRIXLONGEST; break;
default:
everror("Unknown style code '%c'", style);
}
while (TRUE) { /* loop for each event */
Event event;
EventCode code;
@ -260,128 +165,25 @@ static void readLog(EventProc proc)
eventTime = event->any.clock;
code = event->any.code;
/* Output event. */
{
if (style == 'L') putchar('(');
EVENT_CLOCK_PRINT(stdout, eventTime);
printf(" %X", (unsigned)code);
switch (style) {
case '\0': case 'L':
EVENT_CLOCK_PRINT(stdout, eventTime);
putchar(' ');
break;
case 'C':
EVENT_CLOCK_PRINT(stdout, eventTime);
fputs(", ", stdout);
break;
}
switch (style) {
case '\0': case 'L': {
printf("%-19s ", EventCode2Name(code));
} break;
case 'C':
printf("%u", (unsigned)code);
break;
}
switch (code) {
case EventLabelCode:
switch (style) {
case '\0': case 'C':
{
const char *sym = LabelText(proc, event->Label.f1);
printf(style == '\0' ?
" %08"PRIXLONGEST" " :
", %"PRIuLONGEST", ",
(ulongest_t)event->Label.f0);
if (sym != NULL) {
printStr(sym, (style == 'C'));
} else {
printf(style == '\0' ?
"sym %05"PRIXLONGEST :
"sym %"PRIXLONGEST"\"",
(ulongest_t)event->Label.f1);
}
}
break;
case 'L':
printf(" %"PRIXLONGEST" %"PRIXLONGEST,
(ulongest_t)event->Label.f0,
(ulongest_t)event->Label.f1);
break;
}
break;
case EventMeterValuesCode:
switch (style) {
case '\0':
if (event->MeterValues.f3 == 0) {
printf(" %08"PRIXLONGEST" 0 N/A N/A N/A N/A",
(ulongest_t)event->MeterValues.f0);
} else {
double mean = event->MeterValues.f1 / (double)event->MeterValues.f3;
/* .stddev: stddev = sqrt(meanSquared - mean^2), but see */
/* <code/meter.c#limitation.variance>. */
double stddev = sqrt(fabs(event->MeterValues.f2
- (mean * mean)));
printf(" %08"PRIXLONGEST" %8u %8u %8u %#8.3g %#8.3g",
(ulongest_t)event->MeterValues.f0, (uint)event->MeterValues.f3,
(uint)event->MeterValues.f4, (uint)event->MeterValues.f5,
mean, stddev);
}
printAddr(proc, (Addr)event->MeterValues.f0);
break;
case 'C':
putchar(',');
printAddr(proc, (Addr)event->MeterValues.f0);
printf(", %.10G, %.10G, %u, %u, %u",
event->MeterValues.f1, event->MeterValues.f2,
(uint)event->MeterValues.f3, (uint)event->MeterValues.f4,
(uint)event->MeterValues.f5);
break;
case 'L':
printf(" %"PRIXLONGEST" %#.10G %#.10G %X %X %X",
(ulongest_t)event->MeterValues.f0,
event->MeterValues.f1, event->MeterValues.f2,
(uint)event->MeterValues.f3, (uint)event->MeterValues.f4,
(uint)event->MeterValues.f5);
break;
}
break;
case EventPoolInitCode: /* pool, arena, class */
printf(styleConv, (ulongest_t)event->PoolInit.f0);
printf(styleConv, (ulongest_t)event->PoolInit.f1);
/* class is a Pointer, but we label them, so call printAddr */
if (style != 'L') {
if (style == 'C') putchar(',');
printAddr(proc, (Addr)event->PoolInit.f2);
} else
printf(styleConv, (ulongest_t)event->PoolInit.f2);
break;
default:
switch (code) {
#define EVENT_PARAM_PRINT(name, index, sort, ident) \
printParam##sort(proc, styleConv, event->name.f##index);
printParam##sort(event->name.f##index);
#define EVENT_PRINT(X, name, code, always, kind) \
case code: \
EVENT_##name##_PARAMS(EVENT_PARAM_PRINT, name) \
break;
switch (code) { EVENT_LIST(EVENT_PRINT, X) }
}
if (style == 'L') putchar(')');
putchar('\n');
fflush(stdout);
EVENT_LIST(EVENT_PRINT, X)
}
putchar('\n');
fflush(stdout);
EventDestroy(proc, event);
} /* while(!feof(input)) */
}
/* logReader -- reader function for a file log */
static FILE *input;
@ -413,9 +215,14 @@ int main(int argc, char *argv[])
assert(CHECKCONV(ulongest_t, Addr));
assert(CHECKCONV(ulongest_t, void *));
assert(CHECKCONV(ulongest_t, EventCode));
assert(CHECKCONV(Addr, void *)); /* for labelled pointers */
filename = parseArgs(argc, argv);
if (!filename) {
filename = getenv(TELEMETRY_FILENAME_ENVAR
);
if(!filename)
filename = DEFAULT_TELEMETRY_FILENAME;
}
if (strcmp(filename, "-") == 0)
input = stdin;

15
mps/code/eventdef.h
View file

@ -38,7 +38,7 @@
#define EVENT_VERSION_MAJOR ((unsigned)1)
#define EVENT_VERSION_MEDIAN ((unsigned)0)
#define EVENT_VERSION_MINOR ((unsigned)0)
#define EVENT_VERSION_MINOR ((unsigned)1)
/* EVENT_LIST -- list of event types and general properties
@ -68,7 +68,7 @@
*/
#define EventNameMAX ((size_t)19)
#define EventCodeMAX ((EventCode)0x0073)
#define EventCodeMAX ((EventCode)0x0074)
#define EVENT_LIST(EVENT, X) \
/* 0123456789012345678 <- don't exceed without changing EventNameMAX */ \
@ -179,7 +179,8 @@
EVENT(X, TraceFindGrey , 0x0070, TRUE, Trace) \
EVENT(X, TraceBandAdvance , 0x0071, TRUE, Trace) \
EVENT(X, AWLDeclineTotal , 0x0072, TRUE, Trace) \
EVENT(X, AWLDeclineSeg , 0x0073, TRUE, Trace)
EVENT(X, AWLDeclineSeg , 0x0073, TRUE, Trace) \
EVENT(X, EventInit , 0x0074, TRUE, Arena)
/* Remember to update EventNameMAX and EventCodeMAX in eventcom.h!
@ -620,6 +621,14 @@
PARAM(X, 0, P, seg) /* segment declined single access */ \
PARAM(X, 1, W, singleAccesses) /* single accesses this cycle */
#define EVENT_EventInit_PARAMS(PARAM, X) \
PARAM(X, 0, U, major) /* EVENT_VERSION_MAJOR */ \
PARAM(X, 1, U, median) /* EVENT_VERSION_MEDIAN */ \
PARAM(X, 2, U, minor) /* EVENT_VERSION_MINOR */ \
PARAM(X, 3, U, maxCode) /* EventCodeMAX */ \
PARAM(X, 4, U, maxNameLen) /* EventNameMAX */ \
PARAM(X, 5, U, wordWidth) /* MPS_WORD_WIDTH */
#endif /* eventdef_h */

950
mps/code/eventsql.c Normal file
View file

@ -0,0 +1,950 @@
/* eventsql.c: event log to SQLite importer.
*
* $Id$
*
* Copyright (c) 2012 Ravenbrook Limited. See end of file for license.
*
* This is a command-line tool that imports events from a text-format
* MPS telemetry file into a SQLite database file.
*
* The default MPS library will write a binary-format telemetry file.
* The binary-format file can be converted into a text-format file
* using the eventcnv program with the -SC -v options. For
* binary-format compatibility, eventcnv has to be run on the same
* platform as the MPS.
*
* These ASCII text-format files have one line per event, and can be
* manipulated by various splendid systems in the usual Unix way. This
* eventsql program is one such.
*
* Note that eventsql can read streams that come from an MPS running
* on another platform. This is another reason why we use the
* intermediate text-format file, rather than reading the
* binary-format file directly: you can run the MPS and then eventcnv
* on the target platform, then optionally analyse the resulting text
* file on some other machine.
*
* Each event type gets its own table in the database. These tables
* are created from the definitions in eventdef.h if they don't
* already exist. Each event becomes a single row in the appropriate
* table, which has a column for each event parameter, a time column
* for the event time field, and a log_serial column to identify the
* log file. Because the database schema depends on the event
* definitions in eventdef.h, eventsql has to be compiled using the
* same event header files as those used to compile the MPS and
* eventcnv which generated and processed the telemetry output.
*
* The program also creates several other tables: three 'glue' tables
* containing event metadata - event_kind (one row per kind),
* event_type (one row per type), and event_param (one row per
* parameter), all derived from eventdef.h - and the event_log table
* which has one row per log file imported (the log_serial column in
* the event tables is a primary key to this event_log table).
*
* No tables are created if they already exist, unless the -r
* (rebuild) switch is given.
*
* Options:
*
* -v (verbose): Increase verbosity. eventsql logs to stderr. By
* default, it doesn't log much; it can be made more and more
* loquacious by adding more -v switches. Given one or more -v
* switches, it also writes 'ticks' (periods) to stdout, to show
* progress (one dot is 100k events).
*
* -t (test): Run unit tests on parts of eventsql. There aren't many
* of these. TODO: write more unit tests.
*
* -f (force): Import the events to SQL even if the SQL database
* already includes a record of importing a matching log file.
*
* -r (rebuild): Drop the glue tables from SQL, which will force them
* to be recreated. Important if you change event types or kinds in
* eventdef.h.
*
* -l <logfile>: Import events from the named logfile. Defaults to
* stdin. If the specified file (matched by size and modtime) has
* previously been imported to the same database, it will not be
* imported again unless -f is specified.
*
* -d <database>: Import events to the named database file. If not
* specified, eventsql will use the MPS_EVENT_DATABASE environment
* variable, and default to mpsevent.db.
*
* $Id$
*/
#include "misc.h"
#include "config.h"
#include "eventdef.h"
#include "eventcom.h"
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sqlite3.h>
#include <sys/stat.h>
#define DATABASE_NAME_ENVAR "MPS_EVENT_DATABASE"
#define DEFAULT_DATABASE_NAME "mpsevent.db"
typedef sqlite3_int64 int64;
/* we output rows of dots. One dot per SMALL_TICK events,
* BIG_TICK dots per row. */
#define SMALL_TICK 100000
#define BIG_TICK 50
/* Utility code for logging to stderr with multiple log levels,
* and for reporting errors.
*/
unsigned int verbosity = 0;
#define LOG_ALWAYS 0
#define LOG_OFTEN 1
#define LOG_SOMETIMES 2
#define LOG_SELDOM 3
#define LOG_RARELY 4
static void vlog(unsigned int level, const char *format, va_list args)
{
if (level <= verbosity) {
fflush(stderr); /* sync */
fprintf(stderr, "log %d: ", level);
vfprintf(stderr, format, args);
fprintf(stderr, "\n");
}
}
static void log(unsigned int level, const char *format, ...)
{
va_list args;
va_start(args, format);
vlog(level, format, args);
va_end(args);
}
static void error(const char *format, ...)
{
va_list args;
fprintf(stderr, "Fatal error: ");
va_start(args, format);
vlog(LOG_ALWAYS, format, args);
va_end(args);
exit(1);
}
static void sqlite_error(int res, sqlite3 *db, const char *format, ...)
{
va_list args;
log(LOG_ALWAYS, "Fatal SQL error %d", res);
va_start(args, format);
vlog(LOG_ALWAYS, format, args);
va_end(args);
log(LOG_ALWAYS, "SQLite message: %s\n", sqlite3_errmsg(db));
exit(1);
}
static char *prog; /* program name */
static int rebuild = FALSE;
static int runTests = FALSE;
static int force = FALSE;
static char *databaseName = NULL;
static char *logFileName = NULL;
static void usage(void)
{
fprintf(stderr,
"Usage: %s [-rtf] [-l <logfile>] [-d <database>] [-v -v -v ...]\n",
prog);
}
static void usageError(void)
{
usage();
error("Bad usage");
}
/* parseArgs -- parse command line arguments */
static void parseArgs(int argc, char *argv[])
{
int i = 1;
if (argc >= 1)
prog = argv[0];
else
prog = "unknown";
while (i < argc) { /* consider argument i */
if (argv[i][0] == '-') { /* it's an option argument */
switch (argv[i][1]) {
case 'v': /* verbosity */
++ verbosity;
break;
case 'r': /* rebuild */
rebuild = TRUE;
break;
case 'f': /* force */
force = TRUE;
break;
case 't': /* run tests */
runTests = TRUE;
break;
case 'l': /* log file name */
++ i;
if (i == argc)
usageError();
else
logFileName = argv[i];
break;
case 'd': /* database file name */
++ i;
if (i == argc)
usageError();
else
databaseName = argv[i];
break;
case '?': case 'h': /* help */
usage();
break;
default:
usageError();
}
} /* if option */
++ i;
}
}
/* openDatabase(p) opens the database file and returns a SQLite 3
* database connection object. */
static sqlite3 *openDatabase(void)
{
sqlite3 *db;
int res;
if (!databaseName) {
databaseName = getenv(DATABASE_NAME_ENVAR);
if(!databaseName)
databaseName = DEFAULT_DATABASE_NAME;
}
res = sqlite3_open_v2(databaseName,
&db,
SQLITE_OPEN_READWRITE | SQLITE_OPEN_CREATE,
NULL); /* use default sqlite_vfs object */
if (res != SQLITE_OK)
sqlite_error(res, db, "Opening %s failed", databaseName);
log(LOG_OFTEN, "Writing to %s.",databaseName);
return db;
}
/* closeDatabase(db) closes the database opened by openDatabase(). */
static void closeDatabase(sqlite3 *db)
{
int res = sqlite3_close(db);
if (res != SQLITE_OK)
sqlite_error(res, db, "Closing database failed");
log(LOG_SOMETIMES, "Closed %s.", databaseName);
}
/* Utility functions for SQLite statements. */
static sqlite3_stmt *prepareStatement(sqlite3 *db,
const char *sql)
{
int res;
sqlite3_stmt *statement;
log(LOG_SELDOM, "Preparing statement %s", sql);
res = sqlite3_prepare_v2(db, sql,
-1, /* prepare whole string as statement */
&statement,
NULL);
if (res != SQLITE_OK)
sqlite_error(res, db, "statement preparation failed: %s", sql);
return statement;
}
static void finalizeStatement(sqlite3 *db,
sqlite3_stmt *statement)
{
int res;
res = sqlite3_finalize(statement);
if (res != SQLITE_OK)
sqlite_error(res, db, "statement finalize failed");
}
static void runStatement(sqlite3 *db,
const char *sql,
const char *description)
{
int res;
log(LOG_SELDOM, "%s: %s", description, sql);
res = sqlite3_exec(db,
sql,
NULL, /* No callback */
NULL, /* No callback closure */
NULL); /* error messages handled by sqlite_error */
if (res != SQLITE_OK)
sqlite_error(res, db, "%s failed - statement %s", description, sql);
}
/* Test for the existence of a table using sqlite_master table.
*/
static int tableExists(sqlite3* db, const char *tableName)
{
int res;
int exists;
sqlite3_stmt *statement;
statement = prepareStatement(db,
"SELECT 1 FROM sqlite_master WHERE type='table' AND name=?");
res = sqlite3_bind_text(statement, 1, tableName, -1, SQLITE_STATIC);
if (res != SQLITE_OK)
sqlite_error(res, db, "table existence bind of name failed.");
res = sqlite3_step(statement);
switch(res) {
case SQLITE_DONE:
exists = 0;
break;
case SQLITE_ROW:
exists = 1;
break;
default:
sqlite_error(res, db, "select from sqlite_master failed.");
}
finalizeStatement(db, statement);
return exists;
}
/* Unit test for tableExists() */
static struct {
const char* name;
int exists;
} tableTests[] = {
{"event_kind", TRUE},
{"spong", FALSE},
{"EVENT_SegSplit", TRUE}
};
static void testTableExists(sqlite3 *db)
{
size_t i;
int defects = 0;
int tests = 0;
for (i=0; i < (sizeof(tableTests)/sizeof(tableTests[0])); ++i) {
const char *name = tableTests[i].name;
int exists = tableExists(db, name);
if (exists)
log(LOG_OFTEN, "Table exists: %s", name);
else
log(LOG_OFTEN, "Table does not exist: %s", name);
if (exists != tableTests[i].exists) {
log(LOG_ALWAYS, "tableExists test failed on table %s", name);
++ defects;
}
++ tests;
}
log(LOG_ALWAYS, "%d tests, %d defects found.", tests, defects);
}
/* Every time we put events from a log file into a database file, we
* add the log file to the event_log table, and get a serial number
* from SQL which is then attached to all event rows from that log.
* We use this to record overall SQL activity, to deter mistaken
* attempts to add the same log file twice, and to allow events from
* several different log files to share the same SQL file.
*
* When reading events from stdin, we can't so easily avoid the
* duplication (unless we, e.g., take a hash of the event set); we
* assume that the user is smart enough not to do that.
*/
static int64 logSerial = 0;
static void registerLogFile(sqlite3 *db,
const char *filename)
{
sqlite3_stmt *statement;
int res;
const unsigned char *name;
int64 completed;
int64 file_size;
int64 file_modtime;
if (filename) {
struct stat st;
res = stat(filename, &st);
if (res != 0)
error("Couldn't stat() %s", filename);
file_size = st.st_size;
file_modtime = st.st_mtime;
statement = prepareStatement(db,
"SELECT name, serial, completed FROM event_log"
" WHERE size = ? AND modtime = ?");
res = sqlite3_bind_int64(statement, 1, file_size);
if (res != SQLITE_OK)
sqlite_error(res, db, "event_log bind of size failed.");
res = sqlite3_bind_int64(statement, 2, file_modtime);
if (res != SQLITE_OK)
sqlite_error(res, db, "event_log bind of modtime failed.");
res = sqlite3_step(statement);
switch(res) {
case SQLITE_DONE:
log(LOG_SOMETIMES, "No log file matching '%s' found in database.", filename);
break;
case SQLITE_ROW:
name = sqlite3_column_text(statement, 0);
logSerial = sqlite3_column_int64(statement, 1);
completed = sqlite3_column_int64(statement, 2);
log(force ? LOG_OFTEN : LOG_ALWAYS, "Log file matching '%s' already in event_log, named \"%s\" (serial %lu, completed %lu).",
filename, name, logSerial, completed);
if (force) {
log(LOG_OFTEN, "Continuing anyway because -f specified.");
} else {
log(LOG_ALWAYS, "Exiting. Specify -f to force events into SQL anyway.");
exit(0);
}
break;
default:
sqlite_error(res, db, "select from event_log failed.");
}
finalizeStatement(db, statement);
} else { /* stdin */
filename = "<stdin>";
file_size = 0;
file_modtime = 0;
}
statement = prepareStatement(db,
"INSERT into event_log (name, size, modtime, completed)"
" VALUES (?, ?, ?, 0)");
res = sqlite3_bind_text(statement, 1, filename, -1, SQLITE_STATIC);
if (res != SQLITE_OK)
sqlite_error(res, db, "event_log insert bind of name failed.");
res = sqlite3_bind_int64(statement, 2, file_size);
if (res != SQLITE_OK)
sqlite_error(res, db, "event_log insert bind of size failed.");
res = sqlite3_bind_int64(statement, 3, file_modtime);
if (res != SQLITE_OK)
sqlite_error(res, db, "event_log insert bind of modtime failed.");
res = sqlite3_step(statement);
if (res != SQLITE_DONE)
sqlite_error(res, db, "insert into event_log failed.");
logSerial = sqlite3_last_insert_rowid(db);
log(LOG_SOMETIMES, "Log file %s added to event_log with serial %lu",
filename, logSerial);
finalizeStatement(db, statement);
}
static void logFileCompleted(sqlite3 *db,
int64 completed)
{
sqlite3_stmt *statement;
int res;
statement = prepareStatement(db,
"UPDATE event_log SET completed=? WHERE serial=?");
res = sqlite3_bind_int64(statement, 2, logSerial);
if (res != SQLITE_OK)
sqlite_error(res, db, "event_log update bind of serial failed.");
res = sqlite3_bind_int64(statement, 1, completed);
if (res != SQLITE_OK)
sqlite_error(res, db, "event_log update bind of completed failed.");
res = sqlite3_step(statement);
if (res != SQLITE_DONE)
sqlite_error(res, db, "insert into event_log failed.");
log(LOG_SOMETIMES, "Marked in event_log: %lu events", completed);
finalizeStatement(db, statement);
}
/* Macro magic to make a CREATE TABLE statement for each event type. */
#define EVENT_PARAM_SQL_TYPE_A "INTEGER"
#define EVENT_PARAM_SQL_TYPE_P "INTEGER"
#define EVENT_PARAM_SQL_TYPE_U "INTEGER"
#define EVENT_PARAM_SQL_TYPE_W "INTEGER"
#define EVENT_PARAM_SQL_TYPE_D "REAL "
#define EVENT_PARAM_SQL_TYPE_S "TEXT "
#define EVENT_PARAM_SQL_TYPE_B "INTEGER"
#define EVENT_PARAM_SQL_COLUMN(X, index, sort, ident) \
"\"" #ident "\" " EVENT_PARAM_SQL_TYPE_##sort ", "
#define EVENT_TABLE_CREATE(X, name, code, always, kind) \
"CREATE TABLE IF NOT EXISTS EVENT_" #name " ( " \
EVENT_##name##_PARAMS(EVENT_PARAM_SQL_COLUMN, X) \
"time INTEGER, " \
"log_serial INTEGER)",
/* An array of table-creation statement strings. */
const char *createStatements[] = {
"CREATE TABLE IF NOT EXISTS event_kind (name TEXT,"
" description TEXT,"
" enum INTEGER PRIMARY KEY)",
"CREATE TABLE IF NOT EXISTS event_type (name TEXT,"
" code INTEGER PRIMARY KEY,"
" always INTEGER,"
" kind INTEGER,"
" FOREIGN KEY (kind) REFERENCES event_kind(enum));",
"CREATE TABLE IF NOT EXISTS event_param (type INTEGER,"
" param_index INTEGER,"
" sort TEXT,"
" ident TEXT,"
" FOREIGN KEY (type) REFERENCES event_type(code));",
"CREATE TABLE IF NOT EXISTS event_log (name TEXT,"
" size INTEGER,"
" modtime INTEGER,"
" completed INTEGER,"
" serial INTEGER PRIMARY KEY AUTOINCREMENT)",
EVENT_LIST(EVENT_TABLE_CREATE, X)
};
/* makeTables makes all the tables. */
static void makeTables(sqlite3 *db)
{
size_t i;
log(LOG_SOMETIMES, "Creating tables.");
for (i=0; i < (sizeof(createStatements)/sizeof(createStatements[0])); ++i) {
runStatement(db, createStatements[i], "Table creation");
}
}
const char *glueTables[] = {
"event_kind",
"event_type",
"event_param",
};
static void dropGlueTables(sqlite3 *db)
{
size_t i;
int res;
char sql[1024];
log(LOG_ALWAYS, "Dropping glue tables so they are rebuilt.");
for (i=0; i < (sizeof(glueTables)/sizeof(glueTables[0])); ++i) {
log(LOG_SOMETIMES, "Dropping table %s", glueTables[i]);
sprintf(sql, "DROP TABLE %s", glueTables[i]);
res = sqlite3_exec(db,
sql,
NULL, /* No callback */
NULL, /* No callback closure */
NULL); /* error messages handled by sqlite_error */
/* Don't check for errors. */
}
}
/* Populate the metadata "glue" tables event_kind, event_type, and
* event_param. */
#define EVENT_KIND_DO_INSERT(X, name, description) \
res = sqlite3_bind_text(statement, 1, #name, -1, SQLITE_STATIC); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_kind bind of name \"" #name "\" failed."); \
res = sqlite3_bind_text(statement, 2, description, -1, SQLITE_STATIC); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_kind bind of description \"" description "\" failed."); \
res = sqlite3_bind_int(statement, 3, i); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_kind bind of enum %d failed.", i); \
++i; \
res = sqlite3_step(statement); \
if (res != SQLITE_DONE) \
sqlite_error(res, db, "event_kind insert of name \"" #name "\" failed."); \
if (sqlite3_changes(db) != 0) \
log(LOG_SOMETIMES, "Insert of event_kind row for \"" #name "\" affected %d rows.", sqlite3_changes(db)); \
res = sqlite3_reset(statement); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "Couldn't reset event_kind insert statement.");
#define EVENT_TYPE_DO_INSERT(X, name, code, always, kind) \
res = sqlite3_bind_text(statement, 1, #name, -1, SQLITE_STATIC); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_type bind of name \"" #name "\" failed."); \
res = sqlite3_bind_int(statement, 2, code); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_type bind of code %d failed.", code); \
res = sqlite3_bind_int(statement, 3, always); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_type bind of always for name \"" #name "\" failed."); \
res = sqlite3_bind_int(statement, 4, EventKind##kind); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_type bind of kind for name \"" #name "\" failed."); \
res = sqlite3_step(statement); \
if (res != SQLITE_DONE) \
sqlite_error(res, db, "event_type insert of name \"" #name "\" failed."); \
if (sqlite3_changes(db) != 0) \
log(LOG_SOMETIMES, "Insert of event_type row for \"" #name "\" affected %d rows.", sqlite3_changes(db)); \
res = sqlite3_reset(statement); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "Couldn't reset event_type insert statement.");
#define EVENT_PARAM_DO_INSERT(code, index, sort, ident) \
res = sqlite3_bind_int(statement, 1, code); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_param bind of code %d failed.", code); \
res = sqlite3_bind_int(statement, 2, index); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_param bind of index %d failed.", index); \
res = sqlite3_bind_text(statement, 3, #sort, -1, SQLITE_STATIC); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_type bind of sort \"" #sort "\" failed."); \
res = sqlite3_bind_text(statement, 4, #ident, -1, SQLITE_STATIC); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "event_type bind of ident \"" #ident "\" failed."); \
res = sqlite3_step(statement); \
if (res != SQLITE_DONE) \
sqlite_error(res, db, "event_param insert of ident \"" #ident "\" for code %d failed.", code); \
if (sqlite3_changes(db) != 0) \
log(LOG_SOMETIMES, "Insert of event_param row for code %d, ident \"" #ident "\" affected %d rows.", code, sqlite3_changes(db)); \
res = sqlite3_reset(statement); \
if (res != SQLITE_OK) \
sqlite_error(res, db, "Couldn't reset event_param insert statement.");
#define EVENT_TYPE_INSERT_PARAMS(X, name, code, always, kind) \
EVENT_##name##_PARAMS(EVENT_PARAM_DO_INSERT, code)
static void fillGlueTables(sqlite3 *db)
{
int i;
sqlite3_stmt *statement;
int res;
statement = prepareStatement(db,
"INSERT OR IGNORE INTO event_kind (name, description, enum)"
"VALUES (?, ?, ?)");
i = 0;
EventKindENUM(EVENT_KIND_DO_INSERT, X);
finalizeStatement(db, statement);
statement = prepareStatement(db,
"INSERT OR IGNORE INTO event_type (name, code, always, kind)"
"VALUES (?, ?, ?, ?)");
EVENT_LIST(EVENT_TYPE_DO_INSERT, X);
finalizeStatement(db, statement);
statement = prepareStatement(db,
"INSERT OR IGNORE INTO event_param (type, param_index, sort, ident)"
"VALUES (?, ?, ?, ?)");
EVENT_LIST(EVENT_TYPE_INSERT_PARAMS, X);
finalizeStatement(db, statement);
}
/* Populate the actual event tables. */
#define EVENT_TYPE_DECLARE_STATEMENT(X, name, code, always, kind) \
sqlite3_stmt *stmt_##name;
#define EVENT_PARAM_PREPARE_IDENT(X, index, sort, ident) "\"" #ident "\", "
#define EVENT_PARAM_PREPARE_PLACE(X, index, sort, ident) "?, "
#define EVENT_TYPE_PREPARE_STATEMENT(X, name, code, always, kind) \
stmt_##name = \
prepareStatement(db, \
"INSERT INTO EVENT_" #name " (" \
EVENT_##name##_PARAMS(EVENT_PARAM_PREPARE_IDENT, X) \
"log_serial, time) VALUES (" \
EVENT_##name##_PARAMS(EVENT_PARAM_PREPARE_PLACE,X) \
"?, ?)");
#define EVENT_TYPE_FINALIZE_STATEMENT(X, name, code, always, kind) \
finalizeStatement(db, stmt_##name);
#define EVENT_PARAM_BIND_A bind_int
#define EVENT_PARAM_BIND_P bind_int
#define EVENT_PARAM_BIND_U bind_int
#define EVENT_PARAM_BIND_W bind_int
#define EVENT_PARAM_BIND_D bind_real
#define EVENT_PARAM_BIND_S bind_text
#define EVENT_PARAM_BIND_B bind_int
#define EVENT_PARAM_BIND(X, index, sort, ident) \
p = EVENT_PARAM_BIND_##sort (db, statement, eventCount, index+1, p); \
last_index = index+1;
#define EVENT_TYPE_WRITE_SQL(X, name, code, always, kind) \
case code: \
statement = stmt_##name; \
/* bind all the parameters of this particular event with macro magic. */ \
EVENT_##name##_PARAMS(EVENT_PARAM_BIND, X) \
break;
static char *bind_int(sqlite3 *db, sqlite3_stmt *stmt, int64 count, int index, char *p)
{
char *q;
long long val;
int res;
while(*p == ' ')
++p;
val = strtoll(p, &q, 16);
if (q == p)
error("event %llu field %d not an integer: %s",
count, index, p);
res = sqlite3_bind_int64(stmt, index, val);
if (res != SQLITE_OK)
sqlite_error(res, db, "event %llu field %d bind failed", count, index);
return q;
}
static char *bind_real(sqlite3 *db, sqlite3_stmt *stmt, int64 count, int index, char *p)
{
char *q;
double val;
int res;
while(*p == ' ')
++p;
val = strtod(p, &q);
if (q == p)
error("event %llu field %d not a floating-point value: %s",
count, index, p);
res = sqlite3_bind_double(stmt, index, val);
if (res != SQLITE_OK)
sqlite_error(res, db, "event %llu field %d bind failed", count, index);
return q;
}
static char *bind_text(sqlite3 *db, sqlite3_stmt *stmt, int64 count, int index, char *p)
{
char *q;
int res;
while(*p == ' ')
++p;
q = p;
while((*q != '\n') && (*q != '\0')) {
++ q;
}
if ((q == p) || (q[-1] != '"'))
error("event %llu string field %d has no closing quote mark.",
count, index);
res = sqlite3_bind_text(stmt, index, p, (int)(q-p-1), SQLITE_STATIC);
if (res != SQLITE_OK)
sqlite_error(res, db, "event %llu field %d bind failed", count, index);
return q;
}
/* readLog -- read and parse log. Returns the number of events written.
*/
static int64 readLog(FILE *input,
sqlite3 *db)
{
int64 eventCount = 0;
/* declare statements for every event type */
EVENT_LIST(EVENT_TYPE_DECLARE_STATEMENT, X);
/* prepare statements for every event type */
EVENT_LIST(EVENT_TYPE_PREPARE_STATEMENT, X);
runStatement(db, "BEGIN", "Transaction start");
while (TRUE) { /* loop for each event */
char line[1024];
char *p;
char *q;
int last_index=0;
sqlite3_stmt *statement;
int res;
int64 clock;
long code;
p = fgets(line, 1024, input);
if (!p) {
if (feof(input))
break;
else
error("Couldn't read line after event %llu", eventCount);
}
eventCount++;
clock = strtoll(p, &q, 16);
if (q == p)
error("event %llu clock field not a hex integer: %s",
eventCount, p);
if (*q != ' ')
error("event %llu code field not preceded by ' ': %s",
eventCount, q);
while(*q == ' ')
++q;
p = q;
code = strtol(p, &q, 16);
if (q == p)
error("event %llu code field %d not an integer: %s",
eventCount, index, p);
p = q;
/* Write event to SQLite. */
switch (code) {
/* this macro sets statement and last_index */
EVENT_LIST(EVENT_TYPE_WRITE_SQL, X);
default:
error("Event %llu has Unknown event code %d", eventCount, code);
}
/* bind the fields we store for every event */ \
res = sqlite3_bind_int64(statement, last_index+1, logSerial);
if (res != SQLITE_OK)
sqlite_error(res, db, "Event %llu bind of log_serial failed.", eventCount);
res = sqlite3_bind_int64(statement, last_index+2, clock);
if (res != SQLITE_OK)
sqlite_error(res, db, "Event %llu bind of clock failed.", eventCount);
res = sqlite3_step(statement);
if (res != SQLITE_DONE)
sqlite_error(res, db, "insert of event %llu failed.", eventCount);
res = sqlite3_reset(statement);
if (res != SQLITE_OK)
sqlite_error(res, db, "Couldn't reset insert statement of event %llu", eventCount);
if (verbosity > LOG_ALWAYS) {
if ((eventCount % SMALL_TICK) == 0) {
printf(".");
fflush(stdout);
if (((eventCount / SMALL_TICK) % BIG_TICK) == 0) {
printf("\n");
fflush(stdout);
log(LOG_SOMETIMES, "%lu events.", (unsigned long)eventCount);
}
}
}
}
if (verbosity > LOG_ALWAYS) {
printf("\n");
fflush(stdout);
}
runStatement(db, "COMMIT", "Transaction finish");
logFileCompleted(db, eventCount);
/* finalize all the statements */
EVENT_LIST(EVENT_TYPE_FINALIZE_STATEMENT, X);
return eventCount;
}
static FILE *openLog(sqlite3 *db)
{
FILE *input;
registerLogFile(db, logFileName);
if (!logFileName) {
input = stdin;
logFileName = "<stdin>";
} else {
input = fopen(logFileName, "r");
if (input == NULL)
error("unable to open %s", logFileName);
}
log(LOG_OFTEN, "Reading %s.", logFileName ? logFileName : "standard input");
return input;
}
static int64 writeEventsToSQL(sqlite3 *db)
{
FILE *input;
int64 count;
input = openLog(db);
count = readLog(input, db);
(void)fclose(input);
return count;
}
int main(int argc, char *argv[])
{
sqlite3 *db;
int64 count;
parseArgs(argc, argv);
db = openDatabase();
if (rebuild) {
dropGlueTables(db);
}
makeTables(db);
fillGlueTables(db);
count = writeEventsToSQL(db);
log(LOG_ALWAYS, "Imported %llu events from %s to %s, serial %lu.",
count, logFileName, databaseName, logSerial);
if (runTests) {
/* TODO: more unit tests in here */
testTableExists(db);
}
closeDatabase(db);
return 0;
}
/* COPYRIGHT AND LICENSE
*
* Copyright (C) 2012 Ravenbrook Limited <http://www.ravenbrook.com/>.
* All rights reserved. This is an open source license. Contact
* Ravenbrook for commercial licensing options.
*
* Redistribution and use in source and binary forms, with or without
* modification, are permitted provided that the following conditions are
* met:
*
* 1. Redistributions of source code must retain the above copyright
* notice, this list of conditions and the following disclaimer.
*
* 2. Redistributions in binary form must reproduce the above copyright
* notice, this list of conditions and the following disclaimer in the
* documentation and/or other materials provided with the distribution.
*
* 3. Redistributions in any form must be accompanied by information on how
* to obtain complete source code for this software and any accompanying
* software that uses this software. The source code must either be
* included in the distribution or be available for no more than the cost
* of distribution plus a nominal fee, and must be freely redistributable
* under reasonable conditions. For an executable file, complete source
* code means the source code for all modules it contains. It does not
* include source code for modules or files that typically accompany the
* major components of the operating system on which the executable file
* runs.
*
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS
* IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED
* TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR
* PURPOSE, OR NON-INFRINGEMENT, ARE DISCLAIMED. IN NO EVENT SHALL THE
* COPYRIGHT HOLDERS AND CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT,
* INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT
* NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
* USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON
* ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
* THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
*/

113
mps/code/mps.xcodeproj/project.pbxproj
View file

@ -13,6 +13,7 @@
buildPhases = (
);
dependencies = (
2D07B9791636FCBD00DB751B /* PBXTargetDependency */,
3104AFF6156D37BC000A585A /* PBXTargetDependency */,
3114A6D5156E9839001E0AA3 /* PBXTargetDependency */,
3114A6B9156E9763001E0AA3 /* PBXTargetDependency */,
@ -51,6 +52,8 @@
/* End PBXAggregateTarget section */
/* Begin PBXBuildFile section */
2D07B97A1636FCCE00DB751B /* eventsql.c in Sources */ = {isa = PBXBuildFile; fileRef = 2D07B96C1636FC7200DB751B /* eventsql.c */; };
2D07B97C163705E400DB751B /* libsqlite3.dylib in Frameworks */ = {isa = PBXBuildFile; fileRef = 2D07B97B163705E400DB751B /* libsqlite3.dylib */; };
3104AFBF156D3591000A585A /* apss.c in Sources */ = {isa = PBXBuildFile; fileRef = 3104AFBE156D3591000A585A /* apss.c */; };
3104AFC2156D35B2000A585A /* libmps.a in Frameworks */ = {isa = PBXBuildFile; fileRef = 31EEABFB156AAF9D00714D05 /* libmps.a */; };
3104AFC3156D35C3000A585A /* testlib.c in Sources */ = {isa = PBXBuildFile; fileRef = 31EEAC9E156AB73400714D05 /* testlib.c */; };
@ -196,6 +199,13 @@
/* End PBXBuildFile section */
/* Begin PBXContainerItemProxy section */
2D07B9781636FCBD00DB751B /* PBXContainerItemProxy */ = {
isa = PBXContainerItemProxy;
containerPortal = 31EEABDA156AAE9E00714D05 /* Project object */;
proxyType = 1;
remoteGlobalIDString = 2D07B9701636FC9900DB751B;
remoteInfo = eventsql;
};
3104AFC0156D35AE000A585A /* PBXContainerItemProxy */ = {
isa = PBXContainerItemProxy;
containerPortal = 31EEABDA156AAE9E00714D05 /* Project object */;
@ -626,6 +636,15 @@
/* End PBXContainerItemProxy section */
/* Begin PBXCopyFilesBuildPhase section */
2D07B96F1636FC9900DB751B /* CopyFiles */ = {
isa = PBXCopyFilesBuildPhase;
buildActionMask = 2147483647;
dstPath = /usr/share/man/man1/;
dstSubfolderSpec = 0;
files = (
);
runOnlyForDeploymentPostprocessing = 1;
};
3104AFB1156D357B000A585A /* CopyFiles */ = {
isa = PBXCopyFilesBuildPhase;
buildActionMask = 2147483647;
@ -899,6 +918,9 @@
/* End PBXCopyFilesBuildPhase section */
/* Begin PBXFileReference section */
2D07B96C1636FC7200DB751B /* eventsql.c */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.c; path = eventsql.c; sourceTree = "<group>"; };
2D07B9711636FC9900DB751B /* eventsql */ = {isa = PBXFileReference; explicitFileType = "compiled.mach-o.executable"; includeInIndex = 0; path = eventsql; sourceTree = BUILT_PRODUCTS_DIR; };
2D07B97B163705E400DB751B /* libsqlite3.dylib */ = {isa = PBXFileReference; lastKnownFileType = "compiled.mach-o.dylib"; name = libsqlite3.dylib; path = usr/lib/libsqlite3.dylib; sourceTree = SDKROOT; };
3104AFA5156D27E7000A585A /* ssixi6.c */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.c; path = ssixi6.c; sourceTree = "<group>"; };
3104AFB3156D357B000A585A /* apss */ = {isa = PBXFileReference; explicitFileType = "compiled.mach-o.executable"; includeInIndex = 0; path = apss; sourceTree = BUILT_PRODUCTS_DIR; };
3104AFBE156D3591000A585A /* apss.c */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.c; path = apss.c; sourceTree = "<group>"; };
@ -1026,6 +1048,14 @@
/* End PBXFileReference section */
/* Begin PBXFrameworksBuildPhase section */
2D07B96E1636FC9900DB751B /* Frameworks */ = {
isa = PBXFrameworksBuildPhase;
buildActionMask = 2147483647;
files = (
2D07B97C163705E400DB751B /* libsqlite3.dylib in Frameworks */,
);
runOnlyForDeploymentPostprocessing = 0;
};
3104AFB0156D357B000A585A /* Frameworks */ = {
isa = PBXFrameworksBuildPhase;
buildActionMask = 2147483647;
@ -1276,6 +1306,21 @@
/* End PBXFrameworksBuildPhase section */
/* Begin PBXGroup section */
2D07B96A1636FC4C00DB751B /* eventsql */ = {
isa = PBXGroup;
children = (
2D07B96C1636FC7200DB751B /* eventsql.c */,
);
name = eventsql;
sourceTree = "<group>";
};
2D07B9731636FC9900DB751B /* eventsql */ = {
isa = PBXGroup;
children = (
);
path = eventsql;
sourceTree = "<group>";
};
3114A647156E956C001E0AA3 /* Mysterious */ = {
isa = PBXGroup;
children = (
@ -1288,6 +1333,7 @@
3114A6D6156E9846001E0AA3 /* Tools */ = {
isa = PBXGroup;
children = (
2D07B96A1636FC4C00DB751B /* eventsql */,
3114A6D8156E9942001E0AA3 /* eventcnv */,
);
name = Tools;
@ -1374,10 +1420,12 @@
31EEABD8156AAE9E00714D05 = {
isa = PBXGroup;
children = (
2D07B97B163705E400DB751B /* libsqlite3.dylib */,
3114A6D6156E9846001E0AA3 /* Tools */,
3114A647156E956C001E0AA3 /* Mysterious */,
31A47BA8156C1E930039B1C2 /* MPS */,
3124CAB3156BE1B700753214 /* Tests */,
2D07B9731636FC9900DB751B /* eventsql */,
31EEABEF156AAF5C00714D05 /* Products */,
);
sourceTree = "<group>";
@ -1416,6 +1464,7 @@
3114A695156E971B001E0AA3 /* messtest */,
3114A6AC156E9759001E0AA3 /* walkt0 */,
3114A6C6156E9815001E0AA3 /* eventcnv */,
2D07B9711636FC9900DB751B /* eventsql */,
);
name = Products;
sourceTree = "<group>";
@ -1515,6 +1564,23 @@
/* End PBXHeadersBuildPhase section */
/* Begin PBXNativeTarget section */
2D07B9701636FC9900DB751B /* eventsql */ = {
isa = PBXNativeTarget;
buildConfigurationList = 2D07B9741636FC9900DB751B /* Build configuration list for PBXNativeTarget "eventsql" */;
buildPhases = (
2D07B96D1636FC9900DB751B /* Sources */,
2D07B96E1636FC9900DB751B /* Frameworks */,
2D07B96F1636FC9900DB751B /* CopyFiles */,
);
buildRules = (
);
dependencies = (
);
name = eventsql;
productName = eventsql;
productReference = 2D07B9711636FC9900DB751B /* eventsql */;
productType = "com.apple.product-type.tool";
};
3104AFB2156D357B000A585A /* apss */ = {
isa = PBXNativeTarget;
buildConfigurationList = 3104AFBC156D357B000A585A /* Build configuration list for PBXNativeTarget "apss" */;
@ -2124,11 +2190,20 @@
3114A694156E971B001E0AA3 /* messtest */,
3114A6AB156E9759001E0AA3 /* walkt0 */,
3114A6C5156E9815001E0AA3 /* eventcnv */,
2D07B9701636FC9900DB751B /* eventsql */,
);
};
/* End PBXProject section */
/* Begin PBXSourcesBuildPhase section */
2D07B96D1636FC9900DB751B /* Sources */ = {
isa = PBXSourcesBuildPhase;
buildActionMask = 2147483647;
files = (
2D07B97A1636FCCE00DB751B /* eventsql.c in Sources */,
);
runOnlyForDeploymentPostprocessing = 0;
};
3104AFAF156D357B000A585A /* Sources */ = {
isa = PBXSourcesBuildPhase;
buildActionMask = 2147483647;
@ -2461,6 +2536,11 @@
/* End PBXSourcesBuildPhase section */
/* Begin PBXTargetDependency section */
2D07B9791636FCBD00DB751B /* PBXTargetDependency */ = {
isa = PBXTargetDependency;
target = 2D07B9701636FC9900DB751B /* eventsql */;
targetProxy = 2D07B9781636FCBD00DB751B /* PBXContainerItemProxy */;
};
3104AFC1156D35AE000A585A /* PBXTargetDependency */ = {
isa = PBXTargetDependency;
target = 31EEABFA156AAF9D00714D05 /* mps */;
@ -2769,6 +2849,30 @@
/* End PBXTargetDependency section */
/* Begin XCBuildConfiguration section */
2D07B9751636FC9900DB751B /* Debug */ = {
isa = XCBuildConfiguration;
buildSettings = {
GCC_C_LANGUAGE_STANDARD = c99;
PRODUCT_NAME = "$(TARGET_NAME)";
};
name = Debug;
};
2D07B9761636FC9900DB751B /* Release */ = {
isa = XCBuildConfiguration;
buildSettings = {
GCC_C_LANGUAGE_STANDARD = c99;
PRODUCT_NAME = "$(TARGET_NAME)";
};
name = Release;
};
2D07B9771636FC9900DB751B /* WE */ = {
isa = XCBuildConfiguration;
buildSettings = {
GCC_C_LANGUAGE_STANDARD = c99;
PRODUCT_NAME = "$(TARGET_NAME)";
};
name = WE;
};
3104AFBA156D357B000A585A /* Debug */ = {
isa = XCBuildConfiguration;
buildSettings = {
@ -3616,6 +3720,15 @@
/* End XCBuildConfiguration section */
/* Begin XCConfigurationList section */
2D07B9741636FC9900DB751B /* Build configuration list for PBXNativeTarget "eventsql" */ = {
isa = XCConfigurationList;
buildConfigurations = (
2D07B9751636FC9900DB751B /* Debug */,
2D07B9761636FC9900DB751B /* Release */,
2D07B9771636FC9900DB751B /* WE */,
);
defaultConfigurationIsVisible = 0;
};
3104AFBC156D357B000A585A /* Build configuration list for PBXNativeTarget "apss" */ = {
isa = XCConfigurationList;
buildConfigurations = (

28
mps/code/mpsliban.c
View file

@ -36,6 +36,7 @@
#include <stdlib.h>
#include <stdio.h>
#include <string.h>
#include <ctype.h>
int mps_lib_get_EOF(void)
@ -119,7 +120,9 @@ unsigned long mps_lib_telemetry_control(void)
unsigned long mask;
char buf[256];
char *word;
char *p;
char *sep = " ";
char rowName[256];
s = getenv("MPS_TELEMETRY_CONTROL");
if (s == NULL)
@ -130,14 +133,29 @@ unsigned long mps_lib_telemetry_control(void)
if (mask != 0)
return mask;
/* Split the value at spaces and try to patch the words against the names
of event kinds, enabling them if there's a match. */
/* copy the envar to a buffer so we can mess with it. */
strncpy(buf, s, sizeof(buf) - 1);
buf[sizeof(buf) - 1] = '\0';
/* downcase it */
for (p = buf; *p != '\0'; ++p)
*p = (char)tolower(*p);
/* Split the value at spaces and try to match the words against the names
of event kinds, enabling them if there's a match. */
for (word = strtok(buf, sep); word != NULL; word = strtok(NULL, sep)) {
#define TELEMATCH(X, rowName, rowDoc) \
if (strcmp(word, #rowName) == 0) \
mask |= (1ul << EventKind##rowName);
if (strcmp(word, "all") == 0) {
mask = (unsigned long)-1;
printf("All events.");
return mask;
}
#define TELEMATCH(X, name, rowDoc) \
strncpy(rowName, #name, sizeof(rowName) - 1); \
rowName[sizeof(rowName) - 1] = '\0'; \
for (p = rowName; *p != '\0'; ++p) \
*p = (char)tolower(*p); \
if (strcmp(word, rowName) == 0) { \
mask |= (1ul << EventKind##name); \
printf("Events to include " rowDoc "\n"); }
EventKindENUM(TELEMATCH, X)
}

91
mps/manual/source/guide/debug.rst
View file

@ -188,96 +188,7 @@ since you know that the frame is referenced by the ``car`` of the
first pair in the environment, that's the suspect reference. But in a
more complex situation this might not yet be clear. In such a
situation it can be useful to look at the sequence of events leading
up to the detection of the error, and in order to enable you to do
that, the MPS provides its :ref:`topic-telemetry` feature.
.. _guide-debug-telemetry:
Telemetry
---------
In its :term:`cool` :term:`variety`, the MPS is capable of outputting
a configurable stream of events to assist with debugging and
profiling. The exact mechanism by which the telemetry stream is
controlled is in theory configurable via the :ref:`topic-plinth`, but
if you haven't done so then you can set the environment variables
:envvar:`MPS_TELEMETRY_CONTROL` and :envvar:`MPS_TELEMETRY_FILENAME`.
Setting the former to "``65535``" turns on all events, and the default
value for the latter is "``mpsio.log``" which is fine. So let's run
the test case with telemetry turned on::
$ gdb ./scheme
GNU gdb 6.3.50-20050815 (Apple version gdb-1820) (Sat Jun 16 02:40:11 UTC 2012)
[...]
(gdb) set environment MPS_TELEMETRY_CONTROL=65535
(gdb) run
Starting program: example/scheme/scheme
Reading symbols for shared libraries +............................. done
MPS Toy Scheme Example
[...]
7944, 0> (gc)
[...]
7968, 1> foo
Assertion failed: (TYPE(frame) == TYPE_PAIR), function lookup_in_frame, file scheme.c, line 1066.
Program received signal SIGABRT, Aborted.
0x00007fff91aeed46 in __kill ()
At this point there's still output in the MPS's internal event
buffers, which needs to be flushed. It would be a good idea to add a
call to :c:func:`mps_telemetry_flush` to the error handler, but for
now we can just call it directly from the debugger::
(gdb) print mps_telemetry_flush()
$1 = void
The MPS writes the telemetry to the log in an encoded form for speed.
It can be decoded using the :ref:`eventcnv <telemetry-eventcnv>`
program::
(gdb) shell eventcnv | sort > mpsio.txt
The ``sort`` is useful because the events are not necessarily written
to the telemetry file in time order, but each event starts with a
timestamp so sorting makes a time series. The decoded events look like
this, with the timestamp in the first column (in units of
:c:type:`mps_clock_t`, typically 1 µs), the event type in the second
column, and then addresses or other data related to the event in the
remaining columns. All numbers are given in hexadecimal. ::
00000C0DC0DA69DD395 VMCreate 100128000 100129000 10012A000
00000C0DC0DA69E1ACF VMMap 100128000 100129000 10012A000
00000C0DC0DA69FF118 Intern 2 Reservoir
00000C0DC0DA69FF358 Label 1000BD4A8 sym 00002
00000C0DC0DA6A04890 PoolInit 100129328 100129000 1000BD4A8
00000C0DC0DA6A0C813 VMCreate 10012A000 100300000 100400000
00000C0DC0DA6A120B4 VMMap 10012A000 100300000 100301000
00000C0DC0DA6A1D0F1 ArenaCreateVM 100129000 100000 100000
You can search through the telemetry for events related to particular
addresses of interest. Here we look for events related to the address
of the corrupted ``frame`` object::
(gdb) frame 3
#3 0x0000000100003f55 in lookup_in_frame (frame=0x1003fa7d0, symbol=0x1003faf20) at scheme.c:1066
1066 assert(TYPE(frame) == TYPE_PAIR);
(gdb) print frame
$2 = (obj_t) 0x1003fa7d0
(gdb) shell grep -i 1003fa7d0 mpsio.txt || echo not found
not found
There are no events related to this address, so in particular this
address was never fixed (no ``TraceFix`` event). This should be enough
of a clue to track down the cause.
.. note::
You may find it useful to add the command::
set environment MPS_TELEMETRY_CONTROL=65535
to your ``.gdbinit``.
up to the detection of the error. See :ref:`topic-telemetry`.
.. _guide-debug-size:

129
mps/manual/source/topic/telemetry.rst
View file

@ -31,12 +31,97 @@ John McCarthy described the first on-line demonstration of
thought we were victims of a practical joker.
Introduction
------------
Typical uses of telemetry labels include:
In its :term:`cool` :term:`variety`, the MPS is capable of outputting
a configurable stream of events to assist with debugging and
profiling.
- Label pools with a human-meaningful name;
The selection of events that appear in the stream is controlled by the
environment variable :envvar:`MPS_TELEMETRY_CONTROL` (by default
none), and the stream is written to the file named by the environment
variable :envvar:`MPS_TELEMETRY_FILENAME` (by default ``mpsio.log``).
- Label allocated objects with their type or class.
Example
-------
Here's an example of turning on telemetry in the debugger and then
encountering a corrupted object::
$ gdb ./scheme
GNU gdb 6.3.50-20050815 (Apple version gdb-1820) (Sat Jun 16 02:40:11 UTC 2012)
[...]
(gdb) set environment MPS_TELEMETRY_CONTROL=all
(gdb) run
Starting program: example/scheme/scheme
Reading symbols for shared libraries +............................. done
MPS Toy Scheme Example
[...]
7944, 0> (gc)
[...]
7968, 1> foo
Assertion failed: (TYPE(frame) == TYPE_PAIR), function lookup_in_frame, file scheme.c, line 1066.
Program received signal SIGABRT, Aborted.
0x00007fff91aeed46 in __kill ()
At this point there's still output in the MPS's internal event
buffers, which needs to be flushed. It would be a good idea to add a
call to :c:func:`mps_telemetry_flush` to the error handler, but for
now we can just call it directly from the debugger::
(gdb) print mps_telemetry_flush()
$1 = void
The MPS writes the telemetry to the log in an encoded form for speed.
It can be decoded using the :ref:`eventcnv <telemetry-eventcnv>`
program::
(gdb) shell eventcnv | sort > mpsio.txt
The ``sort`` is useful because the events are not necessarily written
to the telemetry file in time order, but each event starts with a
timestamp so sorting makes a time series. The decoded events look like
this, with the timestamp in the first column (in units of
:c:type:`mps_clock_t`, typically 1 µs), the event type in the second
column, and then addresses or other data related to the event in the
remaining columns. All numbers are given in hexadecimal. ::
000AE03973336E3C 2B 1003FC000 1003FD000 1003FE000
000AE0397333BC6D 2D 1003FC000 1003FD000 1003FE000
000AE0397334DF9F 1A 2 "Reservoir"
000AE0397334E0A0 1B 1078C85B8 2
000AE03973352375 15 1003FD328 1003FD000 1078C85B8
000AE039733592F9 2B 1003FE000 1003FF000 10992F000
000AE0397335C8B5 2D 1003FE000 1003FF000 107930000
000AE03973361D5A 5 1003FD000 2000000 2000000
You can search through the telemetry for events related to particular
addresses of interest.
In the example, we might look for events related to the address of the
corrupted ``frame`` object::
(gdb) frame 3
#3 0x0000000100003f55 in lookup_in_frame (frame=0x1003fa7d0, symbol=0x1003faf20) at scheme.c:1066
1066 assert(TYPE(frame) == TYPE_PAIR);
(gdb) print frame
$2 = (obj_t) 0x1003fa7d0
(gdb) shell grep -i 1003fa7d0 mpsio.txt || echo not found
not found
There are no events related to this address, so in particular this
address was never fixed (no ``TraceFix`` event).
.. note::
You may find it useful to add the command::
set environment MPS_TELEMETRY_CONTROL=all
to your ``.gdbinit``.
Event categories
@ -73,14 +158,16 @@ telemetry feature.
If its value can be interpreted as a number, then this number
represents the set of event categories as a :term:`bitmap`. For
example, this turns on event categories numbered 0 to 15::
example, this turns on the ``Pool`` and ``Seg`` event categories::
MPS_TELEMETRY_CONTROL=65535
MPS_TELEMETRY_CONTROL=6
Otherwise, the value is split into words at spaces, and any word
that names an event category turns it on. For example::
MPS_TELEMETRY_CONTROL="Arena Pool Trace"
MPS_TELEMETRY_CONTROL="arena pool trace"
The special event category ``all`` turns on all events.
.. note::
@ -111,26 +198,6 @@ standard output) a representation of each event in the stream.
The name of the file containing the telemetry stream to decode.
Defaults to ``mpsio.log``.
.. option:: -S
Format output human-readably. This is the default output style.
For example::
000007DC7DC1655516E TraceFix 7FFF583001D0 7FFF583000D8 107AFAB20 1
.. option:: -SL
Format output as S-expressions for consumption by :term:`Lisp`.
For example::
(000007DC7DC1655516E TraceFix 7FFF583001D0 7FFF583000D8 107AFAB20 1)
.. option:: -SC
Format output as CSV (comma-separated values). For example::
000007DC7DC1655516E, 38, 140734672929232, 140734672928984, 4423920416, 1
.. option:: -h
@ -193,6 +260,16 @@ Telemetry interface
even try calling this from a debugger after a problem.
Telemetry labels
----------------
Typical uses of telemetry labels include:
- Label pools with a human-meaningful name;
- Label allocated objects with their type or class.
.. c:function:: mps_word_t mps_telemetry_intern(char *label)
Registers a string with the MPS, and receives a :term:`telemetry